I figured the best way to explain the failure mode I am experiencing is
to combine/correlate data from LMS logs, squeezelite logs and network
traffic capture. Please note that Wireshark is running on the client
machine so Wireshark and squeezelite timestamps match, time on LMS
machine is ~2 secs ahead.
squeezelite startup and buffer sizes:
Code:
--------------------
D:\squeezelite-x64.exe -n Callisto -s lms.network.lan -C 60 -o Topping E30
(2- TOPPING USB DAC) [Windows WASAPI] -m 00:02:c9:13:08:d0 -M Squeezelite-X -d
all=sdebug -f squeezelite.log
[01:10:28.996] stream_init:454 init stream
[01:10:28.996] stream_init:455 streambuf size: 2097152
[01:10:28.996] output_init_pa:573 init output
[01:10:28.996] output_init_pa:593 requested latency: 0
[01:10:29.043] output_init_common:360 outputbuf size: 3528000
[01:10:29.043] output_init_common:384 idle timeout: 60000
[01:10:29.090] output_init_common:432 supported rates: 44100
--------------------
strm command s, STMc and start of data flow. Everything appears to be
working fine here.
Code:
--------------------
[01:10:40.529] process:528 strm
[01:10:40.529] process_strm:280 strm command s
[01:10:40.529] process_strm:350 strm s autostart: 1 transition period: 10
transition type: 0 codec: m
[01:10:40.529] sendSTAT:171 ms_played: 0
[01:10:40.529] sendSTAT:195 STAT: STMf
[01:10:40.529] sendSTAT:200 received bytesL: 0 streambuf: 0 outputbuf: 0 calc
elapsed: 0 real elapsed: 1655165750 (diff: -1655165750) device: 0 delay:
1655165750
[01:10:40.529] codec_open:264 codec open: 'm'
[01:10:40.529] connect_socket:164 connecting to 192.168.10.17:9000
[01:10:40.544] stream_sock:600 header: GET
/stream.mp3?player=00:02:c9:13:08:d0 HTTP/1.0
[01:10:40.544] sendSTAT:171 ms_played: 0
[01:10:40.544] sendSTAT:195 STAT: STMc
[01:10:40.544] sendSTAT:200 received bytesL: 0 streambuf: 0 outputbuf: 0 calc
elapsed: 0 real elapsed: 1655165765 (diff: -1655165765) device: 0 delay:
1655165765
[01:10:40.544] process_strm:384 set fade mode: 0, channels: 0, invert: 0
[01:10:40.544] process:528 audg
[01:10:40.544] process_audg:440 audg gainL: 37120 gainR: 37120 adjust: 1
[01:10:40.544] set_volume:111 setting internal gain left: 37120 right: 37120
[01:10:40.638] send_header:131 wrote 53 bytes to socket
[01:10:40.638] send_header:135 wrote header
[01:10:40.638] stream_thread:331 headers: len: 491
HTTP/1.1 200 OK
Server: Logitech Media Server (8.1.1 - 1610364019)
Connection: close
Content-Type: audio/mpeg
Set-Cookie: Squeezebox-albumView=; path=/
Set-Cookie: Squeezebox-expandPlayerControl=true; path=/
Set-Cookie: Squeezebox-expanded-MY_MUSIC=1; path=/
Set-Cookie: Squeezebox-expanded-FAVORITES=1; path=/
Set-Cookie: Squeezebox-expanded-PLUGINS=1; path=/
Set-Cookie: Squeezebox-expanded-PLUGIN_MY_APPS_MODULE_NAME=1; path=/
Set-Cookie: Squeezebox-expanded-RADIO=1; path=/
[01:10:40.638] sendRESP:226 RESP
[01:10:40.638] stream_thread:428 streambuf read 7300 bytes
-<-- first data arriving-
[01:10:40.638] stream_thread:428 streambuf read 5840 bytes
--------------------
Code:
--------------------
[21-06-01 01:10:42.4957] Slim::Player::StreamingController::_Stream (1213)
00:02:c9:13:08:d0: preparing to stream song index 0
[21-06-01 01:10:42.4959] Slim::Player::Song::open (360)
file:///mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05%20-%20Led%20Zeppelin%20-%20Carouselambra.mp3
[21-06-01 01:10:42.4963] Slim::Player::TranscodingHelper::enabledFormat (231)
Checking to see if mp3-mp3-*-* is enabled
[21-06-01 01:10:42.4965] Slim::Player::TranscodingHelper::checkBin (264)
Checking formats for: mp3-mp3-*-*
[21-06-01 01:10:42.4966] Slim::Player::TranscodingHelper::enabledFormat (231)
Checking to see if mp3-mp3-*-* is enabled
[21-06-01 01:10:42.4967] Slim::Player::TranscodingHelper::checkBin (272)
enabled
[21-06-01 01:10:42.4969] Slim::Player::TranscodingHelper::checkBin (274)
Found command: -
[21-06-01 01:10:42.4971] Slim::Player::TranscodingHelper::getConvertCommand2
(488) Matched: mp3->mp3 via: -
[21-06-01 01:10:42.4972] Slim::Player::Song::open (384) seek=false time=0
canSeek=1
[21-06-01 01:10:42.4975] Slim::Player::TranscodingHelper::enabledFormat (231)
Checking to see if mp3-mp3-*-* is enabled
[21-06-01 01:10:42.4977] Slim::Player::TranscodingHelper::checkBin (264)
Checking formats for: mp3-mp3-*-*
[21-06-01 01:10:42.4978] Slim::Player::TranscodingHelper::enabledFormat (231)
Checking to see if mp3-mp3-*-* is enabled
[21-06-01 01:10:42.4979] Slim::Player::TranscodingHelper::checkBin (272)
enabled
[21-06-01 01:10:42.4980] Slim::Player::TranscodingHelper::checkBin (274)
Found command: -
[21-06-01 01:10:42.4982] Slim::Player::TranscodingHelper::getConvertCommand2
(488) Matched: mp3->mp3 via: -
[21-06-01 01:10:42.4983] Slim::Player::Song::open (414) Transcoder:
streamMode=I, streamformat=mp3
[21-06-01 01:10:42.4985] Slim::Player::Song::open (470) Opening stream (no
direct streaming) using Slim::Player::Protocols::File
[file:///mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05%20-%20Led%20Zeppelin%20-%20Carouselambra.mp3]
[21-06-01 01:10:42.4990] Slim::Player::Protocols::File::open (80) duration:
[634.333] size: [19354603] endian [] offset: [35733] for
file:///mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05%20-%20Led%20Zeppelin%20-%20Carouselambra.mp3
[21-06-01 01:10:42.4991] Slim::Player::Protocols::File::open (97) Opening
file /mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05 -
Led Zeppelin - Carouselambra.mp3
[21-06-01 01:10:42.5002] Slim::Player::Protocols::File::open (189) Seeking in
35733 into
/mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05 - Led
Zeppelin - Carouselambra.mp3
[21-06-01 01:10:42.5004] Slim::Player::Song::open (491) URL is a song
(audio):
file:///mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05%20-%20Led%20Zeppelin%20-%20Carouselambra.mp3,
type=mp3
[21-06-01 01:10:42.5058] Slim::Player::Squeezebox::sendFrame (1133) sending
squeezebox frame: audg, length: 22
[21-06-01 01:10:42.5059] Slim::Networking::Select::_writeNoBlock (72) fileno:
[28] Wrote 28 bytes
[21-06-01 01:10:42.5061] Slim::Player::StreamingController::_Stream (1282)
00:02:c9:13:08:d0: stream
[21-06-01 01:10:42.5064] Slim::Player::Squeezebox::stream_s (542) stream_s
called: format: mp3 url:
file:///mnt/media/music/popular/Led.Zeppelin/In.Through.the.Out.Door.(1979)/05%20-%20Led%20Zeppelin%20-%20Carouselambra.mp3
[21-06-01 01:10:42.5067] Slim::Player::Squeezebox::stream_s (907) flags: 0
[21-06-01 01:10:42.5068] Slim::Player::Squeezebox::stream_s (933) Using smart
transition mode
[21-06-01 01:10:42.5070] Slim::Player::Squeezebox::stream_s (993) Starting
decoder with format: m flags: 0x0 autostart: 1 buffer threshold: 255 output
threshold: 1 samplesize: ? samplerate: ? endian: ? channels: ?
[21-06-01 01:10:42.5072] Slim::Player::Squeezebox::stream_s (1024) sending
strm frame of length: 77 request string: [GET
/stream.mp3?player=00:02:c9:13:08:d0 HTTP/1.0
]
...
[21-06-01 01:10:42.5187] Slim::Networking::Slimproto::_stat_handler (778)
FACTORYTEST event=stat mac=00:02:c9:13:08:d0 signalstrength=65535
[21-06-01 01:10:42.5188] Slim::Networking::Slimproto::_stat_handler (784)
00:02:c9:13:08:d0: STAT-STMc: fullness=0, output_fullness=-1, elapsed=0.000
[21-06-01 01:10:42.5190] Slim::Networking::Slimproto::_stat_handler (811)
00:02:c9:13:08:d0 Squeezebox stream status:
event_code: STMc
bytes_rec_H 0
bytes_rec_L 0
fullness: 0 (0%)
bufferSize 2097152
fullness 0
bytes_received 0
signal_strength: 65535
jiffies: 1655165765
voltage: 0
[21-06-01 01:10:42.5191] Slim::Networking::Slimproto::_stat_handler (823)
output size: 3528000
output fullness: 0
elapsed seconds: 0
[21-06-01 01:10:42.5192] Slim::Networking::Slimproto::_stat_handler (835)
elapsed milliseconds: 0
server timestamp: 0
...
[21-06-01 01:10:42.6071] Slim::Web::HTTP::processHTTP (342) Reading request...
[21-06-01 01:10:42.6078] Slim::Web::HTTP::processHTTP (359) HTTP request:
from 192.168.10.100:60755 (Slim::Web::HTTP::ClientConn=GLOB(0x5615ba8704c0))
for GET HTTP/1.0 /stream.mp3?player=00:02:c9:13:08:d0
[21-06-01 01:10:42.6081] Slim::Web::HTTP::processHTTP (366) Raw request
headers: [
GET /stream.mp3?player=00:02:c9:13:08:d0 HTTP/1.0
]
...
[21-06-01 01:10:42.6097] Slim::Web::HTTP::processURL (782) processURL
Clients: 192.168.10.100:60754
[21-06-01 01:10:42.6108] Slim::Web::HTTP::generateHTTPResponse (1037)
Generating response for (mp3, audio/mpeg) stream.mp3
[21-06-01 01:10:42.6111] Slim::Web::HTTP::generateHTTPResponse (1181)
Disabling keep-alive for stream.mp3
[21-06-01 01:10:42.6127] Slim::Web::HTTP::processHTTP (735) Response Headers:
[
HTTP/1.1 200 OK
Connection: close
Content-Type: audio/mpeg
Set-Cookie: Squeezebox-albumView=; path=/
Set-Cookie: Squeezebox-expandPlayerControl=true; path=/
Set-Cookie: Squeezebox-expanded-MY_MUSIC=1; path=/
Set-Cookie: Squeezebox-expanded-FAVORITES=1; path=/
Set-Cookie: Squeezebox-expanded-PLUGINS=1; path=/
Set-Cookie: Squeezebox-expanded-PLUGIN_MY_APPS_MODULE_NAME=1; path=/
Set-Cookie: Squeezebox-expanded-RADIO=1; path=/
]
[21-06-01 01:10:42.6129] Slim::Web::HTTP::processHTTP (738) End request:
keepAlive: [] - waiting for next request for
Slim::Web::HTTP::ClientConn=GLOB(0x5615ba8704c0) on connection = close
[21-06-01 01:10:42.6133] Slim::Web::HTTP::sendStreamingResponse (2168)
sendStreaming response begun...
[21-06-01 01:10:42.6137] Slim::Web::HTTP::sendStreamingResponse (2425)
Streamed 491 to 192.168.10.100 <-- first data sent
--------------------
34902
+-------------------------------------------------------------------+
|Filename: flow_01_start.jpg |
|Download: http://forums.slimdevices.com/attachment.php?attachmentid=34902|
+-------------------------------------------------------------------+
------------------------------------------------------------------------
lngxa's Profile: http://forums.slimdevices.com/member.php?userid=71826
View this thread: http://forums.slimdevices.com/showthread.php?t=114661
_______________________________________________
Squeezecenter mailing list
[email protected]
http://lists.slimdevices.com/mailman/listinfo/squeezecenter
