Issues adding helper binary to Pipeline

foxesden <foxesden.auz6wn-NUepA2SMhDQqspMVqqL2D+4xXEVPTSb/[email protected]> Mon, 5 Dec 2022 19:51:58 +0000
Newsgroups gmane.music.equipment.slimdevices.devel
Organization Logitech Squeezebox Forums
Message-ID <[email protected]>
I am trying to replace/upgrade the program that does the DSP processing
within my EQ plugin, and I am having issues with the audio pipeline,
which I can't seem to resolve.

This is with the old binary and is working

Custom.conf 
flc flc * d0:50:99:85:19:e9
	# FRIT:{START=--skip=%t}U:{END=--until=%v}
	[flac] -dcs --totally-silent $START$ $END$ -- $FILE$ | [sqDSP] -id
"d0:50:99:85:19:e9" -wav -wavo -d 24 | [flac] -cs -0 --totally-silent -

New binary, which reads arguments from command line in standard format
and reads settings from json rather than xml. This is all I have
changed

flc flc * d0:50:99:85:19:e9
	# FRIT:{START=--skip=%t}U:{END=--until=%v}
	[flac] -dcs --totally-silent $START$ $END$ -- $FILE$ | [SqueezeDSP]
--id="d0:50:99:85:19:e9" --wav=true --wavo=true --d=24 | [flac] -cs -0
--totally-silent -

The binary has its own log and an entry should be made as soon as it
starts up. However there are no entries, so it doesn't look as if it is
being called at all.


I have tested the pipeline on the windows command line and both behave
identically; with a sox command replacing the flac command to get audio
output.

flac -dcs --totally-silent break.flac | sqDSP -id "d0:50:99:85:19:e9"
-wav -wavo -d 24 | sox  -q -t wav  -b 24  -c 2 -r 44.1k -L - -t
waveaudio 0

flac -dcs --totally-silent break.flac | squeezeDSP
--id="d0:50:99:85:19:e9" --wav=true --wavo=true --d=24 | sox  -q -t wav 
-b 24  -c 2 -r 44.1k -L - -t waveaudio 0




-------------Monitoring-----
This one is working

SW: 2022-12-05 18:55:27.978 Socketwrapper 1.12beta
SW: 2022-12-05 18:55:27.978 -i 5566 -o 5565 -c
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -dcs
--totally-silent -- - |
"C:\ProgramData\Squeezebox\Cache\InstalledPlugins\Plugins\SqueezeDSP\Bin\sqDSP.exe"
-id "d0:50:99:85:19:e9" -wav -wavo -d 24 |
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -cs
-0 --totally-silent -
SW: 2022-12-05 18:55:27.980 Input from socket ...
SW: 2022-12-05 18:55:27.981 Input socket connected OK.
SW: 2022-12-05 18:55:27.981 Input socket pipe created OK.
SW: 2022-12-05 18:55:27.981 Init complete.
SW: 2022-12-05 18:55:27.981 # =input== =output= ==type== ===details===
SW: 2022-12-05 18:55:27.981 0 000000c4 000000d4  THREAD
SW: 2022-12-05 18:55:27.981 1 000000d0 000000dc  PROCESS
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -dcs
--totally-silent -- -
SW: 2022-12-05 18:55:27.982 2 000000d8 000000e4  PROCESS
"C:\ProgramData\Squeezebox\Cache\InstalledPlugins\Plugins\SqueezeDSP\Bin\sqDSP.exe"
-id "d0:50:99:85:19:e9" -wav -wavo -d 24
SW: 2022-12-05 18:55:27.982 3 000000e0 000000ec  PROCESS
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -cs
-0 --totally-silent -
SW: 2022-12-05 18:55:27.982 4 000000e8 000000f0  THREAD  Output Socket
SW: 2022-12-05 18:55:27.982 MoveDataThreadProc for step 0 started.
SW: 2022-12-05 18:55:27.982 MoveDataThreadProc for step 4 started.
...
...
SW: 2022-12-05 18:55:28.465 MoveDataThreadProc for step 0 got 8192
bytes, about to write data.
SW: 2022-12-05 18:55:28.468 MoveDataThreadProc for step 4 got 4096
bytes, about to write data.
SW: 2022-12-05 18:55:28.469 MoveDataThreadProc for step 4 about to call
ReadFile.
SW: 2022-12-05 18:55:28.469 MoveDataThreadProc for step 4 got 4096
bytes, about to write data.
SW: 2022-12-05 18:55:28.469 MoveDataThreadProc for step 4 about to call
ReadFile.

