Announcement

Collapse
No announcement yet.

Issues adding helper binary to Pipeline

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

    Issues adding helper binary to Pipeline

    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:layerStreamingFailed (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:ESTROY (49) DESTROY(Slim::Player::SongStreamController=ARRAY(0 xc7c39a0)) live=0
    [22-12-05 18:30:05.3825] Slim::Player::StreamingController::_setPlayingStat e (2378) new playing state STOPPED
    [22-12-05 18:30:05.3829] Slim::Player::StreamingController::_setStreamingSt ate (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_notificat ion (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?

    #2
    Originally posted by foxesden View Post
    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?
    Socketwrapper watchdog kills process chainm if no data is moving through the chain withxin X seconds (longer if logging debug is enabled).

    It is possible one of the process chain is crashing so I'd first run LMS from a Command prompt so that any error message written to "console" will be seen.

    Can you simplify the chain so that just test squeezeDSP.exe (e.g. send WAV input to squeezeDSP and send a WAV output to player). If that works then you know SqueezeDSP.exe itself is not the issue.
    Last edited by bpa; 2022-12-05, 21:35.

    Comment


      #3
      I am going to answer my own question here..

      The issue related to environment setup and specifically the login folder. MS keep changing this, I guess to keep the code portable, and in upgrading to .Net 7 they had deprecated the previous command for locating the executable folder, and I picked the wrong alternative approach

      System.AppContext.BaseDirectory; provides the folder of the currently running exe

      I had incorrectly used

      Directory.GetCurrentDirectory(); which explains why it all worked form command line.

      Comment

      Working...
      X