Home of the Squeezebox™ & Transporter® network music players.
Page 1 of 5 123 ... LastLast
Results 1 to 10 of 45
  1. #1
    Senior Member
    Join Date
    Dec 2009
    Location
    Albinea (Bologna Area) Italy
    Posts
    524

    Windows, STDIN and Socketwrapper

    Hi all,


    I wrote a program that act as a transcoder, presenting itself to LMS exactly like FLAC, FFMPEG, FAAD and others do, but sctually act like a prowy for all of them and adding some capabilities. This program is working flawlessy in Linux and OsX, works in windows too, but NOT when reading imput from STDIN.

    To make it short in some circumstances, when the program is invoked by LMS but there is nothing to do, it run as a pump, moving data from stdin to stdout that way:

    Code:
                   Plugins::C3PO::Logger::debugMessage(
    				"HeaderRestorer: start copy from STDIN");
    
                   while (
    			sysread (STDIN, $buffer, 65536)	# read in (up to) 64k chunks, write
    			and syswrite STDOUT, $buffer	# exit if read or write fails
    			) {
    				Plugins::C3PO::Logger::debugMessage(
    				"HeaderRestorer: copied 64Kb chunk");
    		}
    		if ($!){		
    
    			Plugins::C3PO::Logger::errorMessage(
    				"HeaderRestorer/Dummy Transcoder: Problem writing body from STDIN: $!");
    		} else{
    		
    			Plugins::C3PO::Logger::debugMessage(
    				"HeaderRestorer: end copy from STDIN");
    		}
    
    		flush STDOUT;
    BPA pointed me to a windows blocking pipe problem and probably is that one, asking me to open this Thread here, here I'm.

    The log of the program:

    Code:
    [Wed Sep 28 15:14:33 2016] DEBUG: HeaderRestorer: start copy from STDIN 
    [Wed Sep 28 15:14:33 2016] DEBUG: HeaderRestorer: copied 64Kb chunk 
    
     ... ( undreds of lines here )
    
    [Wed Sep 28 15:14:36 2016] DEBUG: HeaderRestorer: copied 64Kb chunk 
    [Wed Sep 28 15:15:37 2016] DEBUG: DEBUGLOG 1
    It correctly start to read from STDIN and write to STDOUT but after a wile aborts (no error or end messages), last line is the first form the restarted one, see below.

    The output from LMS running is there:

    Code:
    ...
    [16-09-28 15:14:31.4349] Slim::Utils::OS::Win32::getPriorityClass (741) Error: Slim::Utils::LogCan't get process handle () [Wrong number of parameters: expected 0, got 1.
    ]
    [16-09-28 15:14:31.4356] Slim::Player::Pipeline::new (96) Launching process with command: "G:\Sviluppo\slimserver\Bin\MSWin32-x86-multi-thread\socketwrapper.exe"  -d -i 2316  -w -o 2315 -c "\"
    thread\C-3PO.exe\" -c e8-de-27-03-05-b2 -p \"C:\Documents and Settings\All Users\Dati applicazioni\SqueezeboxTest\prefs\plugin\C3PO.prefs\" -l \"C:\\Documents and Settings\\All Users\\Dati app
    ver\" -i flc -o wav -"
    [16-09-28 15:14:31.4418] Slim::Player::StreamingController::_Stream (1265) e8:de:27:03:05:b2: stream
    [16-09-28 15:14:31.4445] Slim::Player::StreamingController::_Stream (1302) Song queue is now 0
    [16-09-28 15:14:31.4450] Slim::Player::StreamingController::_setPlayingState (2357) new playing state BUFFERING
    [16-09-28 15:14:31.4454] Slim::Player::StreamingController::_setStreamingState (2366) new streaming state STREAMING
    SW: 2016-09-28 15:14:31.437 Socketwrapper 1.11beta
    SW: 2016-09-28 15:14:31.437 -i 2316 -o 2315 -c "G:\Sviluppo\slimserver\Plugins\C3PO\Bin\MSWin32-x86-multi-thread\C-3PO.exe" -c e8-de-27-03-05-b2 -p "C:\Documents and Settings\All Users\Dati ap
    \Documents and Settings\\All Users\\Dati applicazioni\\SqueezeboxTest\\logs" -x "G:/Sviluppo/slimserver" -i flc -o wav -
    SW: 2016-09-28 15:14:31.437 Input from socket ...
    SW: 2016-09-28 15:14:31.437 Input socket connected OK.
    SW: 2016-09-28 15:14:31.437 Input socket pipe created OK.
    SW: 2016-09-28 15:14:31.437 Init complete.
    SW: 2016-09-28 15:14:31.437 # =input== =output= ==type== ===details===
    SW: 2016-09-28 15:14:31.437 0 00000064 00000074  THREAD
    SW: 2016-09-28 15:14:31.437 1 00000070 0000007c  PROCESS "G:\Sviluppo\slimserver\Plugins\C3PO\Bin\MSWin32-x86-multi-thread\C-3PO.exe" -c e8-de-27-03-05-b2 -p "C:\Documents and Settings\All Use
    s" -l "C:\\Documents and Settings\\All Users\\Dati applicazioni\\SqueezeboxTest\\logs" -x "G:/Sviluppo/slimserver" -i flc -o wav -
    SW: 2016-09-28 15:14:31.437 2 00000078 00000080  THREAD  Output Socket
    SW: 2016-09-28 15:14:31.437 MoveDataThreadProc for step 0 started.
    SW: 2016-09-28 15:14:31.437 MoveDataThreadProc for step 0 about to call ReadFile.
    SW: 2016-09-28 15:14:31.437 MoveDataThreadProc for step 2 started.
    SW: 2016-09-28 15:14:31.453 MoveDataThreadProc for step 2 about to call ReadFile.
    [16-09-28 15:14:31.4791] Slim::Player::Pipeline::acceptReader (203) Pipeline reader connected
    [16-09-28 15:14:31.4878] Slim::Player::Pipeline::acceptWriter (236) Pipeline writer connected
    SW: 2016-09-28 15:14:31.484 MoveDataThreadProc for step 0 got 1460 bytes, about to write data.
    SW: 2016-09-28 15:14:31.484 MoveDataThreadProc for step 0 about to call ReadFile.
    SW: 2016-09-28 15:14:31.484 MoveDataThreadProc for step 0 got 6843 bytes, about to write data.
    [16-09-28 15:14:31.5463] Slim::Player::TranscodingHelper::getConvertCommand2 (444) Error: Didn't find any command matches for type: flc
    [16-09-28 15:14:31.5803] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    [16-09-28 15:14:31.8906] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    [16-09-28 15:14:32.1972] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    Use of uninitialized value in do "file" at C:/Perl/site/lib/PAR.pm line 636.
    [16-09-28 15:14:32.5000] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    SW: 2016-09-28 15:14:32.656 Timeout Process/Thread for step 1 died.
    SW: 2016-09-28 15:14:32.656 Watchdog expired - Thread for step 2 stalled.
    SW: 2016-09-28 15:14:32.656 Tidying up
    SW: 2016-09-28 15:14:32.656  Process/thread 1 stopped
    SW: 2016-09-28 15:14:32.656 Watchdog expired
    [16-09-28 15:14:32.8132] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    Use of uninitialized value in do "file" at C:/Perl/site/lib/PAR.pm line 636.
    [16-09-28 15:14:33.1286] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    C:\Programmi\sox-14-4-2\sox.exe WARN dither: no `improved-e-weighted' filter is available for rate 88200; using sloped TPDF
    SW: 2016-09-28 15:14:33.234 MoveDataThreadProc for step 2 got 8192 bytes, about to write data.
    SW: 2016-09-28 15:14:33.234 MoveDataThreadProc for step 2 about to call ReadFile.
    SW: 2016-09-28 15:14:33.234 MoveDataThreadProc for step 2 got 8192 bytes, about to write data.
    [16-09-28 15:14:33.3108] Slim::Player::StreamingController::playerTrackStarted (2180) e8:de:27:03:05:b2
    [16-09-28 15:14:33.3115] Slim::Player::StreamingController::_setPlayingState (2357) new playing state PLAYING
    [16-09-28 15:14:33.3120] Slim::Player::StreamingController::_Playing (361) Song 0 has now started playing
    [16-09-28 15:14:33.3128] Slim::Player::StreamingController::_Playing (390) Song queue is now 0
    SW: 2016-09-28 15:14:34.656 Tidying up - Thread for step 0 hasn't died.
    SW: 2016-09-28 15:14:34.656 Thread for step 0 streamed    170 blocks totalling 0013DCC7 (1301703) bytes
    SW: 2016-09-28 15:14:34.656 Waiting for process step 1 to terminate
    SW: 2016-09-28 15:14:36.656 Tidying up - Thread for step 2 hasn't died.
    SW: 2016-09-28 15:14:36.656 Thread for step 2 streamed   2108 blocks totalling 01078000 (17268736) bytes
    [16-09-28 15:14:37.8651] Slim::Player::TranscodingHelper::getConvertCommand2 (444) Error: Didn't find any command matches for type: flc
    [16-09-28 15:15:06.0096] Slim::Player::StreamingController::playerOutputUnderrun (2219) e8:de:27:03:05:b2: decoder: 2 / output: 0
    [16-09-28 15:15:06.0106] Slim::Player::StreamingController::_setPlayingState (2357) new playing state BUFFERING
    [16-09-28 15:15:06.1406] Slim::Player::Player::_buffering (1140) Buffering... 2 / 882000
    [16-09-28 15:15:06.4530] Slim::Player::Player::_buffering (1140) Buffering... 2 / 882000
    
    ... (many other lines here)
    
    [16-09-28 15:15:36.9405] Slim::Player::Player::_buffering (1140) Buffering... 2 / 882000
    [16-09-28 15:15:36.9881] Slim::Player::StreamingController::stop (2097) e8:de:27:03:05:b2
    [16-09-28 15:15:36.9890] Slim::Player::StreamingController::_Stop (603) Song queue is now 0
    [16-09-28 15:15:36.9905] Slim::Player::StreamingController::_setPlayingState (2357) new playing state STOPPED
    [16-09-28 15:15:36.9909] Slim::Player::StreamingController::_setStreamingState (2366) new streaming state IDLE
    then it restart from the beginning the same track.

    As you could see the line:

    [16-09-28 15:14:33.1286] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120

    start exactly when the program start to move data:

    [Wed Sep 28 15:14:33 2016] DEBUG: HeaderRestorer: start copy from STDIN

    At 16-09-28 15:14:33 the program start reading from STDIN and writing to STDOUT, everything works until Socketwrapper say sometrhing about processes:

    SW: 2016-09-28 15:14:36.656 Tidying up - Thread for step 2 hasn't died.
    SW: 2016-09-28 15:14:36.656 Thread for step 2 streamed 2108 blocks totalling 01078000 (17268736) bytes

    ant the program aborts and restart

    [Wed Sep 28 15:14:36 2016] DEBUG: HeaderRestorer: copied 64Kb chunk
    [Wed Sep 28 15:15:37 2016] DEBUG: DEBUGLOG 1

    after 30 seconds the player's buffer underrun and the player start trying buffering, but after other 30 secs stops.

    Is something related to a blocking pipe? How should I change or declare the filehandle to make it non blocking in windows?

    I've tried many different ways, but never found a working solution. Courious to know how did people managed to read form stdin in plugins like WAVINPUT or similars.

    I start to think the problem is in the wrapper (PARM::PAR) I use to get a .exe form the .pl in windows, maybe I should use C instead, but in that case I'll need some example to look at, i'm not a c expert at all.

    Please forgive my terrible english and feel free to ask for any clarification.

    Thanks, Marco.
    Last edited by marcoc1712; 2016-09-28 at 10:10.
    __________________________________________________ __________
    SB+, Klimo Merlino + Kent Gold, Monitor Audio Studio 20 Gold SE+, Klimo reference and DIS Interconnect.

  2. #2
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    15,332
    Quote Originally Posted by marcoc1712 View Post
    Code:
    
    SW: 2016-09-28 15:14:32.656 Timeout Process/Thread for step 1 died.
    SW: 2016-09-28 15:14:32.656 Watchdog expired - Thread for step 2 stalled.
    SW: 2016-09-28 15:14:32.656 Tidying up
    
    The reason for socketwrapper decided to stop is that data was stalled - no data has been moving through the system for x secs. The usual cause is that one of the application reading data from the interconnections has stopped reading data.

    You applicaiton is a single process with blocking reads and blocking writes. This is not good design for such a relay application. Usually read and write are two processes or threads and the system read and write are not blocking so that for example a short term problem with write does not stop read happening. You may be coming up against some Windows internal buffer size.

    I suggest
    1. reduce the size of the reads/writes to say 10kb or 5 kb and see if behaviour changes.
    2. Chaneg system reads and writes to non blocking.

  3. #3
    Senior Member
    Join Date
    Dec 2009
    Location
    Albinea (Bologna Area) Italy
    Posts
    524
    Quote Originally Posted by bpa View Post
    The reason for socketwrapper decided to stop is that data was stalled - no data has been moving through the system for x secs. The usual cause is that one of the application reading data from the interconnections has stopped reading data.

    You applicaiton is a single process with blocking reads and blocking writes. This is not good design for such a relay application. Usually read and write are two processes or threads and the system read and write are not blocking so that for example a short term problem with write does not stop read happening. You may be coming up against some Windows internal buffer size.

    I suggest
    1. reduce the size of the reads/writes to say 10kb or 5 kb and see if behaviour changes.
    2. Chaneg system reads and writes to non blocking.
    1. ok (EDIT: done, but nothing changed)
    2. Shall I ask you some example on how to make system reads and writes non blocking in perl on windows? In *nix they normally behave as non blocking, I suppose.

    I've tried to use threads, fork and select, but with no luck.
    Last edited by marcoc1712; 2016-09-28 at 11:33.
    __________________________________________________ __________
    SB+, Klimo Merlino + Kent Gold, Monitor Audio Studio 20 Gold SE+, Klimo reference and DIS Interconnect.

  4. #4
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    15,332
    Quote Originally Posted by marcoc1712 View Post
    1. ok (EDIT: done, but nothing changed)
    Absolutely nothing changed - the same number of bytes were passed by socketwrapper before it failed ? If absolutely nothing changed then I don't believe the change was made or else the problem is not in this app. This is a subtle prblem where details may matter.

    2. Shall I ask you some example on how to make system reads and writes non blocking in perl on windows? In *nix they normally behave as non blocking, I suppose.

    I've tried to use threads, fork and select, but with no luck.
    No Linux is blocking but pipes behave differently so you are living on the edge - a different linux system perhaps with smaller memeory , lower speed processor and your system could fail.

    How do you build you Perl system in Windows also matters as many of these facilities may work on Linux but not on Windows. How do you build your windows exe - activestate ... ? These are the issues that make developers choose C for this sort of application (source code for faad is on slimdevice github).

    edit:

    Personally to do non blocking/async I/o I would look to use an existing system such as AnyEvent which can hiode difference between Windows/Linux/OSX when setting async i/o but my gut feel is that we should be able to get somehting to work with smaller buffers and existing system but I can't provide thta code for a few days as I will have to research it.

    edit 2:

    Example of how to setup non blocking I/O from Perl Cookbook. Not surew if it works on Window and /or specifically on stdin/stdout on Windows.
    http://docstore.mik.ua/orelly/perl/cookbook/ch07_15.htm
    Last edited by bpa; 2016-09-28 at 13:45.

  5. #5
    Senior Member
    Join Date
    Dec 2009
    Location
    Albinea (Bologna Area) Italy
    Posts
    524
    Quote Originally Posted by bpa View Post
    Absolutely nothing changed - the same number of bytes were passed by socketwrapper before it failed ? If absolutely nothing changed then I don't believe the change was made or else the problem is not in this app. This is a subtle prblem where details may matter.



    No Linux is blocking but pipes behave differently so you are living on the edge - a different linux system perhaps with smaller memeory , lower speed processor and your system could fail.

    How do you build you Perl system in Windows also matters as many of these facilities may work on Linux but not on Windows. How do you build your windows exe - activestate ... ? These are the issues that make developers choose C for this sort of application (source code for faad is on slimdevice github).

    edit:

    Personally to do non blocking/async I/o I would look to use an existing system such as AnyEvent which can hiode difference between Windows/Linux/OSX when setting async i/o but my gut feel is that we should be able to get somehting to work with smaller buffers and existing system but I can't provide thta code for a few days as I will have to research it.
    Not really the same amount of bit, but quite the same:

    Code:
    SW: 2016-09-28 20:43:55.203 Timeout Process/Thread for step 1 died.
    SW: 2016-09-28 20:43:55.203 Watchdog expired - Thread for step 2 stalled.
    SW: 2016-09-28 20:43:55.203 Tidying up
    SW: 2016-09-28 20:43:55.203  Process/thread 1 stopped
    SW: 2016-09-28 20:43:55.203 Watchdog expired
    [16-09-28 20:43:55.3906] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    Use of uninitialized value in do "file" at C:/Perl/site/lib/PAR.pm line 636.
    [16-09-28 20:43:55.7011] Slim::Player::Player::_buffering (1140) Buffering... 0 / 261120
    C:\Programmi\sox-14-4-2\sox.exe WARN dither: no `improved-e-weighted' filter is available for rate 88200; using sloped TPDF
    SW: 2016-09-28 20:43:55.765 MoveDataThreadProc for step 2 got 8192 bytes, about to write data.
    SW: 2016-09-28 20:43:55.765 MoveDataThreadProc for step 2 about to call ReadFile.
    SW: 2016-09-28 20:43:55.765 MoveDataThreadProc for step 2 got 8192 bytes, about to write data.
    [16-09-28 20:43:55.8754] Slim::Player::StreamingController::playerTrackStarted (2180) e8:de:27:03:05:b2
    [16-09-28 20:43:55.8760] Slim::Player::StreamingController::_setPlayingState (2357) new playing state PLAYING
    [16-09-28 20:43:55.8763] Slim::Player::StreamingController::_Playing (361) Song 9 has now started playing
    [16-09-28 20:43:55.8769] Slim::Player::StreamingController::_Playing (390) Song queue is now 9
    SW: 2016-09-28 20:43:57.203 Tidying up - Thread for step 0 hasn't died.
    SW: 2016-09-28 20:43:57.203 Thread for step 0 streamed    187 blocks totalling 00151973 (1382771) bytes
    SW: 2016-09-28 20:43:57.203 Waiting for process step 1 to terminate
    [16-09-28 20:43:57.5637] Slim::Player::TranscodingHelper::getConvertCommand2 (444) Error: Didn't find any command matches for type: flc
    SW: 2016-09-28 20:43:59.203 Tidying up - Thread for step 2 hasn't died.
    SW: 2016-09-28 20:43:59.203 Thread for step 2 streamed   2105 blocks totalling 01072000 (17244160) bytes
    To produce the .EXE I use PARM:PAR pp.

    Waiting for your examples, I'll have a look to FAAD, thanks for your kind help.
    __________________________________________________ __________
    SB+, Klimo Merlino + Kent Gold, Monitor Audio Studio 20 Gold SE+, Klimo reference and DIS Interconnect.

  6. #6
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    15,332
    Quote Originally Posted by marcoc1712 View Post
    Not really the same amount of bit, but quite the same:.
    Details matter - what is missing sometimes is as important as what is present. Can you give complete log not a fragment - zip and attach to a post.

  7. #7
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    15,332
    Can you also supply the custom-convert.conf file that you are using ?

  8. #8
    Senior Member
    Join Date
    Dec 2009
    Location
    Albinea (Bologna Area) Italy
    Posts
    524
    Quote Originally Posted by bpa View Post
    Can you also supply the custom-convert.conf file that you are using ?
    No custom-convert.conf, the program we are talking about is part of a plugin (called C-3PO) aimed to competely replace custom-convert.conf, allowing the user to set transcoding and resampling parameters using the web gui. Values are then stored in preference files and directly loaded in the LMS transcoder table at startup or when changed (no needs to restart the server).

    To see the content of the command issued, look for the 'tokenized command' in the log. Just before that you could see how capabilities were imposed and at what vlaues. Same information, but for all players and all transcoding commands, are reported in the ...:Plugin:C-3PO... log section just after the server startup.
    Last edited by marcoc1712; 2016-09-28 at 15:06.
    __________________________________________________ __________
    SB+, Klimo Merlino + Kent Gold, Monitor Audio Studio 20 Gold SE+, Klimo reference and DIS Interconnect.

  9. #9
    Senior Member
    Join Date
    Dec 2009
    Location
    Albinea (Bologna Area) Italy
    Posts
    524
    Quote Originally Posted by bpa View Post
    Details matter - what is missing sometimes is as important as what is present. Can you give complete log not a fragment - zip and attach to a post.

    Attached is the zipped log, produced with C-3PO plugin in debug (verbose) mode, hope you don't care.
    Attached Files Attached Files
    Last edited by marcoc1712; 2016-09-28 at 15:02.
    __________________________________________________ __________
    SB+, Klimo Merlino + Kent Gold, Monitor Audio Studio 20 Gold SE+, Klimo reference and DIS Interconnect.

  10. #10
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    15,332
    Quote Originally Posted by marcoc1712 View Post
    No custom-convert.conf, the program we are talking about is part of a plugin (called C-3PO) aimed to competely replace custom-convert.conf, allowing the user to set transcoding and resampling parameters using the web gui. Values are then stored in preference files and directly loaded in the LMS transcoder table at startup or when changed (no needs to restart the server).

    To see the content of the command issued, look for the 'tokenized command' in the log. Just before that you could see how capabilities were imposed and at what vlaues. Same information, but for all players and all transcoding commands, are reported in the ...:Plugin:C-3PO... log section just after the server startup.
    There are subtle differences in conf file in Windows compared to Linux/OSX due to socketwrapper and windows escape chars and poath limits such as the possible need to have "#PIPE#" - my gut feel is the tokenised command not quite right and the conf file would make it easdy to check.

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •