bpa wrote: 
> More investigation is needed.

I tried to compare the behavior with the playback of a remote file from
the audio archive of Slovak Radio (RTVS). LMS plays back these files
without any problem and they are served by the webserver through
HTTP/1.1 as well, see the curl logs (on the left is still the same file
from Czech Radio iRadio archive <'3959575.mp3'
(http://media.rozhlas.cz/stream/_audio/3959575.mp3)> and on the right is
the file from Slovak Radio archive <'00149534-1.mp3'


Then I got network captures for both the files (using the Microsoft
Message Analyzer), see this 'PDF file'

The network trace for the Slovak Radio shows that the remote file was
sent as several TCP segments (Message Numbers 89 to 246) and right after
it the LMS closed the connection with a single RST packet (Message
#247). The server does not sending any further data after this RST flag.
Since the file is played back until the end by LMS, I assume the server
is correctly representing the Content-Length in this case (57592896
bytes, see in line of Message #89 in the "Headers["Content-Length"]"

On the other hand, the server response with data of the Czech Radio
remote file formed with the TCP segments of Message Numbers 433 to 615
is interrupted by LMS sending the RST packet (Message #590). After this
RST packet, there are a couple of more data packets (HTTP Payload) in
lines #591-615 sent from the radio server, but without any
acknowledgedment by LMS. Since the playback by LMS is always terminated
after elapsing of ~10MB, my guess is that reading data from the CRo
iRadio server end without reading entire data. It may be happening that
the the radio server is saying that the Content-Length is 56058880 bytes
(see in line of Message #433 in the "Headers["Content-Length"]" column),
while the actual data read is only ~10 MB. This would cause LMS to read
fewer bytes than the Content-Length property implied.

Unfortunately, I'm not able to find out from the network trace if the
server sent the whole data (of declared Content-Length size) or not.
Therefore I can't say, looking at the network trace, whether the
Content-Length exactly matches the number of bytes read from the

I think it would help to set a debugger break into a relevant code in
LMS, when this happened, to see the number of bytes that were actually

Relevant previous observations:
- findings by Michael and bpa (previous posts, especially 'post #'
- appearing of "EndOfStream" message and a line from playerEndOfStream
module in the LMS log.
- error message appearing in the log of ffmpeg (see 'post #10'

  C:\WinAPP\ffmpeg\bin>ffmpeg -loglevel trace -i 
http://media.rozhlas.cz/stream/_audio/3959575.mp3 -f mp3 pipe:play | ffplay -i 
  ffmpeg version N-86723-g3b3501f Copyright (c) 2000-2017 the FFmpeg developers
  [http @ 0000000000d66c20] Stream ends prematurely at 10190801, should be 
56058880:  0.000 fd=   0 aq=   20KB vq=    0KB sq=    0B f=0/0
  http://media.rozhlas.cz/stream/_audio/3959575.mp3: I/O error
  [out_0_0 @ 000000000274df20] EOF on sink link out_0_0:default.
  No more output streams to write to, finishing.

- listing of points of reconnection at regular intervals of ~10MB
fragments in the log of ffmpeg using -reconnect option (see 'post #1'
and a complete log 'here'

mherger wrote: 
> I might need to look into supporting the partial content streams.
I checked supporting of the partial content streams by LMS when playing
the remote file (<3959575.mp3> from Czech Radio) from a certain
position. It works fine but the playback is again terminated after
elapsing of the first ~10MB segment (plus the buffer of 3518904 bytes):
Playback starting at 18:10 (18m10s) position with termination at 32:09
(within a track/file of total duration 58:23):

  [18:24:49.6225] Slim::Networking::Slimproto::_http_response_handler (554) 
Squeezebox got HTTP response:
  HTTP/1.1 206 Partial Content
  Content-Type: audio/mpeg
  Last-Modified: Mon, 11 Dec 2017 12:05:52 GMT
  Date: Sat, 14 Apr 2018 22:24:31 GMT
  Cache-Control: max-age=30, public, must-revalidate
  X-Cache: HIT
  X-Cache-Hits: 2
  Accept-Ranges: bytes
  Content-Range: bytes 17440000-56058879/56058880
  Content-Length: 38618880
  Connection: close
  Server: Appext/Engine6
  [18:24:49.6241] Slim::Player::Client::streamingProgressBar (1117) 
url=http://media.rozhlas.cz/stream/_audio/3959575.mp3, duration=3503.68, 
bitrate=undef, contentLength=undef
  [18:24:49.6249] Slim::Player::Client::streamingProgressBar (1151) Duration of 
stream set to 3503.68 seconds
  [18:24:49.7194] Slim::Player::Player::_buffering (1140) Buffering... 0 / 
  [18:24:49.7196] Slim::Player::Player::_buffering (1141)   +output... 3518904 
/ 10584000
  [18:35:21.4993] Slim::Player::StreamingController::_eventAction (271) 
00:04:20:12:7b:07: StatusHeartbeat in PLAYING-STREAMING -> 
  [18:35:22.5069] Slim::Networking::Slimproto::_disco_handler (590) Squeezebox 
got disconnection on the data channel: Connection closed normally
  [18:35:22.5073] Slim::Player::StreamingController::playerEndOfStream (2266) 
  [18:35:22.5076] Slim::Player::StreamingController::_eventAction (271) 
00:04:20:12:7b:07: EndOfStream in PLAYING-STREAMING -> 
  [18:35:22.5080] Slim::Player::StreamingController::_setStreamingState (2366) 
new streaming state STREAMOUT
  [18:35:22.5082] Slim::Player::StreamingController::_eventAction (303) 
00:04:20:12:7b:07: EndOfStream - new state PLAYING-STREAMOUT
  [18:35:22.5129] Slim::Networking::Slimproto::_stat_handler (785) 
00:04:20:12:7b:07: STAT-STMt: fullness=3143442, output_fullness=3516280, 
  [18:35:22.5132] Slim::Player::StreamingController::_eventAction (271) 
00:04:20:12:7b:07: StatusHeartbeat in PLAYING-STREAMOUT -> 
  [18:38:47.5027] Slim::Player::StreamingController::_eventAction (271) 
00:04:20:12:7b:07: StatusHeartbeat in PLAYING-IDLE -> 
  [18:38:48.2981] Slim::Networking::Slimproto::_stat_handler (785) 
00:04:20:12:7b:07: STAT-STMu: fullness=0, output_fullness=-1, elapsed=838.103
  [18:38:48.2987] Slim::Player::StreamingController::playerStopped (2157) 
  [18:38:48.2992] Slim::Player::StreamingController::_eventAction (271) 
00:04:20:12:7b:07: Stopped in PLAYING-IDLE -> 
  [18:38:48.2995] Slim::Player::StreamingController::_setPlayingState (2357) 
new playing state STOPPED
  [18:38:48.3001] Slim::Player::StreamingController::_eventAction (303) 
00:04:20:12:7b:07: Stopped - new state STOPPED-IDLE

What do you think bebore I will try to ask the internet service of Czech
Radio to check the server configuration (regarding the premature end of
streamed file)?


|Filename: curl 2x.jpg                                              |
|Download: http://forums.slimdevices.com/attachment.php?attachmentid=24932|

Home server and store: pCP 3.5.0 on RPi 3B in Pi Desktop (Element14)
with Toshiba 256GB mSATA SSD drive
SB player: *Classic* + Corda Headfive + Sennheiser HD555 | Advance
Acoustic MAP-105 + Focal JM.lab Chorus 706 S
SB players (kids): *Touch* + Advance Acoustic MAP-103 | *Radio White*
(Limited Edition)
SB remote control: Squeeze Control on Windows 10 mobiles
aphonia's Profile: http://forums.slimdevices.com/member.php?userid=42513
View this thread: http://forums.slimdevices.com/showthread.php?t=108891

unix mailing list

Reply via email to