--------------------Monitoring-----------------This one is failing
SW: 2022-12-05 18:51:47.598 Socketwrapper 1.12beta
SW: 2022-12-05 18:51:47.599 -i 5504 -o 5503 -c
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -dcs
--totally-silent -- - |
"C:\ProgramData\Squeezebox\Cache\InstalledPlugins\Plugins\SqueezeDSP\Bin\SqueezeDSP.exe"
--id="d0:50:99:85:19:e9" --wav=true --wavo=true --d=24 |
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -cs
-0 --totally-silent -
SW: 2022-12-05 18:51:47.599 Input from socket ...
SW: 2022-12-05 18:51:47.600 Input socket connected OK.
SW: 2022-12-05 18:51:47.601 Input socket pipe created OK.
SW: 2022-12-05 18:51:47.602 Init complete.
SW: 2022-12-05 18:51:47.602 # =input== =output= ==type== ===details===
SW: 2022-12-05 18:51:47.602 0 000000a4 000000d0  THREAD
SW: 2022-12-05 18:51:47.602 1 000000cc 000000d8  PROCESS
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -dcs
--totally-silent -- -
SW: 2022-12-05 18:51:47.602 2 000000d4 000000e0  PROCESS
"C:\ProgramData\Squeezebox\Cache\InstalledPlugins\Plugins\SqueezeDSP\Bin\SqueezeDSP.exe"
--id="d0:50:99:85:19:e9" --wav=true --wavo=true --d=24
SW: 2022-12-05 18:51:47.602 3 000000dc 000000e8  PROCESS
"E:\GitHub\slimserver-win64\Bin\MSWin32-x64-multi-thread\flac.exe" -cs
-0 --totally-silent -
SW: 2022-12-05 18:51:47.602 4 000000e4 000000ec  THREAD  Output Socket
SW: 2022-12-05 18:51:47.603 MoveDataThreadProc for step 0 started.
SW: 2022-12-05 18:51:47.603 MoveDataThreadProc for step 0 about to call
ReadFile.
...
...
SW: 2022-12-05 18:51:47.625 MoveDataThreadProc for step 0 about to call
ReadFile.
SW: 2022-12-05 18:51:47.626 MoveDataThreadProc for step 0 got 8192
bytes, about to write data.
SW: 2022-12-05 18:51:47.629 MoveDataThreadProc for step 0 about to call
ReadFile.
SW: 2022-12-05 18:51:47.629 MoveDataThreadProc for step 0 got 8192
bytes, about to write data.
SW: 2022-12-05 18:51:47.639 Timeout Process/Thread for step 2 died.
SW: 2022-12-05 18:51:47.640 Watchdog expired - Thread for step 4
stalled.
SW: 2022-12-05 18:51:47.641 Tidying up
SW: 2022-12-05 18:51:47.642  Process/thread 2 stopped
SW: 2022-12-05 18:51:47.643 Watchdog expired
SW: 2022-12-05 18:51:49.654 Tidying up - Thread for step 0 hasn't died.

I have also enabled debugging on the server log and homed in on this
information, which seems most relevant.

[22-12-05 18:30:04.2149] Slim::Player::Pipeline::sysread (304)
Attempting to write to pipeline writer
[22-12-05 18:30:04.6221] Slim::Player::Pipeline::sysread (304)
Attempting to write to pipeline writer
[22-12-05 18:30:04.7815] Slim::Plugin::CLI::Plugin::cli_request_write
(690) status
[22-12-05 18:30:04.7828] Slim::Plugin::CLI::Plugin::client_socket_buffer
(506) 10.119.1.143:5058
[22-12-05 18:30:04.7835] Slim::Plugin::CLI::Plugin::client_socket_write
(450) 10.119.1.143:5058
[22-12-05 18:30:04.7839] Slim::Plugin::CLI::Plugin::client_socket_write
(463) 10.119.1.143:5058 - Sending response [d0%3A50%3A99%3A85%3A19%3Ae9
status - 1 subscribe%3A2 player_name%3AIPhox player_connected%3A1
play...]
[22-12-05 18:30:04.7843] Slim::Plugin::CLI::Plugin::client_socket_write
(489) Sent response to 10.119.1.143:5058
[22-12-05 18:30:05.0318] Slim::Player::Pipeline::sysread (304)
Attempting to write to pipeline writer
[22-12-05 18:30:05.3724] Slim::Player::Source::_wakeupOnReadable (414)
d0:50:99:85:19:e9
[22-12-05 18:30:05.3733] Slim::Player::Pipeline::sysread (304)
Attempting to write to pipeline writer
[22-12-05 18:30:05.3747] Slim::Player::Source::_readNextChunk (355) Read
to end of file or pipe
[22-12-05 18:30:05.3752] Slim::Player::Source::_readNextChunk (378) end
of file or error on socket, song pos: 0
[22-12-05 18:30:05.3756] Slim::Player::Source::_readNextChunk (383)
d0:50:99:85:19:e9 mark end of stream
[22-12-05 18:30:05.3764] Slim::Player::Source::_readNextChunk (391)
Didn't stream any bytes for this song; mark it as failed
[22-12-05 18:30:05.3767]
Slim::Player::StreamingController::playerStreamingFailed (2249)
d0:50:99:85:19:e9
[22-12-05 18:30:05.3774]
Slim::Player::StreamingController::_playersMessage (796) Problem: Can't
open file for::
file:///E:/work/CDBackup/MercanDede_800/07%20-%20%20Tutsak.flac
[22-12-05 18:30:05.3791] Slim::Player::StreamingController::_eventAction
(272) d0:50:99:85:19:e9: StreamingFailed in BUFFERING-STREAMING ->
Slim::Player::StreamingController::_StopNextIfMore
[22-12-05 18:30:05.3796] Slim::Player::StreamingController::_eventAction
(283) params: errorDisconnect => undef
[22-12-05 18:30:05.3808] Slim::Player::StreamingController::_Stop (610)
Song queue is now 0
[22-12-05 18:30:05.3821] Slim::Player::SongStreamController::DESTROY
(49) DESTROY(Slim::Player::SongStreamController=ARRAY(0xc7c39a0))
live=0
[22-12-05 18:30:05.3825]
Slim::Player::StreamingController::_setPlayingState (2378) new playing
state STOPPED
[22-12-05 18:30:05.3829]
Slim::Player::StreamingController::_setStreamingState (2387) new
streaming state IDLE
[22-12-05 18:30:05.3835] Slim::Player::StreamingController::_willRetry
(1409) no retry data
[22-12-05 18:30:05.3839] Slim::Player::StreamingController::nextsong
(889) The next song is number 0, was 0
[22-12-05 18:30:05.3842] Slim::Player::StreamingController::_eventAction
(302) d0:50:99:85:19:e9: StreamingFailed - new state STOPPED-IDLE
[22-12-05 18:30:05.3853]
Slim::Plugin::CLI::Plugin::cli_subscribe_notification (974) playlist
stop




I have tried a similar exercise with a 3rd party command line convolver.
Which also fails despite me being able to pipe input and output through
it.

Any suggestions for what might be going on here, am I doing something
obviously wrong?


------------------------------------------------------------------------
foxesden's Profile: http://forums.slimdevices.com/member.php?userid=56286
View this thread: http://forums.slimdevices.com/showthread.php?t=117170