search

philippe44 / LMS-Raop

LMS to AirPlay bridge
68 stars 13 forks source link

HomePod #4

Closed simonrb2000 closed 6 years ago

simonrb2000 commented 6 years ago

This isn't working too bad actually, just 2 issues at present which isn't bad for a brand new Apple Product.

Volume Feedback doesn't work is the first. Second which is more important it will only play a song for 3 mins then just stop playing. This doesn't matter is if's local music or the Spotty plugin. I shall post some logs soon.

Cheers!

Edit:-below is the error when it stops playing, which is usually after 3 mins give or take a few mins. I shall remove that plugin and see if that helps :D

Edit 2:- No that didn't help haha.

[18-02-11 14:43:24.6437] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.6581] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.6693] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.6787] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.6895] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.7019] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.7115] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:24.7161] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:25.9076] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:26.3077] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:26.3432] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:26.3538] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:26.3596] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:26.3670] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:26.3717] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.2734] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.3899] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.3995] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.4059] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.4103] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.4227] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:27.4402] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:28.0443] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:28.0564] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:28.0634] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:28.0686] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:28.0783] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628. [18-02-11 14:43:28.0830] Slim::Control::Request::notify (2060) Error: Failed notify: Not a HASH reference at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/SyncOptions/Plugin.pm line 628.

thoukydides commented 6 years ago

I had a similar problem with streaming to my HomePod stopping every minute or so, but that was easily fixed by adding KeyAttr => {} to the XMLout calls in Settings.pm.

http://forums.slimdevices.com/showthread.php?105198-ANNOUNCE-AirPlay-Bridge-integrate-AirPlay-devices-with-LMS-(squeeze2raop)&p=906548&viewfull=1#post906548

Volume controls sometimes work for me, but not consistently.

simonrb2000 commented 6 years ago

Thanks Thoukydides, I shall try that! Volume feedback never works for me.

Didn't work for me. Still get the consistent pause in music on the HomePod.. Thanks anyways

simonrb2000 commented 6 years ago

thoukydides, could you post your Settings.pm file? I maybe I have missed one of the XMLout in mine and thats why mine mutes playback after 3 mins..

thoukydides commented 6 years ago

@simonrb2000, here is the file with my modification: Settings.pm.txt

I only had to modify line 186 for it to run stably on my system. I haven't had it stop once since making that change. However, I suspect that the calls to XMLout on line 69 and to XMLin on line 330 should be similarly modified.

Have you tried turning up the logging level for (plugin.raopbridge) - AirPlay bridge to Debug to get more visibility of the failure you are experiencing? In my case the cause and fix were both pretty obvious from this error message:

No value specified for 'KeyAttr' option in call to XMLout() at /var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/RaopBridge/Settings.pm line 186
simonrb2000 commented 6 years ago

Thanks for the above. Tried your settings and no different. I also have nothing in the log when it pauses. I have set it to debug, Error and Info with none of them showing anything in the log.. Hmm very strange.

simonrb2000 commented 6 years ago

Hope this helps to narrow this down..

