Home of the Squeezebox™ & Transporter® network music players.
Page 3 of 5 FirstFirst 12345 LastLast
Results 21 to 30 of 44
  1. #21
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    18,876
    Quote Originally Posted by troffasky View Post
    Both players synced, trying to play TSF Jazz:
    Something is odd here - there is indication of direct streaming (which cannot happen if synced) and no direct streaming.

    You have snipped the log which sometimes is not good as often what is missing from the log is important.

    For log files it is better to note time when starting test and wait for about 30 secs after finishing - put the log lines between those times into a text file (no other editing), ZIP the text file and attach to a post.

  2. #22
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    18,876
    If you are testing with a playlist of more than one URL - then it will complicate the log. For log of player.source use the streaming URL such as http://broadcast.infomaniak.net/tsfjazz-high.mp3

  3. #23
    Junior Member
    Join Date
    May 2020
    Posts
    17
    Both players synced, trying to play http://broadcast.infomaniak.net/tsfjazz-high.mp3. Can see network traffic but hear silence. Slimp3 says "Waiting to sync..." on the screen. Left it like this for about 50s. Then play a local file for about 10s, worked fine on both. Then played Bassdrive stream, worked fine on both.

    server.log.zip

  4. #24
    Senior Member
    Join Date
    May 2008
    Location
    Canada
    Posts
    5,836
    Quote Originally Posted by bpa View Post
    Something is odd here - there is indication of direct streaming (which cannot happen if synced) and no direct streaming.

    You have snipped the log which sometimes is not good as often what is missing from the log is important.

    For log files it is better to note time when starting test and wait for about 30 secs after finishing - put the log lines between those times into a text file (no other editing), ZIP the text file and attach to a post.
    The call to Slim::Player::SqueezeBox2::directHeader always happens as it is handling to RESP which is always sent by the player when it receives the headers of the stream, whether it's a local or remote URL. Then, in directHeader you have

    Code:
    sub directHeaders {
    	my $client = shift;
    	my $headers = shift;
    
    	main::INFOLOG && $directlog->is_info && $directlog->info("Processing headers for direct streaming:\n$headers");
    
    	my $controller = $client->controller()->songStreamController();
    	my $handler    = $controller ? $controller->protocolHandler() : undef;
    	
    	if ($handler && $handler->can('handlesStreamHeaders')) {
    
    		if ($handler->handlesStreamHeaders($client, $headers)) {
    			return;
    		}
    
    	}
    
    	unless ($controller && $controller->isDirect()) {return;}
            ...
    I unfortunately don't have an answer why streaming does not work, seems that the streaming state machine is stucked waiting for a player's indication that enough data has been received. Maybe it's an issue with old SLIMP3

    A proper sync should look like that
    Code:
    [20-05-26 19:09:24.0651] Slim::Player::Song::open (461) Opening stream (no direct streaming) using Slim::Player::Protocols::HTTP [http://icecast.radiofrance.fr/fip-lofi.mp3?ID=76zqey582k]
    [20-05-26 19:09:24.4474] Slim::Player::Song::open (482) URL is a song (audio): http://icecast.radiofrance.fr/fip-lofi.mp3?ID=76zqey582k, type=mp3
    [20-05-26 19:09:24.4481] Slim::Player::StreamingController::_Stream (1282) c8:2b:96:88:1e:0c: stream
    [20-05-26 19:09:24.4490] Slim::Player::StreamingController::_Stream (1282) 00:04:20:1e:07:f2: stream
    [20-05-26 19:09:24.4493] Slim::Player::Boom::play (342) Setting LineIn to 0 for [http://icecast.radiofrance.fr/fip-lofi.mp3?ID=76zqey582k]
    [20-05-26 19:09:24.4507] Slim::Player::StreamingController::_setPlayingState (2377) new playing state BUFFERING
    [20-05-26 19:09:24.4511] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state STREAMING
    [20-05-26 19:09:24.5428] Slim::Player::StreamingController::playerBufferReady (2278) 00:04:20:1e:07:f2
    [20-05-26 19:09:24.5432] Slim::Player::StreamingController::_setPlayingState (2377) new playing state WAITING_TO_SYNC
    [20-05-26 19:09:24.5736] Slim::Player::Player::_buffering (1144) Buffering... 0 / 12288
    [20-05-26 19:09:24.5756] Slim::Player::Player::_buffering (1144) Buffering... 13140 / 12288
    [20-05-26 19:09:24.5764] Slim::Player::Player::_buffering (1145)   +output... 2434744 / 1058400
    [20-05-26 19:09:24.7881] Slim::Player::StreamingController::playerBufferReady (2278) c8:2b:96:88:1e:0c
    [20-05-26 19:09:24.7886] Slim::Player::Squeezebox2::startAt (1080) c8:2b:96:88:1e:0c startAt: 695433
    [20-05-26 19:09:24.7890] Slim::Player::Squeezebox2::startAt (1080) 00:04:20:1e:07:f2 startAt: 1644357241
    [20-05-26 19:09:24.7893] Slim::Player::StreamingController::_setPlayingState (2377) new playing state PLAYING
    [20-05-26 19:09:24.7897] Slim::Player::StreamingController::_Playing (368) Song 0 has now started playing
    [20-05-26 19:09:24.7901] Slim::Player::StreamingController::_Playing (397) Song queue is now 0
    [20-05-26 19:09:25.0349] Slim::Player::StreamingController::playerTrackStarted (2200) 00:04:20:1e:07:f2
    [20-05-26 19:09:25.9160] Slim::Player::StreamingController::playerTrackStarted (2200) c8:2b:96:88:1e:0c
    And in you case, the 2nd player (d0:7e:35:3a:12:f4) never sends the STMl event that triggers the "playerBufferReady" call ... so

    [edit]: oh... I just realized you said "squeezelite on my desktop" is the 2nd player. Smells like when you do sync, this player now has to get the audio through the network loopback interface of that desktop and it might be that it's getting blocked there (as it seems to never receive data). It might work when transcoding is activated as the pipeline is different
    Last edited by philippe_44; 2020-05-26 at 19:25.
    LMS 7.7, 7.8 and 7.9 - 5xRadio, 3xBoom, 4xDuet, 1xTouch, 1 SB2. Sonos PLAY:3, PLAY:5, Marantz NR1603, JBL OnBeat, XBoxOne, XBMC, Foobar2000, ShairPortW, JRiver 21, 2xChromecast Audio, Chromecast v1 and v2, , Pi B3, B2, Pi B+, 2xPi A+, Odroid-C1, Odroid-C2, Cubie2, Yamaha WX-010, AppleTV 4, Airport Express, GGMM E5

  5. #25
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    18,876
    Quote Originally Posted by philippe_44 View Post
    I unfortunately don't have an answer why streaming does not work, seems that the streaming state machine is stucked waiting for a player's indication that enough data has been received. Maybe it's an issue with old SLIMP3
    I agree, I think it is quite possible SliMP3 is a factor.

    For most of us it is impossible to test as we don't have a SliMP3 and there is no software simulator like SoftSqueeze for odler SB.

    IIRC SliMP3 uses a slightly different network & sync protocol so there are different code paths and SliMP3 causes big problems when Touch was released as the very small SliMP3 buffer (vs Touch or squeezelite very large buffer) means sync is hard to maintain. I can't remember whether high or low data rate stream were most susceptible to network issues..

    It is interesting that sync'ed FLAC stream work OK. I think the areas to check include - What MP3 bit rate was the Flac transcoded into ? Is the transcoded bit rate lower/higher than the MP3 stream that fails ?

    I'll look through the logs later.

  6. #26
    Senior Member
    Join Date
    May 2008
    Location
    Canada
    Posts
    5,836
    Quote Originally Posted by bpa View Post
    I agree, I think it is quite possible SliMP3 is a factor.

    For most of us it is impossible to test as we don't have a SliMP3 and there is no software simulator like SoftSqueeze for odler SB.

    IIRC SliMP3 uses a slightly different network & sync protocol so there are different code paths and SliMP3 causes big problems when Touch was released as the very small SliMP3 buffer (vs Touch or squeezelite very large buffer) means sync is hard to maintain. I can't remember whether high or low data rate stream were most susceptible to network issues..

    It is interesting that sync'ed FLAC stream work OK. I think the areas to check include - What MP3 bit rate was the Flac transcoded into ? Is the transcoded bit rate lower/higher than the MP3 stream that fails ?

    I'll look through the logs later.
    I have a bad habit to edit my messages. I’d you go to the forum, you’ll see that I have what I think is a better hypothesis
    LMS 7.7, 7.8 and 7.9 - 5xRadio, 3xBoom, 4xDuet, 1xTouch, 1 SB2. Sonos PLAY:3, PLAY:5, Marantz NR1603, JBL OnBeat, XBoxOne, XBMC, Foobar2000, ShairPortW, JRiver 21, 2xChromecast Audio, Chromecast v1 and v2, , Pi B3, B2, Pi B+, 2xPi A+, Odroid-C1, Odroid-C2, Cubie2, Yamaha WX-010, AppleTV 4, Airport Express, GGMM E5

  7. #27
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    18,876
    Quote Originally Posted by philippe_44 View Post
    I have a bad habit to edit my messages. I’d you go to the forum, you’ll see that I have what I think is a better hypothesis
    [edit]: oh... I just realized you said "squeezelite on my desktop" is the 2nd player. Smells like when you do sync, this player now has to get the audio through the network loopback interface of that desktop and it might be that it's getting blocked there (as it seems to never receive data). It might work when transcoding is activated as the pipeline is different
    Assuming this is the edit. If I understand you correctly. If it is the network loopback interface - then OP should try squeezelite on another system not running LMS. IF problem persist then it is not loopback related on LMS system.

  8. #28
    Junior Member
    Join Date
    May 2020
    Posts
    17
    Squeezelite has always been running on a different system to LMS. I have tried it on two different systems.

    FLAC was transcoded to 320k MP3 if my reading of this is correct:

    [20-05-26 23:32:42.3947] Slim::Player::Song::open (558) Tokenized command: "/usr/share/squeezeboxserver/Bin/x86_64-linux/flac" -dcs -- "/home/stuff/mp3s/television/01 See No Evil.flac" | "/bin/lame" --silent -q 9 --abr 320 - - & |


    TSF Jazz and Bassdrive are both 128k MP3.

  9. #29
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    18,876
    Quote Originally Posted by troffasky View Post
    Squeezelite has always been running on a different system to LMS. I have tried it on two different systems.

    FLAC was transcoded to 320k MP3 if my reading of this is correct:

    [20-05-26 23:32:42.3947] Slim::Player::Song:pen (558) Tokenized command: "/usr/share/squeezeboxserver/Bin/x86_64-linux/flac" -dcs -- "/home/stuff/mp3s/television/01 See No Evil.flac" | "/bin/lame" --silent -q 9 --abr 320 - - & |


    TSF Jazz and Bassdrive are both 128k MP3.
    Thanks for clarification - I think the issue being checked is why is Squeelizte buffer not being filled. Assumption is 65536 is the SlIMP3 buffer threshold and 180224 is the squeezelite threshold
    Code:
    [20-05-26 23:31:55.7623] Slim::Player::Player::_buffering (1144) Buffering... 36200 / 65536
    [20-05-26 23:31:55.7632] Slim::Player::Player::_buffering (1144) Buffering... 0 / 180224
    [20-05-26 23:31:55.8260] Slim::Player::StreamingController::playerBufferReady (2278) 00:04:20:04:12:ff
    [20-05-26 23:31:55.8262] Slim::Player::StreamingController::_setPlayingState (2377) new playing state WAITING_TO_SYNC
    [20-05-26 23:31:56.0633] Slim::Player::Player::_buffering (1144) Buffering... 129400 / 65536
    [20-05-26 23:31:56.0640] Slim::Player::Player::_buffering (1144) Buffering... 0 / 180224
    [20-05-26 23:31:56.3641] Slim::Player::Player::_buffering (1144) Buffering... 129400 / 65536
    [20-05-26 23:31:56.3648] Slim::Player::Player::_buffering (1144) Buffering... 135510 / 180224
    [20-05-26 23:31:56.6650] Slim::Player::Player::_buffering (1144) Buffering... 129400 / 65536
    [20-05-26 23:31:56.6656] Slim::Player::Player::_buffering (1144) Buffering... 141302 / 180224
    [20-05-26 23:31:56.9609] Slim::Player::TranscodingHelper::getConvertCommand2 (442) Error: Didn't find any command matches for type: mp3
    [20-05-26 23:31:56.9659] Slim::Player::Player::_buffering (1144) Buffering... 129400 / 65536
    [20-05-26 23:31:56.9667] Slim::Player::Player::_buffering (1144) Buffering... 144000 / 180224
    .
    .
    .
    [20-05-26 23:32:42.1104] Slim::Player::Player::_buffering (1144) Buffering... 129400 / 65536
    [20-05-26 23:32:42.1114] Slim::Player::Player::_buffering (1144) Buffering... 144000 / 180224
    I know transcoding fairly well but I am not that familiar with sync stuff. I think Philippe has worked a lot with Sync through Groups plugin.

    Normally playing will not start until threshold is reached so question is why is more data not being sent to Squeezelite - Possibilities: is it because no data available to send from input source or because can't send data because of network issue ??

    Can you check if any difference depending on which player is Master ?

    To check buffer theory I'll see if there are problems when syncing with squeezelite with a small internal buffer.

  10. #30
    Senior Member
    Join Date
    Oct 2005
    Location
    Ireland
    Posts
    18,876
    If I start Squeezelite with "-b 32:64" which is internal buffer of 32kbytes and output buffer of 64kbytes (v. small maybe worse than SliMP3) and try to play an MP3. No syncing. Get a similar behaviour to problem (i.e. stream does not play) - internal buffer seems to be too small to reach threshold to start playing. Now to figure whether it is relevant and if so how to fix the sync issue.
    Code:
    [20-05-27 11:20:32.4969] Slim::Player::Song::open (482) URL is a song (audio): http://icecast1.rte.ie/ieradio1, type=mp3
    [20-05-27 11:20:32.4979] Slim::Player::StreamingController::_Stream (1282) 74:da:38:a6:39:77: stream
    [20-05-27 11:20:32.5002] Slim::Player::StreamingController::_Stream (1319) Song queue is now 0
    [20-05-27 11:20:32.5005] Slim::Player::StreamingController::_setPlayingState (2377) new playing state BUFFERING
    [20-05-27 11:20:32.5008] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state STREAMING
    [20-05-27 11:20:32.6246] Slim::Player::Player::_buffering (1144) Buffering... 0 / 61440
    [20-05-27 11:20:32.9253] Slim::Player::Player::_buffering (1144) Buffering... 0 / 61440
    [20-05-27 11:20:33.2260] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:33.5265] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:33.8269] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:34.1275] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:34.4281] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:34.7288] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:34.8763] Slim::Player::TranscodingHelper::getConvertCommand2 (442) Error: Didn't find any command matches for type: mp3
    [20-05-27 11:20:35.0295] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:35.3301] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:35.6307] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440
    [20-05-27 11:20:35.9314] Slim::Player::Player::_buffering (1144) Buffering... 32767 / 61440

Tags for this Thread

Posting Permissions

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