I've also commented a typical log and highlighted the issue
Code:
--------------------
==> user tells LMS to play the Beatles
[19:25:42.618675] process_strm:307 [0xbb9f80], strm s autostart: 1 transition
period: 10 transition type: 0 codec: f
[19:25:42.618710] sendSTAT:169 [0xbb9f80]: STAT:[STMf] msplayed 0
[19:25:42.892043] sq_get_metadata:525 [0xbb9f80]: idx 0
artist:The Beatles
[19:25:42.892285] output_start:81 [0xbb9f80]: start thread 0
==> set Sonos main context
[19:25:42.892431] sq_callback:375 [0xc41840]: set current URI (s:0)
http://192.168.1.10:54937/bridge-1.flac
[19:25:42.892579] AVTSetURI:91 [0xc41840]: uPNP setURI
http://192.168.1.10:54937/bridge-1.flac (cookie 0x1)
[19:25:42.892921] process_start:1202 [0xbb9f80]: codec:c, ch:0, s:0, r:0
==> bridge get audio from LMS
[19:25:42.893273] stream_sock:592 [0xbb9f80] header: GET
/stream.mp3?player=bb:bb:5c:d2:74:b4 HTTP/1.0
[19:25:42.900422] ActionHandler:821 [0xc41840]: Waited action
SetAVTransportURIResponse
[19:25:42.919830] stream_thread:337 [0xbb9f80] headers: len: 494
HTTP/1.1 200 OK
Server: Logitech Media Server (8.1.1 - 1610364019)
Connection: close
Content-Type: audio/x-flac
[19:25:42.921765] AVTPlay:151 [0xc41840]: uPNP play (cookie 0x3)
[19:25:42.933133] ActionHandler:821 [0xc41840]: Waited action PlayResponse
[19:25:42.941035] output_http_thread:140 [0xbb9f80]: got HTTP connection 12
==> Sonos gets audio from bridge
[19:25:43.042074] handle_http:467 [0xbb9f80]: received GET /bridge-1.flac
HTTP/1.1
[19:25:43.042163] handle_http:470 [0xbb9f80]: HTTP headers
CONNECTION: close
Host: 192.168.1.10:54937
ACCEPT: */*
USER-AGENT: Linux UPnP/1.0 Sonos/61.1-85090 (ZPS17)
[19:25:43.042332] handle_http:552 [0xbb9f80]: responding:
HTTP/1.1 200 OK
Server: squeezebox-bridge
Connection: close
Content-Type: audio/flac
Transfer-Encoding: chunked
[19:25:44.204407] _SyncNotifState:671 Sonos Move: uPNP playing
[19:25:44.204508] sq_notify:605 [0xbb9f80] play notification
[19:25:44.204709] sq_notify:698 [0xbb9f80] time 0 0
[19:25:44.204821] ActionHandler:882 [0xc41840]: position 0 (cookie 0x5)
[19:25:44.204866] sq_notify:722 [0xbb9f80] track 1 started at 460737078
==> bridge received all Beatles from LMS
[19:25:44.624418] stream_thread:411 [0xbb9f80] end of stream (t:7300051)
==> tell LMS we are ready for next
[19:25:44.720567] decode_thread:96 decode complete
[19:25:45.303311] sendSTAT:169 [0xbb9f80]: STAT:[STMd] msplayed 0
==> LMS plays Mogwai (next)
[19:25:45.408987] process_strm:307 [0xbb9f80], strm s autostart: 1 transition
period: 10 transition type: 0 codec: f
[19:25:45.460464] sq_get_metadata:525 [0xbb9f80]: idx 1
artist:Mogwai
[19:25:45.460692] output_start:81 [0xbb9f80]: start thread 1
==> set Sonos queue context with Mogwai
[19:25:45.460916] sq_callback:369 [0xc41840]: next URI gapless
http://192.168.1.10:32961/bridge-2.flac
[19:25:45.461109] AVTSetNextURI:112 [0xc41840]: uPNP setNextURI
http://192.168.1.10:32961/bridge-2.flac (cookie 0x8)
==> bridge gets Mogwai from LMS
[19:25:45.461690] stream_sock:592 [0xbb9f80] header: GET
/stream.mp3?player=bb:bb:5c:d2:74:b4 HTTP/1.0
[19:25:45.531295] stream_thread:337 [0xbb9f80] headers: len: 494
HTTP/1.1 200 OK
Server: Logitech Media Server (8.1.1 - 1610364019)
Connection: close
Content-Type: audio/x-flac
==> Sonos received all Beatles from bridge
[19:25:45.559338] output_http_thread:372 [0xbb9f80]: end thread 0 (7300051
bytes)
[19:25:45.610527] ActionHandler:821 [0xc41840]: Waited action
SetNextAVTransportURIResponse
==> Sonos informs the bridge of Beatles timer progress
[19:25:49.201855] sq_notify:698 [0xbb9f80] time 5000 5000
[19:26:59.240395] sq_notify:698 [0xbb9f80] time 75000 75000
==> Sonos requests Mogwai from bridge
[19:27:22.285004] output_http_thread:140 [0xbb9f80]: got HTTP connection 10
[19:27:22.285693] handle_http:467 [0xbb9f80]: received GET /bridge-2.flac
HTTP/1.1
[19:27:22.285735] handle_http:470 [0xbb9f80]: HTTP headers
CONNECTION: close
Host: 192.168.1.10:32961
ACCEPT: */*
USER-AGENT: Linux UPnP/1.0 Sonos/61.1-85090 (ZPS17)
[19:27:22.285850] handle_http:552 [0xbb9f80]: responding:
HTTP/1.1 200 OK
Server: squeezebox-bridge
Connection: close
Content-Type: audio/flac
Transfer-Encoding: chunked
[19:27:23.253225] sq_notify:698 [0xbb9f80] time 99000 99000
==> bridge received all Mogwai from LMS
[19:27:33.117007] stream_thread:411 [0xbb9f80] end of stream (t:35756704)
[19:27:33.259105] sq_notify:698 [0xbb9f80] time 110000 110000
==> tell LMS we are ready for more
[19:27:33.724286] decode_thread:96 decode complete
[19:27:35.259968] sq_notify:698 [0xbb9f80] time 112000 112000
[19:27:35.627112] output_http_thread:241 [0xbb9f80]: self-exit
==> Sonos received all Mogwai from bridge (that was fast!!!)
[19:27:35.627760] output_http_thread:372 [0xbb9f80]: end thread 1 (35756704
bytes)
[19:27:36.260316] sq_notify:698 [0xbb9f80] time 113000 113000
==> bridge detects that Sonos has finished *playing* Beatles and has
*started* Mogwai
==> no trace of Sonos "thinking and playing"
[19:27:41.262235] sq_notify:698 [0xbb9f80] time 117058 0
[19:27:41.262348] ActionHandler:882 [0xc41840]: position 0 (cookie 0x159)
[19:27:41.262400] sq_notify:722 [0xbb9f80] track 2 started at 460854136
==> bridge tells LMS that Mogwai has started
[19:27:41.262474] sendSTAT:169 [0xbb9f80]: STAT:[STMs] msplayed 0
==> bridge tells LMS that all Mogwai has been sent
[19:27:41.262598] sendSTAT:169 [0xbb9f80]: STAT:[STMd] msplayed 0
==> LMS plays Mojave 3 (next)
[19:27:41.391209] process_strm:307 [0xbb9f80], strm s autostart: 1 transition
period: 10 transition type: 0 codec: f
[19:27:41.406153] sq_get_metadata:525 [0xbb9f80]: idx 2
artist:Mojave 3
[19:27:41.406391] output_start:81 [0xbb9f80]: start thread 0
==> set Sonos queue context with Mojave 3
[19:27:41.406588] sq_callback:369 [0xc41840]: next URI gapless
http://192.168.1.10:40005/bridge-3.flac
[19:27:41.406734] AVTSetNextURI:112 [0xc41840]: uPNP setNextURI
http://192.168.1.10:40005/bridge-3.flac (cookie 0x15b)
==> bridges request Mojav 3 from LMS
[19:27:41.407363] stream_sock:592 [0xbb9f80] header: GET
/stream.mp3?player=bb:bb:5c:d2:74:b4 HTTP/1.0
[19:27:41.430280] stream_thread:337 [0xbb9f80] headers: len: 494
HTTP/1.1 200 OK
Server: Logitech Media Server (8.1.1 - 1610364019)
Connection: close
Content-Type: audio/x-flac
[19:27:41.532330] ActionHandler:821 [0xc41840]: Waited action
SetNextAVTransportURIResponse
==> Sonos request Mojave 3 from the bridge
[19:27:41.538429] handle_http:467 [0xbb9f80]: received GET /bridge-3.flac
HTTP/1.1
[19:27:41.538472] handle_http:470 [0xbb9f80]: HTTP headers
CONNECTION: close
Host: 192.168.1.10:40005
ACCEPT: */*
USER-AGENT: Linux UPnP/1.0 Sonos/61.1-85090 (ZPS17)
X-Sonos-SWGen: 2
[19:27:41.538612] handle_http:552 [0xbb9f80]: responding:
HTTP/1.1 200 OK
Server: squeezebox-bridge
Connection: close
Content-Type: audio/flac
Transfer-Encoding: chunked
==> no trace of timer progress on Mogwai
==> Sonos tells bridge that it is "thinking" than "playing"
[19:27:41.762484] _SyncNotifState:621 [0xc41840]: uPNP transition
[19:27:42.264452] _SyncNotifState:671 Sonos Move: uPNP playing
[19:27:42.264576] sq_notify:605 [0xbb9f80] play notification
[19:27:42.265098] sq_notify:698 [0xbb9f80] time 0 0
[19:27:42.265223] ActionHandler:882 [0xc41840]: position 0 (cookie 0x15d)
==> Sonos tells the bridge that is has started to play Mojave 3
[19:27:42.265269] sq_notify:722 [0xbb9f80] track 3 started at 460855139
==> Sonos timer progress
[19:27:43.264923] sq_notify:698 [0xbb9f80] time 1000 1000
[19:27:48.023266] stream_thread:411 [0xbb9f80] end of stream (t:25120628)
[19:27:48.266503] sq_notify:698 [0xbb9f80] time 6000 6000
==> user press "stop"
[19:27:48.322737] process_strm:241 [0xbb9f80] strm command q
[19:27:48.322770] decode_flush:208 [0xbb9f80]: decode flush
[19:27:48.328259] output_http_thread:372 [0xbb9f80]: end thread 0 (19136512
bytes)
[19:27:48.328992] output_flush:580 [0xbb9f80]: flush output buffer
[19:27:48.329105] AVTStop:217 [0xc41840]: uPNP stop (cookie 0x171)
[19:27:48.424781] ActionHandler:821 [0xc41840]: Waited action StopResponse
[19:27:48.765258] _SyncNotifState:643 [0xc41840]: uPNP stop
[19:27:48.765360] sq_notify:658 [0xbb9f80] notify STOP
--------------------
LMS 8.1.x on Odroid-C4 - *SqueezeAMP!*, 5xRadio, 5xBoom, 2xDuet,
1xTouch, 1xSB3. Sonos PLAY:3, PLAY:5, Marantz NR1603, Foobar2000,
ShairPortW, 2xChromecast Audio, Chromecast v1 and v2, Squeezelite on Pi,
Yamaha WX-010, AppleTV 4, Airport Express, GGMM E5, RivaArena 1 & 3
------------------------------------------------------------------------
philippe_44's Profile: http://forums.slimdevices.com/member.php?userid=17261
View this thread: http://forums.slimdevices.com/showthread.php?t=103728
_______________________________________________
plugins mailing list
plugins@lists.slimdevices.com
http://lists.slimdevices.com/mailman/listinfo/plugins