[10:44:41.156163] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:41.181916] PlayerThread:393 [0x109cf8]: tick 4289235549 [10:44:41.242782] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025881.1024262144 (ts:164405941362617) [10:44:41.256429] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:41.356615] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:41.456874] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:41.557118] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:41.657361] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:41.728755] PlayerThread:393 [0x107fc8]: tick 4289236096 [10:44:41.732641] PlayerThread:393 [0x107130]: tick 4289236100 [10:44:41.732743] PlayerThread:393 [0x108e60]: tick 4289236100 [10:44:41.757608] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:41.857787] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:41.958044] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:42.007252] sendSTAT:129 [0xb9b48]: ms fr:55477 clk:4289236375 (frames_played: 2545664 device_frames: 99225) [10:44:42.007408] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:42.058297] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:44:42.158571] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:42.182127] PlayerThread:393 [0x109cf8]: tick 4289236550 [10:44:42.244031] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025882.1014497280 (ts:164405941406617) [10:44:42.258849] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:42.359040] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:42.459325] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:42.559622] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:42.659886] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:42.728987] PlayerThread:393 [0x107fc8]: tick 4289237096 [10:44:42.732798] PlayerThread:393 [0x107130]: tick 4289237100 [10:44:42.732919] PlayerThread:393 [0x108e60]: tick 4289237100 [10:44:42.760130] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:42.860342] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:42.902414] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025882.3875714063 (ref 3728025882.3842163887) [10:44:42.960544] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:43.008653] sendSTAT:129 [0xb9b48]: ms fr:56485 clk:4289237376 (frames_played: 2590016 device_frames: 99225) [10:44:43.008759] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:43.160786] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:43.182318] PlayerThread:393 [0x109cf8]: tick 4289237550 [10:44:43.245250] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025883.1004732416 (ts:164405941450617) [10:44:43.261009] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:43.361199] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:43.461464] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:43.561708] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:43.661948] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:43.729210] PlayerThread:393 [0x107fc8]: tick 4289238097 [10:44:43.732994] PlayerThread:393 [0x107130]: tick 4289238100 [10:44:43.733081] PlayerThread:393 [0x108e60]: tick 4289238101 [10:44:43.762197] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:43.862388] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:43.962689] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:44.009938] sendSTAT:129 [0xb9b48]: ms fr:57485 clk:4289238377 (frames_played: 2634016 device_frames: 99225) [10:44:44.010108] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:44.063007] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:44.163314] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:44.182501] PlayerThread:393 [0x109cf8]: tick 4289238550 [10:44:44.246435] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025884.995033088 (ts:164405941494617) [10:44:44.263620] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:44.363903] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:44.464214] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:44.564519] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:44.664792] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:44:44.729475] PlayerThread:393 [0x107fc8]: tick 4289239097 [10:44:44.733141] PlayerThread:393 [0x107130]: tick 4289239101 [10:44:44.733241] PlayerThread:393 [0x108e60]: tick 4289239101 [10:44:44.765093] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:44.865298] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:44.965580] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:45.001715] process:528 [0xb2108] strm [10:44:45.001886] process_strm:236 [0xb2108] strm command t [10:44:45.001937] sendSTAT:134 [0xb2108]: ms_played: 0 [10:44:45.001982] sendSTAT:158 [0xb2108]: STAT: STMt [10:44:45.002852] process:528 [0xb7288] strm [10:44:45.002998] process_strm:236 [0xb7288] strm command t [10:44:45.003065] sendSTAT:134 [0xb7288]: ms_played: 0 [10:44:45.003108] sendSTAT:158 [0xb7288]: STAT: STMt [10:44:45.003522] process:528 [0xb49c8] strm [10:44:45.003594] process_strm:236 [0xb49c8] strm command t [10:44:45.003641] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:44:45.003683] sendSTAT:158 [0xb49c8]: STAT: STMt [10:44:45.004232] process:528 [0xb9b48] strm [10:44:45.004322] process_strm:236 [0xb9b48] strm command t [10:44:45.004371] sendSTAT:129 [0xb9b48]: ms fr:58482 clk:4289239372 (frames_played: 2677664 device_frames: 99225) [10:44:45.004421] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:45.065909] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:45.166242] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:44:45.182708] PlayerThread:393 [0x109cf8]: tick 4289239550 [10:44:45.247675] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025885.1019543552 (ts:164405941538969) [10:44:45.266608] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:45.453484] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025885.1947475610 (ref 3728025885.1939152551) [10:44:45.466964] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:45.567148] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:44:45.667426] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:45.729729] PlayerThread:393 [0x107fc8]: tick 4289240097 [10:44:45.733300] PlayerThread:393 [0x107130]: tick 4289240101 [10:44:45.733404] PlayerThread:393 [0x108e60]: tick 4289240101 [10:44:45.767716] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:45.867931] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:45.968240] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:46.005597] sendSTAT:129 [0xb9b48]: ms fr:59481 clk:4289240373 (frames_played: 2722368 device_frames: 99225) [10:44:46.005759] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:46.068546] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:46.168851] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:46.182899] PlayerThread:393 [0x109cf8]: tick 4289240550 [10:44:46.248894] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025886.1009844224 (ts:164405941582969) [10:44:46.269149] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:44:46.369427] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:46.469707] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:46.569993] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:46.670245] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:46.729979] PlayerThread:393 [0x107fc8]: tick 4289241097 [10:44:46.733464] PlayerThread:393 [0x107130]: tick 4289241101 [10:44:46.733588] PlayerThread:393 [0x108e60]: tick 4289241101 [10:44:46.770603] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:46.870828] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:46.971086] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:47.007023] sendSTAT:129 [0xb9b48]: ms fr:60481 clk:4289241375 (frames_played: 2766368 device_frames: 99225) [10:44:47.007185] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:47.071353] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:47.171626] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:47.183106] PlayerThread:393 [0x109cf8]: tick 4289241551 [10:44:47.250165] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025887.1068630016 (ts:164405941627673) [10:44:47.271898] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:47.372121] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:47.472372] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:47.672716] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:47.730249] PlayerThread:393 [0x107fc8]: tick 4289242098 [10:44:47.733679] PlayerThread:393 [0x107130]: tick 4289242101 [10:44:47.733886] PlayerThread:393 [0x108e60]: tick 4289242101 [10:44:47.760367] raopcl_send_chunk:579 [0x7601a860]: check n:4289242128 p:4289244369 ts:164405941650201 sn:31938 retr: 0, avail: 0, send: 0, select: 0) [10:44:47.772993] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:47.873219] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:47.973489] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:48.008439] sendSTAT:129 [0xb9b48]: ms fr:61486 clk:4289242376 (frames_played: 2810720 device_frames: 99225) [10:44:48.008561] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:48.073709] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:48.096598] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025888.414545948 (ref 3728025888.380522413) [10:44:48.173920] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:48.183274] PlayerThread:393 [0x109cf8]: tick 4289242551 [10:44:48.251345] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025888.1024655360 (ts:164405941671321) [10:44:48.274115] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:48.374247] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:44:48.474428] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:48.574602] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:44:48.674809] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:48.730516] PlayerThread:393 [0x107fc8]: tick 4289243098 [10:44:48.733923] PlayerThread:393 [0x107130]: tick 4289243101 [10:44:48.734029] PlayerThread:393 [0x108e60]: tick 4289243102 [10:44:48.775089] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:48.875276] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:48.975527] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:44:49.009752] sendSTAT:129 [0xb9b48]: ms fr:62486 clk:4289243377 (frames_played: 2854720 device_frames: 99225) [10:44:49.009910] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:49.075791] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:49.176067] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:49.183447] PlayerThread:393 [0x109cf8]: tick 4289243551 [10:44:49.252548] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025889.1049165824 (ts:164405941715673) [10:44:49.276410] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:49.382935] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:49.483194] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:49.583450] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:44:49.683725] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:44:49.730776] PlayerThread:393 [0x107fc8]: tick 4289244098 [10:44:49.734071] PlayerThread:393 [0x107130]: tick 4289244102 [10:44:49.734173] PlayerThread:393 [0x108e60]: tick 4289244102 [10:44:49.784008] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:49.884290] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:49.984566] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:50.002089] process:528 [0xb2108] strm [10:44:50.002263] process_strm:236 [0xb2108] strm command t [10:44:50.002313] sendSTAT:134 [0xb2108]: ms_played: 0 [10:44:50.002357] sendSTAT:158 [0xb2108]: STAT: STMt [10:44:50.003439] process:528 [0xb7288] strm [10:44:50.003571] process_strm:236 [0xb7288] strm command t [10:44:50.003621] sendSTAT:134 [0xb7288]: ms_played: 0 [10:44:50.003665] sendSTAT:158 [0xb7288]: STAT: STMt [10:44:50.004182] process:528 [0xb49c8] strm [10:44:50.004284] process_strm:236 [0xb49c8] strm command t [10:44:50.004333] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:44:50.004624] sendSTAT:158 [0xb49c8]: STAT: STMt [10:44:50.004912] process:528 [0xb9b48] strm [10:44:50.004986] process_strm:236 [0xb9b48] strm command t [10:44:50.005034] sendSTAT:129 [0xb9b48]: ms fr:63482 clk:4289244373 (frames_played: 2898368 device_frames: 99225) [10:44:50.005085] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:50.084844] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:50.183630] PlayerThread:393 [0x109cf8]: tick 4289244551 [10:44:50.185131] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:50.253889] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025890.1039400960 (ts:164405941759673) [10:44:50.285310] stream_thread:286 [0xb9b48] streambuf read 2090 bytes [10:44:50.385516] stream_thread:286 [0xb9b48] streambuf read 2089 bytes [10:44:50.485708] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:50.585886] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:50.686072] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:50.716170] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025890.3075806469 (ref 3728025890.3068215426) [10:44:50.731025] PlayerThread:393 [0x107fc8]: tick 4289245099 [10:44:50.734217] PlayerThread:393 [0x107130]: tick 4289245102 [10:44:50.734292] PlayerThread:393 [0x108e60]: tick 4289245102 [10:44:50.786277] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:50.886457] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:50.986804] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:51.009392] sendSTAT:129 [0xb9b48]: ms fr:64480 clk:4289245377 (frames_played: 2942368 device_frames: 99225) [10:44:51.009500] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:51.087080] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:51.183840] PlayerThread:393 [0x109cf8]: tick 4289245551 [10:44:51.187346] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:51.254388] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025891.1029701632 (ts:164405941803673) [10:44:51.287577] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:51.387787] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:51.488029] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:44:51.588273] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:51.688516] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:51.731160] PlayerThread:393 [0x107fc8]: tick 4289246099 [10:44:51.734328] PlayerThread:393 [0x107130]: tick 4289246102 [10:44:51.734428] PlayerThread:393 [0x108e60]: tick 4289246102 [10:44:51.788772] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:44:51.889005] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:44:51.989249] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:52.010785] sendSTAT:129 [0xb9b48]: ms fr:65486 clk:4289246378 (frames_played: 2987072 device_frames: 99225) [10:44:52.010860] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:52.089520] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:44:52.184098] PlayerThread:393 [0x109cf8]: tick 4289246552 [10:44:52.189793] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:52.255618] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025892.1054212096 (ts:164405941848025) [10:44:52.290010] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:52.390287] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:52.490571] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:52.590809] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:52.691046] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:52.731395] PlayerThread:393 [0x107fc8]: tick 4289247099 [10:44:52.734499] PlayerThread:393 [0x107130]: tick 4289247102 [10:44:52.734654] PlayerThread:393 [0x108e60]: tick 4289247102 [10:44:52.791277] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:52.891507] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:52.925018] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025892.3972625705 (ref 3728025892.3938245267) [10:44:52.991724] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:53.012108] sendSTAT:129 [0xb9b48]: ms fr:66490 clk:4289247380 (frames_played: 3031424 device_frames: 99225) [10:44:53.012168] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:53.091915] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:53.184340] PlayerThread:393 [0x109cf8]: tick 4289247552 [10:44:53.192104] stream_thread:286 [0xb9b48] streambuf read 1044 bytes [10:44:53.256170] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025893.1078788096 (ts:164405941892377) [10:44:53.292234] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:53.392408] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:53.492586] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:53.592774] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:53.692994] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:53.731625] PlayerThread:393 [0x107fc8]: tick 4289248099 [10:44:53.734710] PlayerThread:393 [0x107130]: tick 4289248102 [10:44:53.734863] PlayerThread:393 [0x108e60]: tick 4289248102 [10:44:53.793229] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:53.893468] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:53.993756] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:54.013344] sendSTAT:129 [0xb9b48]: ms fr:67484 clk:4289248381 (frames_played: 3075072 device_frames: 99225) [10:44:54.013473] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:54.094030] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:54.184555] PlayerThread:393 [0x109cf8]: tick 4289248552 [10:44:54.194296] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:54.257366] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025894.1069023232 (ts:164405941936377) [10:44:54.294498] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:54.417192] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:44:54.517459] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:54.617712] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:54.717968] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:54.731877] PlayerThread:393 [0x107fc8]: tick 4289249099 [10:44:54.734932] PlayerThread:393 [0x108e60]: tick 4289249102 [10:44:54.735013] PlayerThread:393 [0x107130]: tick 4289249103 [10:44:54.818232] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:54.918499] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:55.001926] process:528 [0xb2108] strm [10:44:55.002112] process_strm:236 [0xb2108] strm command t [10:44:55.002163] sendSTAT:134 [0xb2108]: ms_played: 0 [10:44:55.002208] sendSTAT:158 [0xb2108]: STAT: STMt [10:44:55.003072] process:528 [0xb7288] strm [10:44:55.003158] process_strm:236 [0xb7288] strm command t [10:44:55.003205] sendSTAT:134 [0xb7288]: ms_played: 0 [10:44:55.003247] sendSTAT:158 [0xb7288]: STAT: STMt [10:44:55.003760] process:528 [0xb49c8] strm [10:44:55.003842] process_strm:236 [0xb49c8] strm command t [10:44:55.003935] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:44:55.004240] sendSTAT:158 [0xb49c8]: STAT: STMt [10:44:55.004428] process:528 [0xb9b48] strm [10:44:55.004494] process_strm:236 [0xb9b48] strm command t [10:44:55.004542] sendSTAT:129 [0xb9b48]: ms fr:68476 clk:4289249372 (frames_played: 3118720 device_frames: 99225) [10:44:55.004592] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:55.018771] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:55.119054] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:55.184857] PlayerThread:393 [0x109cf8]: tick 4289249552 [10:44:55.219322] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:55.258588] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025895.1059323904 (ts:164405941980377) [10:44:55.319552] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:55.419805] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:55.520056] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:55.620316] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:55.720579] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:55.732064] PlayerThread:393 [0x107fc8]: tick 4289250100 [10:44:55.735074] PlayerThread:393 [0x108e60]: tick 4289250103 [10:44:55.735175] PlayerThread:393 [0x107130]: tick 4289250103 [10:44:55.820847] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:55.841308] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025895.3613171302 (ref 3728025895.3605807953) [10:44:55.921112] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:56.005766] sendSTAT:129 [0xb9b48]: ms fr:69482 clk:4289250373 (frames_played: 3163424 device_frames: 99225) [10:44:56.005925] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:56.021381] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:56.121664] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:56.185121] PlayerThread:393 [0x109cf8]: tick 4289250553 [10:44:56.259781] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025896.1049559040 (ts:164405942024377) [10:44:56.322007] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:56.422264] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:56.522518] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:56.622826] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:56.723243] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:56.732249] PlayerThread:393 [0x107fc8]: tick 4289251100 [10:44:56.735252] PlayerThread:393 [0x108e60]: tick 4289251103 [10:44:56.735425] PlayerThread:393 [0x107130]: tick 4289251103 [10:44:56.823503] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:56.923744] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:57.007258] sendSTAT:129 [0xb9b48]: ms fr:70481 clk:4289251375 (frames_played: 3207072 device_frames: 99225) [10:44:57.007386] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:57.023969] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:57.124213] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:57.185370] PlayerThread:393 [0x109cf8]: tick 4289251553 [10:44:57.224440] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:57.260987] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025897.1074069504 (ts:164405942068729) [10:44:57.324674] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:57.424871] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:57.525154] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:57.625400] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:57.725612] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:57.732448] PlayerThread:393 [0x107fc8]: tick 4289252100 [10:44:57.735467] PlayerThread:393 [0x108e60]: tick 4289252103 [10:44:57.735558] PlayerThread:393 [0x107130]: tick 4289252103 [10:44:57.770765] raopcl_send_chunk:579 [0x7601a860]: check n:4289252138 p:4289254370 ts:164405942091257 sn:33191 retr: 0, avail: 0, send: 0, select: 0) [10:44:57.825854] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:57.926187] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:58.008604] sendSTAT:129 [0xb9b48]: ms fr:71485 clk:4289252376 (frames_played: 3251424 device_frames: 99225) [10:44:58.008730] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:58.026440] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:58.126649] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:58.185573] PlayerThread:393 [0x109cf8]: tick 4289252553 [10:44:58.226848] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:58.262152] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025898.1064370176 (ts:164405942112729) [10:44:58.327030] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:58.427210] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:58.527431] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:58.627665] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:58.727872] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:58.732636] PlayerThread:393 [0x107fc8]: tick 4289253100 [10:44:58.735633] PlayerThread:393 [0x108e60]: tick 4289253103 [10:44:58.735676] PlayerThread:393 [0x107130]: tick 4289253103 [10:44:58.776692] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025898.3335755069 (ref 3728025898.3301523093) [10:44:58.828073] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:58.928286] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:59.009351] sendSTAT:129 [0xb9b48]: ms fr:72486 clk:4289253377 (frames_played: 3295424 device_frames: 99225) [10:44:59.009528] sendSTAT:158 [0xb9b48]: STAT: STMt [10:44:59.028562] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:59.128863] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:59.185752] PlayerThread:393 [0x109cf8]: tick 4289253553 [10:44:59.229115] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:59.263310] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025899.1088880640 (ts:164405942157081) [10:44:59.329384] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:44:59.551102] stream_thread:286 [0xb9b48] streambuf read 6270 bytes [10:44:59.651395] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:59.732778] PlayerThread:393 [0x107fc8]: tick 4289254100 [10:44:59.735759] PlayerThread:393 [0x108e60]: tick 4289254103 [10:44:59.735880] PlayerThread:393 [0x107130]: tick 4289254103 [10:44:59.751671] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:44:59.851942] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:44:59.952208] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:00.002327] process:528 [0xb2108] strm [10:45:00.002487] process_strm:236 [0xb2108] strm command t [10:45:00.002522] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:00.002545] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:00.003491] process:528 [0xb7288] strm [10:45:00.003602] process_strm:236 [0xb7288] strm command t [10:45:00.003629] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:00.003745] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:00.003977] process:528 [0xb49c8] strm [10:45:00.004041] process_strm:236 [0xb49c8] strm command t [10:45:00.004066] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:00.004087] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:00.007102] process:528 [0xb9b48] strm [10:45:00.007222] process_strm:236 [0xb9b48] strm command t [10:45:00.007248] sendSTAT:129 [0xb9b48]: ms fr:73478 clk:4289254375 (frames_played: 3339072 device_frames: 99225) [10:45:00.007274] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:00.052445] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:00.152643] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:00.185996] PlayerThread:393 [0x109cf8]: tick 4289254553 [10:45:00.252839] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:00.264536] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025900.1113456640 (ts:164405942201433) [10:45:00.708612] stream_thread:286 [0xb9b48] streambuf read 18808 bytes [10:45:00.733071] PlayerThread:393 [0x107fc8]: tick 4289255101 [10:45:00.735934] PlayerThread:393 [0x108e60]: tick 4289255103 [10:45:00.736058] PlayerThread:393 [0x107130]: tick 4289255104 [10:45:00.808887] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:00.909158] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:01.008478] sendSTAT:129 [0xb9b48]: ms fr:74478 clk:4289255376 (frames_played: 3383424 device_frames: 99225) [10:45:01.008657] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:01.009437] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:01.047624] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025901.204277234 (ref 3728025901.169401984) [10:45:01.109629] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:01.186153] PlayerThread:393 [0x109cf8]: tick 4289255554 [10:45:01.209892] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:01.310119] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:01.410375] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:01.510675] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:01.607230] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025901.2577793024 (ts:164405942260569) [10:45:01.610934] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:01.711183] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:01.733288] PlayerThread:393 [0x107fc8]: tick 4289256101 [10:45:01.736125] PlayerThread:393 [0x108e60]: tick 4289256104 [10:45:01.736278] PlayerThread:393 [0x107130]: tick 4289256104 [10:45:01.811424] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:01.911654] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:02.009923] sendSTAT:129 [0xb9b48]: ms fr:75480 clk:4289256377 (frames_played: 3427776 device_frames: 99225) [10:45:02.010037] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:02.011872] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:02.112043] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:02.186406] PlayerThread:393 [0x109cf8]: tick 4289256554 [10:45:02.212282] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:02.312498] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:02.412755] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:02.513047] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:02.607961] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025902.2568093696 (ts:164405942304569) [10:45:02.613314] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:02.713562] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:02.733497] PlayerThread:393 [0x107fc8]: tick 4289257101 [10:45:02.736328] PlayerThread:393 [0x108e60]: tick 4289257104 [10:45:02.736416] PlayerThread:393 [0x107130]: tick 4289257104 [10:45:02.813776] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:02.914027] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:03.011197] sendSTAT:129 [0xb9b48]: ms fr:76485 clk:4289257379 (frames_played: 3472128 device_frames: 99225) [10:45:03.011327] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:03.114346] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:03.186571] PlayerThread:393 [0x109cf8]: tick 4289257554 [10:45:03.215809] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:03.316053] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:03.416348] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:03.516580] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:03.609271] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025903.2558328832 (ts:164405942348569) [10:45:03.624326] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:03.653285] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025903.2805545652 (ref 3728025903.2770785815) [10:45:03.724577] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:03.733764] PlayerThread:393 [0x107fc8]: tick 4289258101 [10:45:03.736502] PlayerThread:393 [0x108e60]: tick 4289258104 [10:45:03.736652] PlayerThread:393 [0x107130]: tick 4289258104 [10:45:03.824824] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:03.925097] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:04.012546] sendSTAT:129 [0xb9b48]: ms fr:77490 clk:4289258380 (frames_played: 3516480 device_frames: 99225) [10:45:04.012667] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:04.025353] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:04.125626] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:04.186855] PlayerThread:393 [0x109cf8]: tick 4289258554 [10:45:04.225858] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:04.326195] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:04.426489] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:04.526745] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:45:04.609793] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025904.2582904832 (ts:164405942392921) [10:45:04.626980] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:04.727214] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:04.733977] PlayerThread:393 [0x107fc8]: tick 4289259101 [10:45:04.736715] PlayerThread:393 [0x108e60]: tick 4289259104 [10:45:04.736845] PlayerThread:393 [0x107130]: tick 4289259104 [10:45:04.827449] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:04.927663] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:05.000935] process:528 [0xb2108] strm [10:45:05.001046] process_strm:236 [0xb2108] strm command t [10:45:05.001072] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:05.001094] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:05.002383] process:528 [0xb7288] strm [10:45:05.002565] process_strm:236 [0xb7288] strm command t [10:45:05.002607] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:05.002630] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:05.003732] process:528 [0xb49c8] strm [10:45:05.003840] process_strm:236 [0xb49c8] strm command t [10:45:05.003867] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:05.003890] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:05.004152] process:528 [0xb9b48] strm [10:45:05.004202] process_strm:236 [0xb9b48] strm command t [10:45:05.004227] sendSTAT:129 [0xb9b48]: ms fr:78479 clk:4289259372 (frames_played: 3559776 device_frames: 99225) [10:45:05.004253] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:05.027876] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:05.128120] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:05.187164] PlayerThread:393 [0x109cf8]: tick 4289259555 [10:45:05.228391] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:05.328598] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:05.428865] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:05.529115] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:05.611011] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025905.2607415296 (ts:164405942437273) [10:45:05.629355] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:05.729605] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:05.734174] PlayerThread:393 [0x107fc8]: tick 4289260102 [10:45:05.736915] PlayerThread:393 [0x108e60]: tick 4289260104 [10:45:05.737063] PlayerThread:393 [0x107130]: tick 4289260105 [10:45:05.829916] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:05.930174] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:06.005059] sendSTAT:129 [0xb9b48]: ms fr:79480 clk:4289260373 (frames_played: 3604128 device_frames: 99225) [10:45:06.005183] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:06.030463] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:06.130746] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:06.187465] PlayerThread:393 [0x109cf8]: tick 4289260555 [10:45:06.230995] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:06.266960] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025906.1146301001 (ref 3728025906.1110893939) [10:45:06.331272] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:06.431506] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:06.531746] stream_thread:286 [0xb9b48] streambuf read 1045 bytes [10:45:06.612255] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025906.2563440640 (ts:164405942480921) [10:45:06.631997] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:06.732237] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:06.734396] PlayerThread:393 [0x107fc8]: tick 4289261102 [10:45:06.737129] PlayerThread:393 [0x108e60]: tick 4289261105 [10:45:06.737292] PlayerThread:393 [0x107130]: tick 4289261105 [10:45:06.832591] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:06.932835] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:07.006262] sendSTAT:129 [0xb9b48]: ms fr:80477 clk:4289261374 (frames_played: 3648128 device_frames: 99225) [10:45:07.006431] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:07.033068] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:07.133318] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:07.187863] PlayerThread:393 [0x109cf8]: tick 4289261555 [10:45:07.233560] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:07.521773] stream_thread:286 [0xb9b48] streambuf read 11493 bytes [10:45:07.613489] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025907.2587951104 (ts:164405942525273) [10:45:07.622033] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:07.725411] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:07.734694] PlayerThread:393 [0x107fc8]: tick 4289262102 [10:45:07.737343] PlayerThread:393 [0x108e60]: tick 4289262105 [10:45:07.737529] PlayerThread:393 [0x107130]: tick 4289262105 [10:45:07.768249] raopcl_send_chunk:579 [0x7601a860]: check n:4289262136 p:4289264372 ts:164405942532313 sn:34444 retr: 0, avail: 0, send: 0, select: 0) [10:45:07.825665] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:07.925921] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:08.009351] sendSTAT:129 [0xb9b48]: ms fr:81486 clk:4289262377 (frames_played: 3692480 device_frames: 99225) [10:45:08.009512] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:08.026197] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:08.126492] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:08.188355] PlayerThread:393 [0x109cf8]: tick 4289262556 [10:45:08.226736] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:08.326989] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:08.427249] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:08.527487] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:08.614765] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025908.2578186240 (ts:164405942569273) [10:45:08.627742] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:08.728005] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:08.734957] PlayerThread:393 [0x107fc8]: tick 4289263102 [10:45:08.737597] PlayerThread:393 [0x108e60]: tick 4289263105 [10:45:08.737783] PlayerThread:393 [0x107130]: tick 4289263105 [10:45:08.828268] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:08.897373] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025908.3853972938 (ref 3728025908.3844685302) [10:45:08.928581] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:09.010474] sendSTAT:129 [0xb9b48]: ms fr:82482 clk:4289263378 (frames_played: 3736480 device_frames: 99225) [10:45:09.010705] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:09.028905] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:09.129156] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:09.188681] PlayerThread:393 [0x109cf8]: tick 4289263556 [10:45:09.231545] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:09.331815] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:09.432056] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:09.532294] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:09.616060] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025909.2602762240 (ts:164405942613625) [10:45:09.632512] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:09.732741] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:09.735217] PlayerThread:393 [0x107fc8]: tick 4289264103 [10:45:09.737837] PlayerThread:393 [0x108e60]: tick 4289264105 [10:45:09.738004] PlayerThread:393 [0x107130]: tick 4289264106 [10:45:09.832960] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:09.933228] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:10.000771] process:528 [0xb2108] strm [10:45:10.000944] process_strm:236 [0xb2108] strm command t [10:45:10.000985] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:10.001009] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:10.001868] process:528 [0xb7288] strm [10:45:10.002047] process_strm:236 [0xb7288] strm command t [10:45:10.002103] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:10.002193] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:10.002460] process:528 [0xb49c8] strm [10:45:10.002632] process_strm:236 [0xb49c8] strm command t [10:45:10.002688] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:10.002811] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:10.003055] process:528 [0xb9b48] strm [10:45:10.003237] process_strm:236 [0xb9b48] strm command t [10:45:10.003555] sendSTAT:129 [0xb9b48]: ms fr:83481 clk:4289264371 (frames_played: 3780480 device_frames: 99225) [10:45:10.003624] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:10.033448] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:10.188946] PlayerThread:393 [0x109cf8]: tick 4289264556 [10:45:10.233754] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:10.333983] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:10.434223] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:10.534459] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:45:10.617374] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025910.2592997376 (ts:164405942657625) [10:45:10.634688] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:10.734935] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:10.735509] PlayerThread:393 [0x107fc8]: tick 4289265103 [10:45:10.738489] PlayerThread:393 [0x108e60]: tick 4289265106 [10:45:10.738592] PlayerThread:393 [0x107130]: tick 4289265106 [10:45:10.835203] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:10.935423] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:11.004558] sendSTAT:129 [0xb9b48]: ms fr:84474 clk:4289265372 (frames_played: 3824128 device_frames: 99225) [10:45:11.004700] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:11.035653] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:11.135910] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:11.189203] PlayerThread:393 [0x109cf8]: tick 4289265557 [10:45:11.236176] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:11.336443] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:11.436745] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:11.495909] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025911.2129723958 (ref 3728025911.2096807786) [10:45:11.537017] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:11.618625] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025911.2617573376 (ts:164405942701977) [10:45:11.637220] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:11.735767] PlayerThread:393 [0x107fc8]: tick 4289266103 [10:45:11.737454] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:11.738835] PlayerThread:393 [0x108e60]: tick 4289266106 [10:45:11.738992] PlayerThread:393 [0x107130]: tick 4289266106 [10:45:11.837719] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:11.937944] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:12.005927] sendSTAT:129 [0xb9b48]: ms fr:85482 clk:4289266373 (frames_played: 3868832 device_frames: 99225) [10:45:12.006207] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:12.038199] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:12.138452] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:12.189525] PlayerThread:393 [0x109cf8]: tick 4289266557 [10:45:12.238711] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:45:12.338964] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:12.439217] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:12.539501] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:12.619910] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025912.2642083840 (ts:164405942746329) [10:45:12.639728] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:12.736151] PlayerThread:393 [0x107fc8]: tick 4289267104 [10:45:12.739049] PlayerThread:393 [0x108e60]: tick 4289267107 [10:45:12.739227] PlayerThread:393 [0x107130]: tick 4289267107 [10:45:12.740000] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:12.840288] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:12.940529] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:13.007456] sendSTAT:129 [0xb9b48]: ms fr:86479 clk:4289267375 (frames_played: 3912832 device_frames: 99225) [10:45:13.007631] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:13.040763] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:13.141059] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:13.189856] PlayerThread:393 [0x109cf8]: tick 4289267557 [10:45:13.241281] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:13.341544] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:13.441778] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:13.542006] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:13.621156] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025913.2632384512 (ts:164405942790329) [10:45:13.642224] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:13.736383] PlayerThread:393 [0x107fc8]: tick 4289268104 [10:45:13.739284] PlayerThread:393 [0x108e60]: tick 4289268107 [10:45:13.739437] PlayerThread:393 [0x107130]: tick 4289268107 [10:45:13.742431] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:13.842647] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:13.942956] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:14.008792] sendSTAT:129 [0xb9b48]: ms fr:87486 clk:4289268376 (frames_played: 3957184 device_frames: 99225) [10:45:14.008975] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:14.043194] stream_thread:286 [0xb9b48] streambuf read 1045 bytes [10:45:14.077148] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025914.331227877 (ref 3728025914.324533809) [10:45:14.143429] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:14.190129] PlayerThread:393 [0x109cf8]: tick 4289268558 [10:45:14.243656] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:14.343912] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:14.444160] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:14.544401] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:14.622419] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025914.2622619648 (ts:164405942834329) [10:45:14.644657] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:14.736587] PlayerThread:393 [0x107fc8]: tick 4289269104 [10:45:14.739491] PlayerThread:393 [0x108e60]: tick 4289269107 [10:45:14.739640] PlayerThread:393 [0x107130]: tick 4289269107 [10:45:14.744938] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:14.845140] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:14.945358] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:15.001674] process:528 [0xb2108] strm [10:45:15.001796] process_strm:236 [0xb2108] strm command t [10:45:15.001824] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:15.001847] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:15.002390] process:528 [0xb7288] strm [10:45:15.002471] process_strm:236 [0xb7288] strm command t [10:45:15.002513] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:15.002555] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:15.002728] process:528 [0xb49c8] strm [10:45:15.002778] process_strm:236 [0xb49c8] strm command t [10:45:15.002801] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:15.002823] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:15.003123] process:528 [0xb9b48] strm [10:45:15.003296] process_strm:236 [0xb9b48] strm command t [10:45:15.003344] sendSTAT:129 [0xb9b48]: ms fr:88473 clk:4289269371 (frames_played: 4000480 device_frames: 99225) [10:45:15.003370] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:15.045588] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:15.145784] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:15.190345] PlayerThread:393 [0x109cf8]: tick 4289269558 [10:45:15.246017] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:15.346301] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:15.446551] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:15.546826] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:15.623702] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025915.2612854784 (ts:164405942878329) [10:45:15.647033] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:15.736875] PlayerThread:393 [0x107fc8]: tick 4289270104 [10:45:15.739692] PlayerThread:393 [0x108e60]: tick 4289270107 [10:45:15.739844] PlayerThread:393 [0x107130]: tick 4289270107 [10:45:15.747262] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:15.847487] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:15.947691] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:16.003929] sendSTAT:129 [0xb9b48]: ms fr:89479 clk:4289270371 (frames_played: 4045184 device_frames: 99225) [10:45:16.004064] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:16.047902] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:16.148105] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:16.190544] PlayerThread:393 [0x109cf8]: tick 4289270558 [10:45:16.248368] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:16.348656] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:16.412843] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025916.1772936729 (ref 3728025916.1764607467) [10:45:16.448939] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:16.549231] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:16.624933] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025916.2671706112 (ts:164405942923033) [10:45:16.649509] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:16.737160] PlayerThread:393 [0x107fc8]: tick 4289271105 [10:45:16.739904] PlayerThread:393 [0x108e60]: tick 4289271107 [10:45:16.740023] PlayerThread:393 [0x107130]: tick 4289271108 [10:45:16.749756] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:16.849943] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:16.950288] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:17.004800] sendSTAT:129 [0xb9b48]: ms fr:90479 clk:4289271372 (frames_played: 4089184 device_frames: 99225) [10:45:17.004972] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:17.050584] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:17.150907] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:17.190764] PlayerThread:393 [0x109cf8]: tick 4289271558 [10:45:17.251221] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:17.351529] stream_thread:286 [0xb9b48] streambuf read 1045 bytes [10:45:17.452004] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:17.552322] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:17.626188] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025917.2661941248 (ts:164405942967033) [10:45:17.652595] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:17.737422] PlayerThread:393 [0x107fc8]: tick 4289272105 [10:45:17.740069] PlayerThread:393 [0x108e60]: tick 4289272108 [10:45:17.740186] PlayerThread:393 [0x107130]: tick 4289272108 [10:45:17.752836] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:17.768545] raopcl_send_chunk:579 [0x7601a860]: check n:4289272136 p:4289274373 ts:164405942973369 sn:35697 retr: 0, avail: 0, send: 0, select: 0) [10:45:17.853107] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:17.953347] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:18.006030] sendSTAT:129 [0xb9b48]: ms fr:91483 clk:4289272374 (frames_played: 4133536 device_frames: 99225) [10:45:18.006234] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:18.053596] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:18.153850] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:18.191036] PlayerThread:393 [0x109cf8]: tick 4289272559 [10:45:18.254078] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:18.354307] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:18.454557] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:18.554873] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:18.627399] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025918.2652241920 (ts:164405943011033) [10:45:18.655149] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:18.737659] PlayerThread:393 [0x107fc8]: tick 4289273105 [10:45:18.740260] PlayerThread:393 [0x108e60]: tick 4289273108 [10:45:18.740417] PlayerThread:393 [0x107130]: tick 4289273108 [10:45:18.755427] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:18.855668] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:18.955953] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:19.007095] sendSTAT:129 [0xb9b48]: ms fr:92480 clk:4289273375 (frames_played: 4177536 device_frames: 99225) [10:45:19.007215] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:19.056196] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:19.156476] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:19.191217] PlayerThread:393 [0x109cf8]: tick 4289273559 [10:45:19.256683] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:19.327124] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025919.1404840852 (ref 3728025919.1370634878) [10:45:19.356890] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:19.457087] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:19.557297] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:19.628565] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025919.2676752384 (ts:164405943055385) [10:45:19.657631] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:19.738243] PlayerThread:393 [0x107fc8]: tick 4289274106 [10:45:19.740475] PlayerThread:393 [0x108e60]: tick 4289274108 [10:45:19.740594] PlayerThread:393 [0x107130]: tick 4289274108 [10:45:19.757923] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:19.858187] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:19.958500] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:20.001650] process:528 [0xb2108] strm [10:45:20.001827] process_strm:236 [0xb2108] strm command t [10:45:20.001878] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:20.001921] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:20.002885] process:528 [0xb7288] strm [10:45:20.003043] process_strm:236 [0xb7288] strm command t [10:45:20.003097] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:20.003141] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:20.003582] process:528 [0xb49c8] strm [10:45:20.003659] process_strm:236 [0xb49c8] strm command t [10:45:20.003707] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:20.003749] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:20.004256] process:528 [0xb9b48] strm [10:45:20.004337] process_strm:236 [0xb9b48] strm command t [10:45:20.004385] sendSTAT:129 [0xb9b48]: ms fr:93478 clk:4289274372 (frames_played: 4221536 device_frames: 99225) [10:45:20.004435] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:20.058895] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:20.159100] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:20.191403] PlayerThread:393 [0x109cf8]: tick 4289274559 [10:45:20.259312] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:20.359515] stream_thread:286 [0xb9b48] streambuf read 1157 bytes [10:45:20.359655] stream_thread:286 [0xb9b48] streambuf read 3023 bytes [10:45:20.459850] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:20.560060] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:20.629746] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025920.2667053056 (ts:164405943099385) [10:45:20.660270] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:20.738539] PlayerThread:393 [0x107fc8]: tick 4289275106 [10:45:20.740671] PlayerThread:393 [0x108e60]: tick 4289275108 [10:45:20.740853] PlayerThread:393 [0x107130]: tick 4289275108 [10:45:20.760505] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:20.861004] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:20.961293] stream_thread:286 [0xb9b48] streambuf read 1045 bytes [10:45:21.005644] sendSTAT:129 [0xb9b48]: ms fr:94479 clk:4289275373 (frames_played: 4265536 device_frames: 99225) [10:45:21.005831] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:21.061707] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:21.162007] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:21.191599] PlayerThread:393 [0x109cf8]: tick 4289275559 [10:45:21.262326] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:21.362748] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:21.463059] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:21.563376] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:21.602316] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025921.2586695593 (ref 3728025921.2552467004) [10:45:21.630975] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025921.2657288192 (ts:164405943143385) [10:45:21.663666] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:21.738913] PlayerThread:393 [0x107fc8]: tick 4289276106 [10:45:21.740909] PlayerThread:393 [0x108e60]: tick 4289276108 [10:45:21.741027] PlayerThread:393 [0x107130]: tick 4289276109 [10:45:21.763950] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:21.864235] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:21.964532] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:22.006221] sendSTAT:129 [0xb9b48]: ms fr:95483 clk:4289276374 (frames_played: 4309888 device_frames: 99225) [10:45:22.006444] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:22.064826] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:22.165052] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:22.191996] PlayerThread:393 [0x109cf8]: tick 4289276559 [10:45:22.265244] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:22.365452] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:22.465662] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:22.565940] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:22.632290] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025922.2681864192 (ts:164405943187737) [10:45:22.666288] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:22.739244] PlayerThread:393 [0x107fc8]: tick 4289277107 [10:45:22.741081] PlayerThread:393 [0x108e60]: tick 4289277109 [10:45:22.741258] PlayerThread:393 [0x107130]: tick 4289277109 [10:45:22.766551] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:22.866795] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:22.967026] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:23.007622] sendSTAT:129 [0xb9b48]: ms fr:96479 clk:4289277375 (frames_played: 4353888 device_frames: 99225) [10:45:23.007776] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:23.067247] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:23.167461] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:23.192328] PlayerThread:393 [0x109cf8]: tick 4289277560 [10:45:23.267662] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:23.367934] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:23.468177] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:23.568465] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:23.633522] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025923.2706374656 (ts:164405943232089) [10:45:23.668918] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:23.739525] PlayerThread:393 [0x107fc8]: tick 4289278107 [10:45:23.741338] PlayerThread:393 [0x108e60]: tick 4289278109 [10:45:23.741531] PlayerThread:393 [0x107130]: tick 4289278109 [10:45:23.769245] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:23.869544] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:23.964761] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025923.4143350655 (ref 3728025923.4108856453) [10:45:24.008982] sendSTAT:129 [0xb9b48]: ms fr:97485 clk:4289278376 (frames_played: 4398240 device_frames: 99225) [10:45:24.009165] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:24.070033] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:24.170333] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:24.192522] PlayerThread:393 [0x109cf8]: tick 4289278560 [10:45:24.270679] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:24.371028] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:24.471370] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:24.571741] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:24.633997] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025924.2696609792 (ts:164405943276089) [10:45:24.672080] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:24.740121] PlayerThread:393 [0x107fc8]: tick 4289279108 [10:45:24.741608] PlayerThread:393 [0x108e60]: tick 4289279109 [10:45:24.741769] PlayerThread:393 [0x107130]: tick 4289279109 [10:45:24.772386] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:24.872706] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:24.973042] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:25.002341] process:528 [0xb2108] strm [10:45:25.002503] process_strm:236 [0xb2108] strm command t [10:45:25.002553] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:25.002598] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:25.003823] process:528 [0xb7288] strm [10:45:25.003942] process_strm:236 [0xb7288] strm command t [10:45:25.003991] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:25.004034] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:25.005093] process:528 [0xb49c8] strm [10:45:25.005181] process_strm:236 [0xb49c8] strm command t [10:45:25.005229] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:25.005409] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:25.007405] process:528 [0xb9b48] strm [10:45:25.007586] process_strm:236 [0xb9b48] strm command t [10:45:25.007639] sendSTAT:129 [0xb9b48]: ms fr:98483 clk:4289279375 (frames_played: 4441888 device_frames: 99225) [10:45:25.007690] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:25.073450] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:25.173833] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:25.192772] PlayerThread:393 [0x109cf8]: tick 4289279560 [10:45:25.274132] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:25.374399] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:25.474687] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:25.574950] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:25.635227] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025925.2686910464 (ts:164405943320089) [10:45:25.675162] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:25.740349] PlayerThread:393 [0x107fc8]: tick 4289280108 [10:45:25.741798] PlayerThread:393 [0x108e60]: tick 4289280109 [10:45:25.741891] PlayerThread:393 [0x107130]: tick 4289280109 [10:45:25.775367] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:25.875627] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:25.975921] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:26.008907] sendSTAT:129 [0xb9b48]: ms fr:99478 clk:4289280376 (frames_played: 4486240 device_frames: 99225) [10:45:26.009079] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:26.076293] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:26.176605] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:26.192984] PlayerThread:393 [0x109cf8]: tick 4289280560 [10:45:26.276896] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:26.377215] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:26.477524] stream_thread:286 [0xb9b48] streambuf read 2090 bytes [10:45:26.577812] stream_thread:286 [0xb9b48] streambuf read 2090 bytes [10:45:26.636446] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025926.2677145600 (ts:164405943364089) [10:45:26.678112] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:26.740680] PlayerThread:393 [0x107fc8]: tick 4289281108 [10:45:26.741925] PlayerThread:393 [0x108e60]: tick 4289281109 [10:45:26.742036] PlayerThread:393 [0x107130]: tick 4289281110 [10:45:26.778389] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:26.878691] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:26.967746] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025926.4156226967 (ref 3728025926.4145693584) [10:45:26.978977] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:27.010289] sendSTAT:129 [0xb9b48]: ms fr:100486 clk:4289281378 (frames_played: 4530592 device_frames: 99225) [10:45:27.010481] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:27.079230] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:27.179532] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:27.193244] PlayerThread:393 [0x109cf8]: tick 4289281561 [10:45:27.279883] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:27.380189] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:27.480474] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:27.580768] stream_thread:286 [0xb9b48] streambuf read 5225 bytes [10:45:27.637744] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025927.2701721600 (ts:164405943408441) [10:45:27.681119] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:27.740996] PlayerThread:393 [0x107fc8]: tick 4289282108 [10:45:27.742092] PlayerThread:393 [0x108e60]: tick 4289282110 [10:45:27.742214] PlayerThread:393 [0x107130]: tick 4289282110 [10:45:27.773891] raopcl_send_chunk:579 [0x7601a860]: check n:4289282141 p:4289284374 ts:164405943414425 sn:36950 retr: 0, avail: 0, send: 0, select: 0) [10:45:27.781429] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:27.881646] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:27.981946] stream_thread:286 [0xb9b48] streambuf read 3134 bytes [10:45:28.011719] sendSTAT:129 [0xb9b48]: ms fr:101485 clk:4289282379 (frames_played: 4574592 device_frames: 99225) [10:45:28.011911] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:28.082259] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:28.182644] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:28.193525] PlayerThread:393 [0x109cf8]: tick 4289282561 [10:45:28.283053] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:28.383328] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:28.483616] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:28.583832] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:28.638812] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025928.2691956736 (ts:164405943452441) [10:45:28.684051] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:28.741250] PlayerThread:393 [0x107fc8]: tick 4289283109 [10:45:28.742264] PlayerThread:393 [0x108e60]: tick 4289283110 [10:45:28.742362] PlayerThread:393 [0x107130]: tick 4289283110 [10:45:28.784277] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:28.884481] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:28.984710] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:29.013110] sendSTAT:129 [0xb9b48]: ms fr:102489 clk:4289283381 (frames_played: 4618592 device_frames: 99225) [10:45:29.013226] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:29.184992] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:29.193879] PlayerThread:393 [0x109cf8]: tick 4289283561 [10:45:29.285192] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:29.309526] _rtp_timing_thread:1289 [0x7601a860]: NTP sync: 3728025929.1329279493 (ref 3728025929.1295352464) [10:45:29.385379] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:29.485535] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:29.585709] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:29.640008] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025929.2682257408 (ts:164405943496441) [10:45:29.685907] stream_thread:286 [0xb9b48] streambuf read 3135 bytes [10:45:29.741476] PlayerThread:393 [0x107fc8]: tick 4289284109 [10:45:29.742426] PlayerThread:393 [0x107130]: tick 4289284110 [10:45:29.742519] PlayerThread:393 [0x108e60]: tick 4289284110 [10:45:29.786141] stream_thread:286 [0xb9b48] streambuf read 5224 bytes [10:45:29.886363] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:29.986635] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:30.001942] process:528 [0xb2108] strm [10:45:30.002090] process_strm:236 [0xb2108] strm command t [10:45:30.002141] sendSTAT:134 [0xb2108]: ms_played: 0 [10:45:30.002185] sendSTAT:158 [0xb2108]: STAT: STMt [10:45:30.003246] process:528 [0xb7288] strm [10:45:30.003335] process_strm:236 [0xb7288] strm command t [10:45:30.003385] sendSTAT:134 [0xb7288]: ms_played: 0 [10:45:30.003441] sendSTAT:158 [0xb7288]: STAT: STMt [10:45:30.004600] process:528 [0xb49c8] strm [10:45:30.004762] process_strm:236 [0xb49c8] strm command t [10:45:30.004816] sendSTAT:134 [0xb49c8]: ms_played: 0 [10:45:30.004866] sendSTAT:158 [0xb49c8]: STAT: STMt [10:45:30.005642] process:528 [0xb9b48] strm [10:45:30.005723] process_strm:236 [0xb9b48] strm command t [10:45:30.005771] sendSTAT:129 [0xb9b48]: ms fr:103476 clk:4289284373 (frames_played: 4662240 device_frames: 99225) [10:45:30.005821] sendSTAT:158 [0xb9b48]: STAT: STMt [10:45:30.086925] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:30.187201] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:30.194062] PlayerThread:393 [0x109cf8]: tick 4289284562 [10:45:30.287484] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:30.387750] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:30.488084] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:30.588356] stream_thread:286 [0xb9b48] streambuf read 4179 bytes [10:45:30.641248] _raopcl_send_sync:1220 [0x7601a860]: sync ntp:3728025930.2706767872 (ts:164405943540793) [10:45:30.688627] stream_thread:286 [0xb9b48] streambuf read 4180 bytes [10:45:30.741732] PlayerThread:393 [0x107fc8]: tick 4289285109 [10:45:30.742576] PlayerThread:393 [0x107130]: tick 4289285110 [10:45:30.742685] PlayerThread:393 [0x108e60]: tick 4289285110 [10:45:30.788879] stream_thread:286 [0xb9b48] streambuf read 4179 bytes

simonrb2000 commented 6 years ago

Think I have found the issue. I didn't have Cover Art or Meta Data being sent to player. After enabling that it seems to be working. Fingers crossed.