Logitech Transporters hanging when connected to roon

Adrian_Matala · October 16, 2018, 2:32pm

Hi,

I have tried to use roon with my Slimdevices/Logitech Transporters. The Transporters are visible on the network and I can activate the players but when I try to play something, they just hang. There is no sound coming out and progress bar is not moving, the Transporters are completely non responsive to any IR remote commands.
The only way to get back control of my Transporters is to shut down roon, then they will prompt me to choose another music source and I can select the LMS running on a different computer than roon.
Is this a known problem?
Thanks!

bobflood · October 17, 2018, 12:49am

Have you activated support for Logitech on the set-up page?

Adrian_Matala · October 17, 2018, 5:28am

Yes… And I can see the Trasnporter, activate it, select it for playback, but then it just hangs and doesn’t play anything with progress bar stuck at 0:00.

It gets stuck like this for ever and can’t even control the Transporter via the IR remote anymore:

I have the latest version of roon installed:

I have 3 Logitech Transporters and they all have the same problem…

Thanks for any suggestions!

Ratbert · October 17, 2018, 7:07am

If you have LMS running on another device at the same time try shutting it down?

Adrian_Matala · October 17, 2018, 8:02am

Is this a requirement? I understand that you can’t have a LMS running on the same device as roon when Squeezebox support is active, but there shouldn’t be a problem running a LMS on another device.
On the Transporter you can choose the LMS or roon instance you want to connect to and then the others are simply ignored…
But if you think it may help I’ll give it a try, athough it’s not an easy feat as the other device is a decicated computer running LMS and serving all my players around the house… It’s not always easy finding a downtime slot…

Adrian_Matala · October 17, 2018, 8:45am

This is what I have found in the log related to the Transporter. I’ll try to upload a complete log later on because I had background analysis active during this test and it wrote a lot of info to the log which is not that easy to filter out. I’ll do a new test with background analysis turned off to have a cleaner log:

10/17 07:22:34 Info: [squeezebox/client] [192.168.1.39:59128] connected
10/17 07:22:34 Trace: [squeezebox/client] [192.168.1.39:59128] GOT HELO device_id=5 revision=87 mac=00:04:20:10:05:5b uuid=00000000-0000-0000-0000-000000000000 wlan_channel_list=32768 bytes_received=0 language=EN capabilities=
10/17 07:22:34 Info: [squeezebox/client] [192.168.1.39:59128] Device Data: modelkey=transporter model=Squeezebox Transporter uuid=00000000-0000-0000-0000-000000000000 name= mac=00:04:20:10:05:5b ipendpoint=192.168.1.39:59128
10/17 07:22:34 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=     crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876580361 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:22:35 Trace: [squeezebox/server] [HTTP] Unexpected Post /jsonrpc.js from 192.168.1.34:23022
10/17 07:22:35 Trace: [squeezebox/server] [HTTP] GOT {"params":["",["players",0,999]],"method":"slim.request","id":1}
10/17 07:22:36 Trace: [squeezebox/client] [192.168.1.39:59128] State Change Initializing => Connected
10/17 07:22:36 Info: [devicedb] [autodetect] Match DeviceAutodetectData[Type=Squeezebox Vendor=Logitech Model=Squeezebox Transporter] => Squeezebox Transporter
10/17 07:22:36 Info: [squeezebox] device TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128) added
10/17 07:22:36 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 07:22:36 Trace: [push] connecting to 104.248.55.243:9200
10/17 07:22:36 Trace: [push] connected
10/17 07:22:37 Trace: [squeezebox/server] [HTTP] Unexpected Post /jsonrpc.js from 192.168.1.34:23024
10/17 07:22:37 Trace: [squeezebox/server] [HTTP] GOT {"params":["",["players",0,999]],"method":"slim.request","id":1}
10/17 07:22:55 Info: [transport] creating endpoint for squeezebox device 23:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 07:22:55 Trace: [squeezebox/client] [192.168.1.39:59128] SENT audg oldvol=100 dvc=1 preamp=255 newvol=65536
10/17 07:22:55 Trace: [dspengine] created new dsp config {"version":3,"items":[{"type":"bs2b","enabled":false},{"type":"parametric_equalizer","enabled":false},{"type":"audeze_presets","enabled":false}]}
10/17 07:22:55 Trace: [transport/audeze] picking preset lowlatency 
10/17 07:22:55 Trace: [transport/audeze] picked null preset!
10/17 07:22:55 Debug: AudioDeviceMunge.GetManufacturer(AudioDeviceType.Squeezebox, "Logitech", "Squeezebox Transporter", "TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)", "") => "Logitech";
10/17 07:22:55 Debug: AudioDeviceMunge.GetModel(AudioDeviceType.Squeezebox, "Logitech", "Squeezebox Transporter", "TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)", "") => "Squeezebox Transporter";
10/17 07:22:55 Trace: [zone TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)] Loading
10/17 07:22:55 Trace: [zone TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)] Suspend
10/17 07:22:55 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:22:55 Info: [transport] created zone TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)
10/17 07:22:55 Info: [transport]     with endpoint TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128) (23:1:b5c97230-9c8a-8806-ceda-428deec6b131) [IsAvailable=True]
10/17 07:22:55 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=audg crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876601991 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:22:55 Trace: [zone TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)] Loaded Queue=0 Tracks Swim=Inactive AutoSwim=True Loop=Disabled Shuffle=False
10/17 07:22:55 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876602012 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:22:56 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 07:22:56 Trace: [push] connecting to 104.248.55.243:9200
10/17 07:22:56 Trace: [push] connected
10/17 07:22:56 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 07:22:56 Trace: [push] retrying connection in 49141ms
10/17 07:23:00 Info: [stats] 8030mb Virtual, 1733mb Physical, 960mb Managed, 1899 Handles, 99 Threads
10/17 07:23:01 Trace: [TR2] [Inactive] [STOPPED @ 0:00] 
10/17 07:23:06 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 07:23:06 Trace: [push] connecting to 104.248.55.243:9200
10/17 07:23:07 Trace: [push] connected
10/17 07:23:07 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 07:23:07 Trace: [push] retrying connection in 27616ms
10/17 07:24:03 Trace: [audiodevice/setup] [Squeezebox Transporter] commit
10/17 07:24:03 Info: [transport] destroyed zone TR2 was playing? False
10/17 07:24:03 Trace: [zone TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128)] Suspend
10/17 07:24:03 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:24:03 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:24:03 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876670103 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:24:03 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876670104 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:24:03 Info: [transport] creating endpoint for squeezebox device 23:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 07:24:03 Trace: [squeezebox/client] [192.168.1.39:59128] SENT audg oldvol=100 dvc=1 preamp=255 newvol=65536
10/17 07:24:03 Trace: [dspengine] created new dsp config {"version":3,"items":[{"type":"bs2b","enabled":false},{"type":"parametric_equalizer","enabled":false},{"type":"audeze_presets","enabled":false}]}
10/17 07:24:03 Trace: [transport/audeze] picking preset lowlatency 
10/17 07:24:03 Trace: [transport/audeze] picked null preset!
10/17 07:24:04 Trace: [zone TR2] Loading
10/17 07:24:04 Trace: [zone TR2] Suspend
10/17 07:24:04 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:24:04 Info: [transport] created zone TR2
10/17 07:24:04 Info: [transport]     with endpoint TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128) (23:1:b5c97230-9c8a-8806-ceda-428deec6b131) [IsAvailable=True]
10/17 07:24:04 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=audg crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876670166 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:24:04 Trace: [zone TR2] Loaded Queue=0 Tracks Swim=Inactive AutoSwim=True Loop=Disabled Shuffle=False
10/17 07:24:04 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876670176 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Trace: [zone TR2] Playing 10 Items
10/17 07:25:16 Trace: [zone TR2] Selecting Source state=Stopped
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:25:16 Trace: [zone TR2] Playing TransportItem
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:25:16 Trace: [zone TR2] Selecting Source state=Stopped
10/17 07:25:16 Trace: [TR2] [Inactive] [LOADING @ 0:00] Prize - Gavin Harrison / Osric
10/17 07:25:16 Trace: [analysis] prioritizing current track LibraryTrack[20730930, Gavin Harrison, Osric, 05ric - The Man Who Sold Himself - Prize IsAvailable=True IsDeleted=False ] for zone 22:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 07:25:16 Trace: [analysis] prioritizing next track LibraryTrack[20731442, Gavin Harrison, Osric, 05ric - The Man Who Sold Himself - Identitas IsAvailable=True IsDeleted=False ] for zone 22:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 07:25:16 Trace: [analysis] analyzing (high priority) trackid=20730930 url=\\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\01 Prize.flac
10/17 07:25:16 Trace: [musicpowerstate] music is playing, preventing idle sleep
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876742572 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876742574 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Info: [TR2] [zoneplayer] Playing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\01 Prize.flac
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:25:16 Info: [TR2] [zoneplayer] Queueing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\02 Identitas.flac
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876742646 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Info: [TR2] [zoneplayer]     Open Result (Playing):Result[Status=Success]
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876743030 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Info: [TR2] [zoneplayer] Starting playback
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=s autostart=1 formatbyte=f pcmsamplesize=? pcmsamplerate=? pcmchannels=? pcmendian=? threshold=255 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=GET /76a0668dfdcf4b91ba09df44fc5fee4a HTTP/1.0


10/17 07:25:16 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/248 sec
10/17 07:25:16 Info: [zone TR2] OnPlayFeedback Playing
10/17 07:25:16 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [PLAYING @ 0:00] Prize - Gavin Harrison / Osric
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876743101 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMc crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876743102 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMe crlf_count=0 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876743104 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMh crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876743111 output_buffer_size=3528000 output_buffer_fullness=3520120 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:16 Info: [TR2] [zoneplayer] Open result (Queueing): Result[Status=Success]
10/17 07:25:16 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/305 sec
10/17 07:25:17 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMs crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=287024 bytes_received=0 wireless_signal=65535 jiffies=2876743301 output_buffer_size=3528000 output_buffer_fullness=64640 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:25:17 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Flac 44100/16/2 BitRate=786 Quality=Lossless
    Output OutputType=Squeezebox Quality=Lossless SubType= Model=Squeezebox Transporter

STOPPED roon here:

------------------------------------------------------------
10/17 07:29:20 Trace: [zone System Output] Suspend
10/17 07:29:20 Trace: [zone System Output] Stop
10/17 07:29:20 Trace: [zone TR2] Suspend
10/17 07:29:20 Trace: [zone TR2] Stop
10/17 07:29:20 Info: [zone TR2] OnPlayFeedback Stopped
10/17 07:29:20 Trace: [transport] disabling transport
10/17 07:29:20 Trace: [zone System Output] Suspend
10/17 07:29:20 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 0:00/4:08] Prize - Gavin Harrison / Osric
10/17 07:29:20 Trace: [radio] [1] dispose session
10/17 07:29:20 Trace: [zone TR2] Suspend
10/17 07:29:20 Trace: [raat] disposing
10/17 07:29:20 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 07:29:20 Trace: [push] retrying connection in 43156ms
10/17 07:29:20 Info: [audio/env] [zoneplayer] All streams were disposed
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:29:20 Trace: [airplay] disposing
10/17 07:29:20 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 07:29:20 Trace: [devialet] disposing
10/17 07:29:20 Trace: [devicemanager/sonos] disposing
10/17 07:29:20 Trace: [devicemanager/kef] disposing
10/17 07:29:20 Debug: [upnp/discovery] disposing tracker
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] State Change Connected => Disconnected
10/17 07:29:20 Info: [squeezebox] device TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:59128) removed
10/17 07:29:20 Trace: [hqplayer] disposing
10/17 07:29:20 Trace: [meridian] disposing
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876986455 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876986457 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876986457 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 07:29:20 Trace: [squeezebox/client] [192.168.1.39:59128] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2876986458 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0

Dusty · October 17, 2018, 9:13am

@support Can you have a look? Thanks.

Henry_McLeod · October 17, 2018, 9:37am

No need really. The very first line of the Knowledge base entry for Squeezebox Setup is to switch off any other instances of LMS running on your network.

https://kb.roonlabs.com/Squeezebox_Setup

Adrian_Matala · October 17, 2018, 9:48am

Oh, okay… That was not clear to me. But why is that needed? It’s perfectly fine to run multiple instances of LMS on the same network, as long as they are not running on the same device…
I guess I was so much used with the LMS way of working, I just assumed it would be the same…

Henry_McLeod · October 17, 2018, 9:58am

I think it is because Roon ‘sort of’ emulates LMS but it isn’t a full emulation so it doesn’t play well with other instances of that software. But that is speculation on my part!

Adrian_Matala · October 17, 2018, 10:00am

OK I’ll give it a try when I can find some time to stop my main LMS instance, probably sometime at night…

Adrian_Matala · October 17, 2018, 4:02pm

Hi, I have tried but still no luck. I have stopped my other LMS installation, restarted roon with Squeezebox support active. Just like the first time it has detected my Transporter without problems, but when trying to play tracks it’s just stuck at 0:00. I can skip tracks back and forth but none will start playing.
The Transporter screen is stuck on Now Playing with no progress bar and doesn’t respond to any IR commands:

I am attaching the full log of the test, from roon startup till shutdown. If @support needs more information, please let me know!

10/17 17:48:34 Info: Starting Roon v1.5 (build 354) stable on windows
10/17 17:48:34 Debug: looking for *_old files in: C:\Users\amata\AppData\Local\Roon\Application
10/17 17:48:34 Debug: looking for old numerical version dirs in: C:\Users\amata\AppData\Local\Roon\Application
10/17 17:48:34 Trace: Checking if we are already running
10/17 17:48:34 Trace: Nope, we are the only one running
10/17 17:48:34 Info: Is 64 bit? True
10/17 17:48:34 Trace: [broo/imagecache] loaded 2 cache entries from C:\Users\amata\AppData\Local\Roon\Cache\brooimages\index.db, current: 512mb / 0mb
10/17 17:48:35 Info: Loading broo project: ui.broox
10/17 17:48:35 Trace: [realtime] fetching time from NTP server
10/17 17:48:35 Trace: [realtime] Got time from NTP: 17/10/2018 15:48:34 (3748780114575ms)
10/17 17:48:35 Trace: [realtime] Updated clock skew to -00:00:00.8235468 (-823,5468ms)
10/17 17:48:35 Debug: OpenGL Version: 4.6.0 NVIDIA 416.16
OpenGL Vendor: NVIDIA Corporation
OpenGL ShaderLangerVersion: 4.60 NVIDIA
OpenGL Extensions: GL_AMD_multi_draw_indirect GL_AMD_seamless_cubemap_per_texture GL_AMD_vertex_shader_viewport_index GL_AMD_vertex_shader_layer GL_ARB_arrays_of_arrays GL_ARB_base_instance GL_ARB_bindless_texture GL_ARB_blend_func_extended GL_ARB_buffer_storage GL_ARB_clear_buffer_object GL_ARB_clear_texture GL_ARB_clip_control GL_ARB_color_buffer_float GL_ARB_compatibility GL_ARB_compressed_texture_pixel_storage GL_ARB_conservative_depth GL_ARB_compute_shader GL_ARB_compute_variable_group_size GL_ARB_conditional_render_inverted GL_ARB_copy_buffer GL_ARB_copy_image GL_ARB_cull_distance GL_ARB_debug_output GL_ARB_depth_buffer_float GL_ARB_depth_clamp GL_ARB_depth_texture GL_ARB_derivative_control GL_ARB_direct_state_access GL_ARB_draw_buffers GL_ARB_draw_buffers_blend GL_ARB_draw_indirect GL_ARB_draw_elements_base_vertex GL_ARB_draw_instanced GL_ARB_enhanced_layouts GL_ARB_ES2_compatibility GL_ARB_ES3_compatibility GL_ARB_ES3_1_compatibility GL_ARB_ES3_2_compatibility GL_ARB_explicit_attrib_location GL_ARB_explicit_uniform_location GL_ARB_fragment_coord_conventions GL_ARB_fragment_layer_viewport GL_ARB_fragment_program GL_ARB_fragment_program_shadow GL_ARB_fragment_shader GL_ARB_fragment_shader_interlock GL_ARB_framebuffer_no_attachments GL_ARB_framebuffer_object GL_ARB_framebuffer_sRGB GL_ARB_geometry_shader4 GL_ARB_get_program_binary GL_ARB_get_texture_sub_image GL_ARB_gl_spirv GL_ARB_gpu_shader5 GL_ARB_gpu_shader_fp64 GL_ARB_gpu_shader_int64 GL_ARB_half_float_pixel GL_ARB_half_float_vertex GL_ARB_imaging GL_ARB_indirect_parameters GL_ARB_instanced_arrays GL_ARB_internalformat_query GL_ARB_internalformat_query2 GL_ARB_invalidate_subdata GL_ARB_map_buffer_alignment GL_ARB_map_buffer_range GL_ARB_multi_bind GL_ARB_multi_draw_indirect GL_ARB_multisample GL_ARB_multitexture GL_ARB_occlusion_query GL_ARB_occlusion_query2 GL_ARB_parallel_shader_compile GL_ARB_pipeline_statistics_query GL_ARB_pixel_buffer_object GL_ARB_point_parameters GL_ARB_point_sprite GL_ARB_polygon_offset_clamp GL_ARB_post_depth_coverage GL_ARB_program_interface_query GL_ARB_provoking_vertex GL_ARB_query_buffer_object GL_ARB_robust_buffer_access_behavior GL_ARB_robustness GL_ARB_sample_locations GL_ARB_sample_shading GL_ARB_sampler_objects GL_ARB_seamless_cube_map GL_ARB_seamless_cubemap_per_texture GL_ARB_separate_shader_objects GL_ARB_shader_atomic_counter_ops GL_ARB_shader_atomic_counters GL_ARB_shader_ballot GL_ARB_shader_bit_encoding GL_ARB_shader_clock GL_ARB_shader_draw_parameters GL_ARB_shader_group_vote GL_ARB_shader_image_load_store GL_ARB_shader_image_size GL_ARB_shader_objects GL_ARB_shader_precision GL_ARB_shader_storage_buffer_object GL_ARB_shader_subroutine GL_ARB_shader_texture_image_samples GL_ARB_shader_texture_lod GL_ARB_shading_language_100 GL_ARB_shader_viewport_layer_array GL_ARB_shading_language_420pack GL_ARB_shading_language_include GL_ARB_shading_language_packing GL_ARB_shadow GL_ARB_sparse_buffer GL_ARB_sparse_texture GL_ARB_sparse_texture2 GL_ARB_sparse_texture_clamp GL_ARB_spirv_extensions GL_ARB_stencil_texturing GL_ARB_sync GL_ARB_tessellation_shader GL_ARB_texture_barrier GL_ARB_texture_border_clamp GL_ARB_texture_buffer_object GL_ARB_texture_buffer_object_rgb32 GL_ARB_texture_buffer_range GL_ARB_texture_compression GL_ARB_texture_compression_bptc GL_ARB_texture_compression_rgtc GL_ARB_texture_cube_map GL_ARB_texture_cube_map_array GL_ARB_texture_env_add GL_ARB_texture_env_combine GL_ARB_texture_env_crossbar GL_ARB_texture_env_dot3 GL_ARB_texture_filter_anisotropic GL_ARB_texture_filter_minmax GL_ARB_texture_float GL_ARB_texture_gather GL_ARB_texture_mirror_clamp_to_edge GL_ARB_texture_mirrored_repeat GL_ARB_texture_multisample GL_ARB_texture_non_power_of_two GL_ARB_texture_query_levels GL_ARB_texture_query_lod GL_ARB_texture_rectangle GL_ARB_texture_rg GL_ARB_texture_rgb10_a2ui GL_ARB_texture_stencil8 GL_ARB_texture_storage GL_ARB_texture_storage_multisample GL_ARB_texture_swizzle GL_ARB_texture_view GL_ARB_timer_query GL_ARB_transform_feedback2 GL_ARB_transform_feedback3 GL_ARB_transform_feedback_instanced GL_ARB_transform_feedback_overflow_query GL_ARB_transpose_matrix GL_ARB_uniform_buffer_object GL_ARB_vertex_array_bgra GL_ARB_vertex_array_object GL_ARB_vertex_attrib_64bit GL_ARB_vertex_attrib_binding GL_ARB_vertex_buffer_object GL_ARB_vertex_program GL_ARB_vertex_shader GL_ARB_vertex_type_10f_11f_11f_rev GL_ARB_vertex_type_2_10_10_10_rev GL_ARB_viewport_array GL_ARB_window_pos GL_ATI_draw_buffers GL_ATI_texture_float GL_ATI_texture_mirror_once GL_S3_s3tc GL_EXT_texture_env_add GL_EXT_abgr GL_EXT_bgra GL_EXT_bindable_uniform GL_EXT_blend_color GL_EXT_blend_equation_separate GL_EXT_blend_func_separate GL_EXT_blend_minmax GL_EXT_blend_subtract GL_EXT_compiled_vertex_array GL_EXT_Cg_shader GL_EXT_depth_bounds_test GL_EXT_direct_state_access GL_EXT_draw_buffers2 GL_EXT_draw_instanced GL_EXT_draw_range_elements GL_EXT_fog_coord GL_EXT_framebuffer_blit GL_EXT_framebuffer_multisample GL_EXTX_framebuffer_mixed_formats GL_EXT_framebuffer_multisample_blit_scaled GL_EXT_framebuffer_object GL_EXT_framebuffer_sRGB GL_EXT_geometry_shader4 GL_EXT_gpu_program_parameters GL_EXT_gpu_shader4 GL_EXT_multi_draw_arrays GL_EXT_packed_depth_stencil GL_EXT_packed_float GL_EXT_packed_pixels GL_EXT_pixel_buffer_object GL_EXT_point_parameters GL_EXT_polygon_offset_clamp GL_EXT_post_depth_coverage GL_EXT_provoking_vertex GL_EXT_raster_multisample GL_EXT_rescale_normal GL_EXT_secondary_color GL_EXT_separate_shader_objects GL_EXT_separate_specular_color GL_EXT_shader_image_load_formatted GL_EXT_shader_image_load_store GL_EXT_shader_integer_mix GL_EXT_shadow_funcs GL_EXT_sparse_texture2 GL_EXT_stencil_two_side GL_EXT_stencil_wrap GL_EXT_texture3D GL_EXT_texture_array GL_EXT_texture_buffer_object GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_latc GL_EXT_texture_compression_rgtc GL_EXT_texture_compression_s3tc GL_EXT_texture_cube_map GL_EXT_texture_edge_clamp GL_EXT_texture_env_combine GL_EXT_texture_env_dot3 GL_EXT_texture_filter_anisotropic GL_EXT_texture_filter_minmax GL_EXT_texture_integer GL_EXT_texture_lod GL_EXT_texture_lod_bias GL_EXT_texture_mirror_clamp GL_EXT_texture_object GL_EXT_texture_shared_exponent GL_EXT_texture_sRGB GL_EXT_texture_sRGB_R8 GL_EXT_texture_sRGB_decode GL_EXT_texture_storage GL_EXT_texture_swizzle GL_EXT_timer_query GL_EXT_transform_feedback2 GL_EXT_vertex_array GL_EXT_vertex_array_bgra GL_EXT_vertex_attrib_64bit GL_EXT_window_rectangles GL_EXT_import_sync_object GL_IBM_rasterpos_clip GL_IBM_texture_mirrored_repeat GL_KHR_context_flush_control GL_KHR_debug GL_EXT_memory_object GL_EXT_memory_object_win32 GL_EXT_win32_keyed_mutex GL_KHR_parallel_shader_compile GL_KHR_no_error GL_KHR_robust_buffer_access_behavior GL_KHR_robustness GL_EXT_semaphore GL_EXT_semaphore_win32 GL_KTX_buffer_region GL_NV_alpha_to_coverage_dither_control GL_NV_bindless_multi_draw_indirect GL_NV_bindless_multi_draw_indirect_count GL_NV_bindless_texture GL_NV_blend_equation_advanced GL_NV_blend_equation_advanced_coherent GL_NVX_blend_equation_advanced_multi_draw_buffers GL_NV_blend_minmax_factor GL_NV_blend_square GL_NV_clip_space_w_scaling GL_NV_command_list GL_NV_compute_program5 GL_NV_conditional_render GL_NV_conservative_raster GL_NV_conservative_raster_dilate GL_NV_conservative_raster_pre_snap_triangles GL_NV_copy_depth_to_color GL_NV_copy_image GL_NV_depth_buffer_float GL_NV_depth_clamp GL_NV_draw_texture GL_NV_draw_vulkan_image GL_NV_ES1_1_compatibility GL_NV_ES3_1_compatibility GL_NV_explicit_multisample GL_NV_feature_query GL_NV_fence GL_NV_fill_rectangle GL_NV_float_buffer GL_NV_fog_distance GL_NV_fragment_coverage_to_color GL_NV_fragment_program GL_NV_fragment_program_option GL_NV_fragment_program2 GL_NV_fragment_shader_interlock GL_NV_framebuffer_mixed_samples GL_NV_framebuffer_multisample_coverage GL_NV_geometry_shader4 GL_NV_geometry_shader_passthrough GL_NV_gpu_program4 GL_NV_internalformat_sample_query GL_NV_gpu_program4_1 GL_NV_gpu_program5 GL_NV_gpu_program5_mem_extended GL_NV_gpu_program_fp64 GL_NV_gpu_shader5 GL_NV_half_float GL_NV_light_max_exponent GL_NV_memory_attachment GL_NV_multisample_coverage GL_NV_multisample_filter_hint GL_NV_occlusion_query GL_NV_packed_depth_stencil GL_NV_parameter_buffer_object GL_NV_parameter_buffer_object2 GL_NV_path_rendering GL_NV_path_rendering_shared_edge GL_NV_pixel_data_range GL_NV_point_sprite GL_NV_primitive_restart GL_NV_query_resource GL_NV_query_resource_tag GL_NV_register_combiners GL_NV_register_combiners2 GL_NV_sample_locations GL_NV_sample_mask_override_coverage GL_NV_shader_atomic_counters GL_NV_shader_atomic_float GL_NV_shader_atomic_float64 GL_NV_shader_atomic_fp16_vector GL_NV_shader_atomic_int64 GL_NV_shader_buffer_load GL_NV_shader_storage_buffer_object GL_NV_stereo_view_rendering GL_NV_texgen_reflection GL_NV_texture_barrier GL_NV_texture_compression_vtc GL_NV_texture_env_combine4 GL_NV_texture_multisample GL_NV_texture_rectangle GL_NV_texture_rectangle_compressed GL_NV_texture_shader GL_NV_texture_shader2 GL_NV_texture_shader3 GL_NV_transform_feedback GL_NV_transform_feedback2 GL_NV_uniform_buffer_unified_memory GL_NV_vertex_array_range GL_NV_vertex_array_range2 GL_NV_vertex_attrib_integer_64bit GL_NV_vertex_buffer_unified_memory GL_NV_vertex_program GL_NV_vertex_program1_1 GL_NV_vertex_program2 GL_NV_vertex_program2_option GL_NV_vertex_program3 GL_NV_viewport_array2 GL_NV_viewport_swizzle GL_NVX_conditional_render GL_NVX_gpu_memory_info GL_NVX_multigpu_info GL_NVX_nvenc_interop GL_NV_shader_thread_group GL_NV_shader_thread_shuffle GL_KHR_blend_equation_advanced GL_KHR_blend_equation_advanced_coherent GL_OVR_multiview GL_OVR_multiview2 GL_SGIS_generate_mipmap GL_SGIS_texture_lod GL_SGIX_depth_texture GL_SGIX_shadow GL_SUN_slice_accum GL_WIN_swap_hint WGL_EXT_swap_control 

10/17 17:48:35 Debug: Maximum OpenGl texture size is 32768
10/17 17:48:35 Info: Broo Debug Web GUI ready at http://localhost:6700/broo/
10/17 17:48:35 Trace: [brooengine] Loaded atlas list. 0ms
10/17 17:48:35 Trace: [brooengine] Window is running in scale 1,104167
10/17 17:48:35 Trace: [brooengine] Using atlas scale 2
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-1.png. 38ms
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-2.png. 18ms
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-3.png. 18ms
10/17 17:48:35 Info: [broker] starting 6d31ff3c-e21a-48a5-a79a-41c3f7026581
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-4.png. 22ms
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-5.png. 16ms
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-6.png. 17ms
10/17 17:48:35 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at C:\
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-7.png. 18ms
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] getting volumeshare (\\musicserver\1M) from json due to adding volumeshare from previously mounted shares stored in registry
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] new volumeshare created from json for \\musicserver\1M
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] json volumeshare cifsmount does not exist (\\musicserver\1M), but we will not mount it now because we lazy mount shares based on need
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-8.png. 25ms
10/17 17:48:35 Info: [stats] 5189mb Virtual, 122mb Physical, 15mb Managed, 797 Handles, 35 Threads
10/17 17:48:35 Info: [broker/locations] adding storage location: Internet:Name=Internet Media:Id=e268f098-04c4-4e65-af3f-38ba3c3fcecb
10/17 17:48:35 Info: [broker/locations] media availability: Internet:Name=Internet Media:Id=e268f098-04c4-4e65-af3f-38ba3c3fcecb is online
10/17 17:48:35 Trace: [brooengine] Loaded atlas texture ui_atlas@2x-9.png. 16ms
10/17 17:48:35 Info: [broker/locations] adding storage location: MetadataService:Name=Metadata Service:Id=13769258-b70b-4243-b1d6-bd46e8257ba8
10/17 17:48:35 Info: [broker/locations] media availability: MetadataService:Name=Metadata Service:Id=13769258-b70b-4243-b1d6-bd46e8257ba8 is online
10/17 17:48:35 Info: [broker/locations] adding storage location: Offline:Name=Offline:Id=f1e4b43f-f643-47ba-b875-fd93b32a6006
10/17 17:48:35 Trace: [brooengine] Loaded atlas. 197ms
10/17 17:48:35 Debug: render area size initial value: 257x234
10/17 17:48:35 Info: Loaded broo project: ui.broox, atlas: ui
10/17 17:48:35 Debug: [broker/locations/migration] start, propname: loc_ec7ebdad05744fd0b1b8b7095fd10276
10/17 17:48:35 Debug: [broker/locations] Migrating UUID based storage location, id: loc_ec7ebdad05744fd0b1b8b7095fd10276, version: 2
10/17 17:48:35 Info: [broker/locations] adding storage location: DefaultMusicFolder:Name=Music Folder:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] getting volumeshare (\\musicserver\1M) from json due to getting entry from json
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] json volumeshare cifsmount does not exist (\\musicserver\1M), but we will not mount it now because we lazy mount shares based on need
10/17 17:48:35 Info: [broker/locations/directorystoragelocation] initializing FileBrowser.Entry: \\musicserver, 1M : \, drive availability is: False
10/17 17:48:35 Info: [broker/locations/directorystoragelocation] drive is not available so disposing resources (if they exist): FileBrowser.Entry: \\musicserver, 1M : \
10/17 17:48:35 Info: [broker/locations] storage location backend (CIFSShare:Name=:Location=FileBrowser.Entry: \\musicserver, 1M : \:Id=ec7ebdad-0574-4fd0-b1b8-b7095fd10276) offline reason changed to: DriveNotReady
10/17 17:48:35 Info: [broker/locations/directorystoragelocation] we'd like to keep this volume mounted: \\musicserver\1M
10/17 17:48:35 Info: [broker/locations] created enabled location, FileBrowser.Entry: \\musicserver, 1M : \
10/17 17:48:35 Info: [broker/locations] adding storage location: CIFSShare:Name=:Location=FileBrowser.Entry: \\musicserver, 1M : \:Id=ec7ebdad-0574-4fd0-b1b8-b7095fd10276
10/17 17:48:35 Debug: [roon/cifs] tryremount, path: \\musicserver\1M, username: , password NULL
10/17 17:48:35 Trace: [roon/cifs] WNetUseConnection(\\musicserver\1M, , <password>)
10/17 17:48:35 Trace: [roon/cifs] UseConnection \\musicserver\1M ==> 0
10/17 17:48:35 Trace: [roon/cifs] Connected
10/17 17:48:35 Trace: [brokerserver] Enabling broker server
10/17 17:48:35 Info: [broker/distributed] HTTP server listening on port 9100
10/17 17:48:35 Trace: [broker/backups] initializing
10/17 17:48:35 Info: [broker] is licensed for userid d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:35 Info: [clientdata] initializing with C:\Users\amata\AppData\Local\Roon\Database\Core\d0226e605b8c452babfd2f44cb7e2255\clientdata.db
10/17 17:48:35 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:35 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:35 Trace: [broker/accounts] refreshing account info for amatala@belgacom.net
10/17 17:48:35 Trace: [broker/accounts] booted up with token 89d0a516-000c-4204-be0f-e860a7a339a1 userid d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:35 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/login
10/17 17:48:35 Trace: [fiveaccountserver] BODY token=89d0a516-000c-4204-be0f-e860a7a339a1
10/17 17:48:35 Trace: [broker/accounts] Updating Machine Allocation machineid=a00d00ad-d7a5-f0ac-5f93-6b9cd179a053 hwserial= machinename=HOMEPCNEW machinetype=Server
10/17 17:48:35 Trace: [fiveaccountserver] POST https://accounts5.roonlabs.com/accounts/3/machineallocate
10/17 17:48:35 Trace: [fiveaccountserver] BODY token=89d0a516-000c-4204-be0f-e860a7a339a1&machine=a00d00ad-d7a5-f0ac-5f93-6b9cd179a053&name=HOMEPCNEW&type=Server
10/17 17:48:35 Info: [clientdata] initializing with C:\Users\amata\AppData\Local\Roon\Database\Core\d0226e605b8c452babfd2f44cb7e2255\clientdata.db
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] new share tracked on existing volume: \\musicserver\1M on \\musicserver\1M
10/17 17:48:35 Info: [broker/filebrowser/volumeshare] Volume's CIFSMount's availability changed: True
10/17 17:48:35 Debug: [broker/filebrowser/drive] availability on drive's volume changed: True: VolumeShare[networkpath:\\musicserver\1M,mountdir:\\musicserver\1M]
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] Use volume, user: broker/filebrowser/drive/init2, id: \\musicserver\1M
10/17 17:48:35 Info: [broker/filebrowser/volumeshare] Volume's removable changed: False
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] Use dispose, id: \\musicserver\1M
10/17 17:48:35 Info: [broker/filebrowser/volumeshare] Volume's removable changed: True
10/17 17:48:35 Info: [broker/locations/directorystoragelocation] drive availabilitychanged: True, FileBrowser.Entry: \\musicserver, 1M : \ (it was False)
10/17 17:48:35 Info: [broker/locations/directorystoragelocation] drive is available checking to referencing fs provider and setting up dirwatcher: FileBrowser.Entry: \\musicserver, 1M : \
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] Use volume, user: broker/filebrowser/entry/GetFSDir, id: \\musicserver\1M
10/17 17:48:35 Info: [broker/filebrowser/volumeshare] Volume's removable changed: False
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] Use dispose, id: \\musicserver\1M
10/17 17:48:35 Info: [broker/filebrowser/volumeshare] Volume's removable changed: True
10/17 17:48:35 Info: [libraryapi] loaded first run time 07/10/2018 07:34:46
10/17 17:48:35 Debug: [broker/filebrowser/volumeshare] Use volume, user: broker/locations/dirstorage, id: \\musicserver\1M
10/17 17:48:35 Info: [broker/filebrowser/volumeshare] Volume's removable changed: False
10/17 17:48:35 Debug: [broker/locations/directorystoragelocation] drive path lookup took 2ms: FileBrowser.Entry: \\musicserver, 1M : \
10/17 17:48:36 Debug: [broker/locations/directorystoragelocation] dirwatcher init took 0ms: FileBrowser.Entry: \\musicserver, 1M : \
10/17 17:48:36 Info: [broker/locations/directorystoragelocation] attaching backend: FileBrowser.Entry: \\musicserver, 1M : \
10/17 17:48:36 Debug: [storage/directory] directorystorage init, location(\\musicserver\1M, dirwatcher is available: True) 
10/17 17:48:36 Debug: [storage/directory] init just before reorg delete thread, path: \\musicserver\1M
10/17 17:48:36 Info: [broker/locations] storage location backend created and attached (CIFSShare:Name=:Location=FileBrowser.Entry: \\musicserver, 1M : \:Id=ec7ebdad-0574-4fd0-b1b8-b7095fd10276)

Adrian_Matala · October 17, 2018, 4:04pm

Log (cont’d):

10/17 17:48:36 Trace: [devicedb] initializing
10/17 17:48:36 Info: [broker/locations] media availability: CIFSShare:Name=:Location=FileBrowser.Entry: \\musicserver, 1M : \:Id=ec7ebdad-0574-4fd0-b1b8-b7095fd10276 is online
10/17 17:48:36 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at D:\
10/17 17:48:36 Trace: [devicedb] refreshing, etag=W/"bcb6b-1667de20afe"
10/17 17:48:36 Trace: [devicedb] builtin device db found at C:\Users\amata\AppData\Local\Roon\Application\100500354\devicedb-prod.zip
10/17 17:48:36 Trace: [devicedb] cached device db found at C:\Users\amata\AppData\Local\Roon\Cache\devicedb-prod.zip
10/17 17:48:36 Debug: render area size changed value: 1023x768
10/17 17:48:36 Trace: [devicedb] loading device db at C:\Users\amata\AppData\Local\Roon\Cache\devicedb-prod.zip
10/17 17:48:36 Debug: [storage/directory] temp directory cleared, path: \\musicserver\1M\.tmp
10/17 17:48:36 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at E:\
10/17 17:48:36 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at F:\
10/17 17:48:36 Info: [broker/filebrowser/volumeattached] skipping drive F:\ because it is a CD-Rom
10/17 17:48:36 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at G:\
10/17 17:48:36 Info: [broker/filebrowser/volumeattached] skipping drive G:\ because it is a CD-Rom
10/17 17:48:36 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at Y:\
10/17 17:48:36 Trace: [devicedb] loaded 46 vendors, 228 products from devicedb with timestamp 16/10/2018 17:17:36
10/17 17:48:36 Info: [raatserver] [runner] Start or Connect...
10/17 17:48:36 Info: ConnectOrStartAndWaitForExit RAATServer
10/17 17:48:36 Debug: initialize backend in 1045ms
10/17 17:48:36 Info: [broker/dropbox] no account configured
10/17 17:48:36 Info: [remoting] loaded protocol hash 5aa5749df30a88c939482a863f7ea4d11bd7d981 from C:\Users\amata\AppData\Local\Roon\Application\100500354\Roon.Broker.Api.Remote.dll
10/17 17:48:36 Info: [broker/distributed] Remoting server listening on port 9101
10/17 17:48:36 Trace: [distributedbroker] Enabling remote broker tracking
10/17 17:48:36 Info: [music/database] opened database. migration version = 8 current version = 8
10/17 17:48:36 Info: [playlistdb] opened. migration version = 1 current version = 1
10/17 17:48:36 Info: [identification] Starting
10/17 17:48:36 Info: [additionalimages] starting
10/17 17:48:36 Debug: [easyhttp] GET  to https://devicedb.roonlabs.net/1/devicedb-prod.zip returned after 486 ms, status code: 304
10/17 17:48:36 Trace: [devicedb] Not Modified. Nothing to do
10/17 17:48:36 Trace: Successful POST response from https://accounts5.roonlabs.com/accounts/3/login
10/17 17:48:36 Trace: Successful POST response from https://accounts5.roonlabs.com/accounts/3/machineallocate
10/17 17:48:36 Trace: [geoip] GET https://accounts5.roonlabs.com/geoip/1/lookup
10/17 17:48:36 Trace: [fiveaccountserver] GOT {"status":"Success","userid":"d0226e60-5b8c-452b-abfd-2f44cb7e2255","token":"89d0a516-000c-4204-be0f-e860a7a339a1","expiration":30,"email":"amatala@belgacom.net","groups":[]}
10/17 17:48:36 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/profileslist?token=89d0a516-000c-4204-be0f-e860a7a339a1
10/17 17:48:36 Trace: [fiveaccountserver] GET https://accounts5.roonlabs.com/accounts/3/userinfo?token=89d0a516-000c-4204-be0f-e860a7a339a1
10/17 17:48:36 Trace: [broker/accounts] updated token. New expiration is 16/11/2018 17:48:35
10/17 17:48:36 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:36 Debug: [easyhttp] POST to https://bits.roonlabs.net/1/q/roon.debug.,roon.client.,roon.broker.,roon.dsp.,roon.sood?roon_auth_token=89d0a516-000c-4204-be0f-e860a7a339a1
10/17 17:48:36 Trace: [fiveaccountserver] GOT {"status":"Success","licenseid":"9fbb0644-5ba4-49ca-9e1a-ad6bbae0a2d6"}
10/17 17:48:36 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:36 Trace: [broker/accounts] Machine Allocation Succeeded
10/17 17:48:36 Trace: [geoip] GOT {"country":"BE","state":"VBR","city":"Vilvoorde","postalcode":"1800","latitude":50.9333,"longitude":4.4333,"ipaddress":"87.65.75.14","status":"Success"}
10/17 17:48:36 Trace: [fiveaccountserver] GOT {"status":"Success","profiles":[{"id":"04c4fffb-9f08-425c-ae00-3d503c617a00","name":"Adrian","photo":"https://sooloos-profileimages.s3.amazonaws.com/five-d0226e60-5b8c-452b-abfd-2f44cb7e2255--04c4fffb-9f08-425c-ae00-3d503c617a00.jpg","birthdate":"19730000","facebook_auth":"{ \"accesstoken\": \"EAADeu8DcOV8BALtpZApBw5AaWQubrI57AaZBKZBTTllSZB3t1AcyKm2BZCwtcsB2MecJLfRhlA8gAuFxygAoxPIS9AA4A7ZAvnTSnJfk5iy88R37EoJPnibSVXyBAJtXSuzCL6nn3OdE1qEESHrwKyrcdp9fzUT6ZBgNr86YLfYUAZDZD\" }"}]}
10/17 17:48:36 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:36 Info: [library] Queueing initial load of 221137 tracks + 21403 auxfiles
10/17 17:48:36 Trace: [music/genres] loading genres (contenthash=30192aee32efe9356b00bf2fd4340f77)
10/17 17:48:36 Info: GENRE: name,level,is broad?,is holiday?,is stratified?,is directonly?
10/17 17:48:36 Trace: [music/genres] load complete. 1227 genres loaded.
10/17 17:48:36 Trace: [music/genres] fetching genre list from remote (contenthash=30192aee32efe9356b00bf2fd4340f77)
10/17 17:48:36 Trace: [metadatasvc] REQ https://metadata5.roonlabs.com/md/4/updategenres?uid=d0226e60-5b8c-452b-abfd-2f44cb7e2255&lid=&token=89d0a516-000c-4204-be0f-e860a7a339a1&content_hash=30192aee32efe9356b00bf2fd4340f77
10/17 17:48:37 Trace: [httpcache] loaded 4594 cache entries from C:\Users\amata\AppData\Local\Roon\Cache\httpcache_2.db, current: 127mb / 128mb
10/17 17:48:37 Info: [broker/locations] adding storage location: Tidal:Name=TIDAL:Id=a2bc918b-81fb-abc3-f24b-19bcfed910a2
10/17 17:48:37 Info: [broker/locations] updating location Tidal:Name=TIDAL:Id=a2bc918b-81fb-abc3-f24b-19bcfed910a2
10/17 17:48:37 Info: [broker/locations] updating location Tidal:Name=TIDAL:Id=a2bc918b-81fb-abc3-f24b-19bcfed910a2
10/17 17:48:37 Info: [broker/locations] updating location Tidal:Name=TIDAL:Id=a2bc918b-81fb-abc3-f24b-19bcfed910a2
10/17 17:48:37 Debug: {X=0,Y=0,Width=1920,Height=1080}
10/17 17:48:37 Trace: [fiveaccountserver] GOT {"user":{"userid":"d0226e60-5b8c-452b-abfd-2f44cb7e2255","firstname":"Adrian","lastname":"Matala","email":"amatala@belgacom.net","joinmailinglist":true,"class":"Normal","groups":[],"trialallowed":false},"status":"Success"}
10/17 17:48:37 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:48:37 Trace: [roonbridge] [sood] Refreshing device list
10/17 17:48:37 Info: [raatserver] [runner] Status: Started
10/17 17:48:37 Debug: [easyhttp] POST to https://bits.roonlabs.net/1/q/roon.debug.,roon.client.,roon.broker.,roon.dsp.,roon.sood?roon_auth_token=89d0a516-000c-4204-be0f-e860a7a339a1 returned after 668 ms, status code: 200
10/17 17:48:37 Trace: [bits] updated bits, in 679ms
10/17 17:48:37 Debug: ev_app_init: using local broker
10/17 17:48:37 Info: [client/root] Broker changed null => HOMEPCNEW (Local Broker  6d31ff3c-e21a-48a5-a79a-41c3f7026581)
10/17 17:48:37 Info: [client/root] Client is controlling the local broker
10/17 17:48:37 Info: [client/root] Broker ready changed False => True
10/17 17:48:37 Debug: ev_app_init: showing app loading window
10/17 17:48:37 Debug: app_init completed
10/17 17:48:37 Debug: trigger: appinitwasnotrun
10/17 17:48:37 Debug: trigger: do nothing
10/17 17:48:47 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 17:48:47 Trace: [push] connecting to 104.248.55.243:9200
10/17 17:48:47 Trace: [push] connected
10/17 17:48:50 Info: [stats] 6264mb Virtual, 1070mb Physical, 677mb Managed, 1470 Handles, 71 Threads
10/17 17:48:56 Warn: [library] work id 293756 (124:0:MC0002460640) not found
10/17 17:48:56 Warn: [library] failed to create performance 9847669 (117:1:5802e1a6-0018-48e5-a383-85ffa371bf73): missing work 293756 (124:0:MC0002460640). can't load performance
10/17 17:49:05 Trace: [library] finished with 221137 dirty tracks 19570 dirty albums 74174 dirty performers 71101 dirty works 88924 dirty performances 1231 dirty genres 21403 dirty auxfiles 384 dirty countries 9 dirty periods 40 dirty forms 4601 dirty places 2673 dirty creditroles 4056 dirty labels 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 221137 tracks to (re)load, 0 tracks to retain, 21403 auxfiles to (re)load, 0 auxfiles to retain, and 476137 changed objects
10/17 17:49:05 Debug: [library/index] updating search indices: 0 ops 0 adds, 0 removes
10/17 17:49:05 Trace: [dbperf] flush 0 bytes, 0 ops in 16589 ms (cumulative 0 bytes, 0 ops in 16589 ms)
10/17 17:49:05 Info: [music/storage] enabling library
10/17 17:49:05 Info: [music/storage] Loading storage backend \
10/17 17:49:05 Trace: [appupdater] initial check for updates
10/17 17:49:05 Debug: [base/updater] Checking for updates: http://updates.roonlabs.com/update/?v=2&serial=2C879555-B14C-4AE4-A02C-E60E966614F8&userid=d0226e60-5b8c-452b-abfd-2f44cb7e2255&platform=windows64&product=Roon&branding=roon&curbranch=stable&version=100500354&branch=stable
10/17 17:49:05 Info: [stats] 7395mb Virtual, 2316mb Physical, 1655mb Managed, 1398 Handles, 60 Threads
10/17 17:49:06 Info: [library] retaining 221137 tracks for storage backend ec7ebdad-0574-4fd0-b1b8-b7095fd10276 (\)
10/17 17:49:06 Info: [library] retaining 21403 auxfiles for storage backend ec7ebdad-0574-4fd0-b1b8-b7095fd10276 (\)
10/17 17:49:07 Info: [loadstatus] IsLibraryLoading True => False
10/17 17:49:07 Trace: [library] endmutation in 30649ms
10/17 17:49:07 Info: [music] first pass through media thread is done
10/17 17:49:07 Debug: [appupdater] Update not needed
10/17 17:49:07 Debug: Begin queuing fs events, ignoreitunes: False, ignoreplaylists: False
10/17 17:49:07 Debug: [storage/directory] case sensitivity, check path: \\musicserver\1M\@!hi-res stereo, result: False
10/17 17:49:07 Debug: [storage/directory] case sensitivity test, rootpath: \\musicserver\1M, result: False
10/17 17:49:07 Info: Flushing kart data to server
10/17 17:49:08 Debug: server said: 
10/17 17:49:09 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 17:49:09 Trace: [push] retrying connection in 6918ms
10/17 17:49:11 Trace: [library] finished with 221137 dirty tracks 19570 dirty albums 67182 dirty performers 70904 dirty works 88923 dirty performances 914 dirty genres 21403 dirty auxfiles 360 dirty countries 9 dirty periods 40 dirty forms 4102 dirty places 2673 dirty creditroles 4056 dirty labels 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 0 tracks to (re)load, 221137 tracks to retain, 0 auxfiles to (re)load, 21403 auxfiles to retain, and 468630 changed objects
10/17 17:49:11 Debug: [library/index] updating search indices: 404437 ops 403429 adds, 0 removes
10/17 17:49:16 Trace: [dbperf] flush 0 bytes, 0 ops in 568 ms (cumulative 0 bytes, 0 ops in 17157 ms)
10/17 17:49:16 Trace: [library] endmutation in 8453ms
10/17 17:49:16 Info: [transport] initializing
10/17 17:49:16 Trace: [broker/accounts] Data updated. AccountStatus=LoggedIn MachineStatus=Licensed UserId=d0226e60-5b8c-452b-abfd-2f44cb7e2255
10/17 17:49:16 Trace: [transport] enabling transport
10/17 17:49:16 Trace: [metadatasvc] GOT (39239ms) Sooloos.Msg.Metadata.GenresUpdate: 
10/17 17:49:16 Trace: [music/genres] got genre update in 39245ms
10/17 17:49:16 Trace: [music/genres] no update required
10/17 17:49:16 Trace: [scd] reinit
10/17 17:49:16 Trace: [scd] using subnet 30341aac 172.26.52.48
10/17 17:49:16 Trace: [raat] [sood] Refreshing device list
10/17 17:49:16 Trace: [raatserver] [sood] Refreshing device list
10/17 17:49:16 Trace: [scd] reinit
10/17 17:49:16 Trace: [scd] using subnet 30341aac 172.26.52.48
10/17 17:49:16 Info: [transport] enabling squeezebox server
10/17 17:49:16 Info: [squeezebox/server] listening for slimproto clients on port 3483, http clients on port 9000
10/17 17:49:16 Info: [squeezebox/discovery] starting
10/17 17:49:16 Info: [hqplayer] initializing integration
10/17 17:49:16 Info: [transport] enabling meridian streaming
10/17 17:49:16 Info: [transport] initialized
10/17 17:49:16 Info: [loadstatus] IsTransportLoading True => False
10/17 17:49:16 Info: [loadstatus] IsStartup True => False
10/17 17:49:16 Debug: ev_app_init: using local broker
10/17 17:49:16 Info: [roonapi] initializing
10/17 17:49:16 Debug: ev_app_init: done
10/17 17:49:16 Debug: trigger: appinitwasrun
10/17 17:49:16 Debug: trigger: apploaded, restoring nav stack
10/17 17:49:16 Debug: GMS: restoring nav stack
10/17 17:49:16 Debug: GMS: restoring nav stack data: trackbrowser
10/17 17:49:16 Trace: [raat] RAATServer discovered: RaatServer HOMEPCNEW @ 127.0.0.1:15964
10/17 17:49:16 Info: [raatserver] GOT SERVER a00d00ad-d7a5-f0ac-5f93-6b9cd179a053::e4e62423-4f04-4bbf-9b10-547695701d8b @ 127.0.0.1:15964 HOMEPCNEW PROTOVER=1 RAATVER=1.1.30 
10/17 17:49:16 Trace: [raatserver] [RaatServer HOMEPCNEW @ 127.0.0.1:15964] connecting (attempt 1)
10/17 17:49:16 Trace: [raatserver] [RaatServer HOMEPCNEW @ 127.0.0.1:15964] connected
10/17 17:49:16 Trace: [rnet/RnetJsonClient] SENT {"request":"enumerate_devices","subscription_id":"0"}
10/17 17:49:16 Trace: [rnet/RnetJsonClient] GOT NONFINAL {"status": "Success", "devices": [{"name": "System Output", "device_id": "default", "type": "wasapi", "is_system_output": true, "config": {"external_config": {}, "unique_id": "77b2704c-74f8-1a55-d02e-228b66844e21", "output": {"type": "wasapi", "name": "System Output", "device": "default"}, "volume": {"type": "wasapi", "device": "default"}}}, {"name": "Realtek High Definition Audio", "device_id": "{0.0.0.00000000}.{3832618b-da77-432a-88d9-c15bc220ec50}", "type": "wasapi"}, {"name": "Realtek High Definition Audio", "device_id": "{0.0.0.00000000}.{e4101496-0333-493f-91fb-633161324d7f}", "type": "wasapi", "config": {"external_config": {}, "unique_id": "d3fab2f6-77d5-7cb2-4ec5-eeb3b34ced55", "output": {"type": "wasapi", "name": "Realtek High Definition Audio", "device": "{0.0.0.00000000}.{e4101496-0333-493f-91fb-633161324d7f}"}, "volume": {"type": "wasapi", "device": "{0.0.0.00000000}.{e4101496-0333-493f-91fb-633161324d7f}"}}}, {"name": "CA USBAudio ASIO Driver", "device_id": "{55DC9612-7218-49A6-8748-0A1AA1CD5724}", "type": "asio"}, {"name": "JRiver Media Center 23", "device_id": "{FBD8E51C-6638-4867-A3C9-D0C099CC51E0}", "type": "asio"}]}
10/17 17:49:16 Trace: [devicedb] [autodetect] No Match for DeviceAutodetectData[Type=Local Model=System Output]
10/17 17:49:16 Info: [raatserver] GOT DEVICE e4e62423-4f04-4bbf-9b10-547695701d8b::default Type=wasapi Name=System Output 
10/17 17:49:16 Trace: [devicedb] [autodetect] No Match for DeviceAutodetectData[Type=Local Model=Realtek High Definition Audio]
10/17 17:49:16 Info: [raatserver] GOT DEVICE e4e62423-4f04-4bbf-9b10-547695701d8b::{0.0.0.00000000}.{3832618b-da77-432a-88d9-c15bc220ec50} Type=wasapi Name=Realtek High Definition Audio 
10/17 17:49:16 Info: [raatserver] GOT DEVICE e4e62423-4f04-4bbf-9b10-547695701d8b::{0.0.0.00000000}.{e4101496-0333-493f-91fb-633161324d7f} Type=wasapi Name=Realtek High Definition Audio 
10/17 17:49:16 Trace: [devicedb] [autodetect] No Match for DeviceAutodetectData[Type=Local Model=CA USBAudio ASIO Driver AsioDriverId={55DC9612-7218-49A6-8748-0A1AA1CD5724}]
10/17 17:49:16 Info: [raatserver] GOT DEVICE e4e62423-4f04-4bbf-9b10-547695701d8b::{55DC9612-7218-49A6-8748-0A1AA1CD5724} Type=asio Name=CA USBAudio ASIO Driver 
10/17 17:49:16 Trace: [devicedb] [autodetect] No Match for DeviceAutodetectData[Type=Local Model=JRiver Media Center 23 AsioDriverId={FBD8E51C-6638-4867-A3C9-D0C099CC51E0}]
10/17 17:49:16 Info: [raatserver] GOT DEVICE e4e62423-4f04-4bbf-9b10-547695701d8b::{FBD8E51C-6638-4867-A3C9-D0C099CC51E0} Type=asio Name=JRiver Media Center 23 
10/17 17:49:16 Trace: [rnet/RnetJsonClient] SENT {"request":"enable_device","device_id":"default","subscription_id":"1"}
10/17 17:49:17 Info: [roonapi] listening on port 9150
10/17 17:49:17 Debug: GMS: restoring nav stack data: albumbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: artistbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: composerbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: workbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: tagbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: playlistbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: playlistdetails
10/17 17:49:17 Debug: GMS: restoring nav stack data: phonetrackbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: phonealbumbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: phoneartistbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: phonecomposerbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: phoneworkbrowser
10/17 17:49:17 Debug: GMS: restoring nav stack data: screens
10/17 17:49:17 Debug: UI-FWD: skipping fwd2 due to lazyload: home
10/17 17:49:17 Debug: UI-FWD: skipping fwd2 due to lazyload: albumbrowser
10/17 17:49:17 Debug: UI-FWD: skipping fwd2 due to lazyload: artistbrowser
10/17 17:49:17 Debug: UI-FWD: skipping fwd2 due to lazyload: albumbrowser
10/17 17:49:17 Debug: UI-FWD: skipping fwd2 due to lazyload: albumdetails
10/17 17:49:17 Debug: UI-FWD: skipping fwd2 due to lazyload: queue
10/17 17:49:17 Debug: GMS: found currentscreen in GMS file, going to index 3
10/17 17:49:17 Debug: UI-FORCE-UNLAZY: mode: albumbrowser
10/17 17:49:17 Debug: GMS: trying to save nav stack, but nav stack stuff was in progress
10/17 17:49:17 Debug: UI-FWD: mode: albumbrowser
10/17 17:49:17 Debug: GMS: trying to save nav stack, but nav stack stuff was in progress
10/17 17:49:17 Debug: UI-NAV: album browser / focus:  / infobar:  / bookmarkdata: [object Broo.Runtime.BrooMap]
10/17 17:49:17 Debug: GMS: done restoring nav stack
10/17 17:49:17 Trace: [music/query] performing album query
10/17 17:49:17 Trace: [music/query] query returned 19570 Sooloos.Broker.Api.AlbumLite(s)
10/17 17:49:17 Trace: [rnet/RnetJsonClient] GOT NONFINAL {"status": "DeviceChanged", "device": {"name": "System Output", "device_id": "default", "discovery_data": {"tcp_port": 15972, "vendor": "N/A", "unique_id": "77b2704c-74f8-1a55-d02e-228b66844e21", "version": "N/A", "raat_version": "1.1.30", "protocol_version": "3", "model": "N/A"}, "type": "wasapi", "is_system_output": true, "config": {"external_config": {}, "unique_id": "77b2704c-74f8-1a55-d02e-228b66844e21", "output": {"type": "wasapi", "name": "System Output", "device": "default"}, "volume": {"type": "wasapi", "device": "default"}}}}
10/17 17:49:17 Info: [raatserver] [System Output] connecting (attempt 1)
10/17 17:49:17 Trace: [rnet/RnetJsonClient] GOT NONFINAL {"status": "Success"}
10/17 17:49:17 Trace: [System Output] [raatclient] Initializing RAAT session
10/17 17:49:17 Trace: [System Output] [raatclient] Loading script raat.dat:base.lua as module base [1088 chars]
10/17 17:49:17 Trace: [System Output] [raatclient] Loading script raat.dat:dkjson.lua as module dkjson [22416 chars]
10/17 17:49:17 Trace: [System Output] [raatclient] Loading script raat.dat:protocol.lua as module protocol [2045 chars]
10/17 17:49:17 Trace: [System Output] [raatclient] Loading script raat.dat:roon_tcp.lua [42279 chars]
10/17 17:49:17 Trace: [System Output] [raatclient] RAAT Session initialized in 18ms
10/17 17:49:17 Trace: [System Output] [raatclient] SENT [2]{"request":"info"}
10/17 17:49:17 Trace: [System Output] [raatclient] SENT [3]{"request":"set_client_type","client_type":"Roon"}
10/17 17:49:17 Trace: [System Output] [raatclient] GOT [2] {"transport":{"is_supported":false,"info":[]},"flags":{"has_write_chmap":true},"platform":{"os":"windows"},"output":{"supported_formats":"48000/24/2|8,96000/16/2|8,192000/16/2|8,44100/24/2|8,48000/16/2|8,192000/24/2|8,44100/16/2|8,96000/24/2|8","info":{"config":{"type":"wasapi","device":"default","name":"System Output"}}},"volume":{"info":{"config":{"device":"default","type":"wasapi"}},"is_supported":true},"status":"Success","source_selection":{"info":[],"is_supported":false},"info":{"unique_id":"77b2704c-74f8-1a55-d02e-228b66844e21"}}
10/17 17:49:17 Trace: [System Output] [raatclient] GOT [3] {"status":"Success"}
10/17 17:49:17 Trace: [raatserver] [System Output] connected
10/17 17:49:17 Info: [transport] creating endpoint for raat device 77b2704c-74f8-1a55-d02e-228b66844e21
10/17 17:49:17 Trace: [System Output] [raatclient] SENT [4]{"request":"subscribe_transport"}
10/17 17:49:17 Debug: AudioDeviceMunge.GetManufacturer(AudioDeviceType.Local, "", "System Output", "", "") => (null);
10/17 17:49:17 Debug: AudioDeviceMunge.GetModel(AudioDeviceType.Local, "", "System Output", "", "") => (null);
10/17 17:49:17 Debug: AudioDeviceMunge.GetManufacturer(AudioDeviceType.Local, "", "", "", "") => (null);
10/17 17:49:17 Debug: AudioDeviceMunge.GetModel(AudioDeviceType.Local, "", "", "", "") => (null);
10/17 17:49:17 Trace: [System Output] [raatclient] SENT [5]{"request":"subscribe_controls","controller_id":"6d31ff3c-e21a-48a5-a79a-41c3f7026581"}
10/17 17:49:17 Trace: [System Output] [raatclient] GOT [5] {"controls":{"volume":{"type":"number","mute":false,"step":1.0,"value":100,"min":0.0,"info":{"config":{"device":"default","type":"wasapi"}},"max":100.0}},"status":"Success","action":"Changed"}
10/17 17:49:17 Trace: [dspengine] created new dsp config {"version":3,"items":[{"type":"bs2b","enabled":false},{"type":"parametric_equalizer","enabled":false},{"type":"audeze_presets","enabled":false}]}
10/17 17:49:17 Trace: [transport/audeze] picking preset lowlatency 
10/17 17:49:17 Trace: [transport/audeze] picked null preset!
10/17 17:49:17 Trace: [zone System Output] Loading
10/17 17:49:17 Trace: [zone System Output] Suspend
10/17 17:49:17 Trace: [System Output] [zoneplayer/raat] Endpoint System Output Initial State: Idle
10/17 17:49:17 Info: [transport] created zone System Output
10/17 17:49:17 Info: [transport]     with endpoint System Output (23:1:77b2704c-74f8-1a55-d02e-228b66844e21) [IsAvailable=True]
10/17 17:49:17 Trace: [System Output] [Inactive] [STOPPED @ 0:00] 
10/17 17:49:17 Info: [swim] Loaded Swim : TransportDb.SwimMediaSpec={ LimitToSeed=True PreplayTrackFromSeed=True TrackCriteria=115 bytes IncludeHidden=True }
10/17 17:49:17 Trace: [radio] [1] create session
10/17 17:49:19 Trace: [radio] [1] done in 29ms
10/17 17:49:19 Trace: [radio] [1] get next items nitems=10 flushed_trackids=
10/17 17:49:19 Trace: [radio] [1]     Track Johnny Hallyday - Allumer le Feu
10/17 17:49:19 Trace: [radio] [1]     Track Peter Frampton - All I Wanna Be (Is by Your Side)
10/17 17:49:19 Trace: [radio] [1]     Track Johnny Cash - Delia's Gone
10/17 17:49:19 Trace: [radio] [1]     Track John Mellencamp - Baltimore Oriole
10/17 17:49:19 Trace: [radio] [1]     Track Johnny Winter - Leland Mississippi Blues
10/17 17:49:19 Trace: [radio] [1]     Track Roger Waters - Money
10/17 17:49:19 Trace: [radio] [1]     Track Rhapsody - The Magic of the Wizard's Dream
10/17 17:49:19 Trace: [radio] [1]     Track Helloween - I Live for Your Pain
10/17 17:49:19 Trace: [radio] [1]     Track The Alan Parsons Project - Children of the Moon
10/17 17:49:19 Trace: [radio] [1]     Track The Beatles - Ticket To Ride
10/17 17:49:19 Trace: [radio] [1] done in 31ms
10/17 17:49:19 Trace: [zone System Output] Loaded Queue=1 Tracks Swim=Active AutoSwim=True Loop=Disabled Shuffle=False
10/17 17:49:19 Trace: [analysis] prioritizing next track LibraryTrack[27895602, Johnny Hallyday - Flashback Tour - Allumer le Feu IsAvailable=True IsDeleted=False ] for zone 22:1:77b2704c-74f8-1a55-d02e-228b66844e21
10/17 17:49:19 Trace: [analysis] analyzing (high priority) trackid=27895602 url=\\musicserver\1M\@J\J[F-Z]\Johnny Hallyday\[2006] Flashback Tour - Disc 2\03 Allumer le Feu.flac
10/17 17:49:19 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 17:49:19 Trace: [push] connecting to 104.248.55.243:9200
10/17 17:49:19 Trace: [push] connected
10/17 17:49:20 Info: [stats] 8041mb Virtual, 2608mb Physical, 2047mb Managed, 1737 Handles, 96 Threads
10/17 17:49:20 Info: [squeezebox/client] [192.168.1.39:62804] connected
10/17 17:49:21 Trace: [squeezebox/client] [192.168.1.39:62804] GOT HELO device_id=5 revision=87 mac=00:04:20:10:05:5b uuid=00000000-0000-0000-0000-000000000000 wlan_channel_list=32768 bytes_received=0 language=EN capabilities=
10/17 17:49:21 Info: [squeezebox/client] [192.168.1.39:62804] Device Data: modelkey=transporter model=Squeezebox Transporter uuid=00000000-0000-0000-0000-000000000000 name= mac=00:04:20:10:05:5b ipendpoint=192.168.1.39:62804
10/17 17:49:21 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=     crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914186617 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:22 Trace: [squeezebox/client] [192.168.1.39:62804] State Change Initializing => Connected
10/17 17:49:22 Info: [transport] creating endpoint for squeezebox device 23:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 17:49:22 Trace: [squeezebox/client] [192.168.1.39:62804] SENT audg oldvol=100 dvc=1 preamp=255 newvol=65536
10/17 17:49:22 Trace: [dspengine] created new dsp config {"version":3,"items":[{"type":"bs2b","enabled":false},{"type":"parametric_equalizer","enabled":false},{"type":"audeze_presets","enabled":false}]}
10/17 17:49:22 Trace: [transport/audeze] picking preset lowlatency 
10/17 17:49:22 Trace: [transport/audeze] picked null preset!
10/17 17:49:22 Info: [devicedb] [autodetect] Match DeviceAutodetectData[Type=Squeezebox Vendor=Logitech Model=Squeezebox Transporter] => Squeezebox Transporter
10/17 17:49:22 Info: [squeezebox] device TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:62804) added
10/17 17:49:22 Debug: AudioDeviceMunge.GetManufacturer(AudioDeviceType.Squeezebox, "Logitech", "Squeezebox Transporter", "TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:62804)", "") => "Logitech";
10/17 17:49:22 Debug: AudioDeviceMunge.GetModel(AudioDeviceType.Squeezebox, "Logitech", "Squeezebox Transporter", "TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:62804)", "") => "Squeezebox Transporter";
10/17 17:49:22 Trace: [zone TR2] Loading
10/17 17:49:22 Trace: [zone TR2] Suspend
10/17 17:49:22 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:22 Info: [transport] created zone TR2
10/17 17:49:22 Info: [transport]     with endpoint TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:62804) (23:1:b5c97230-9c8a-8806-ceda-428deec6b131) [IsAvailable=True]
10/17 17:49:22 Trace: [TR2] [Inactive] [STOPPED @ 0:00] 
10/17 17:49:22 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=audg crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914188206 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:22 Trace: [zone TR2] Loaded Queue=10 Tracks Swim=Inactive AutoSwim=True Loop=Disabled Shuffle=False
10/17 17:49:22 Trace: [TR2] [Inactive] [PAUSED @ 0:00/4:08] Prize - Gavin Harrison / Osric
10/17 17:49:22 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914188237 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:23 Trace: [analysis] analysis completed in 3743ms for 335s of FLAC 44.1kHz 16bit audio. loudness=-9,62720951959121LUFS dbTP=0,234729892166382 noisestartms=0 noiseendms=333762 isdts=False mqa=0 for track 27895602 url=\\musicserver\1M\@J\J[F-Z]\Johnny Hallyday\[2006] Flashback Tour - Disc 2\03 Allumer le Feu.flac
10/17 17:49:23 Trace: [library] finished with 1 dirty tracks 1 dirty albums 4 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 8 changed objects
10/17 17:49:23 Debug: [library/index] updating search indices: 2 ops 0 adds, 0 removes
10/17 17:49:23 Trace: [dbperf] flush 4914 bytes, 2 ops in 4 ms (cumulative 4914 bytes, 2 ops in 17161 ms)
10/17 17:49:23 Trace: [library] endmutation in 33ms
10/17 17:49:23 Trace: [squeezebox/server] [COMET] GOT [{"ext":{"mac":"00:04:20:1a:41:22","uuid":"87fd26ee398cc1a59b401d7ab4146759","rev":"7.5.4 r9408"},"supportedConnectionTypes":["streaming"],"version":"1.0","channel":"\/meta\/handshake"}]
10/17 17:49:23 Trace: [squeezebox/server] [COMET] SENT [{"successful":true,"version":"1.0","channel":"/meta/handshake","advice":{"reconnect":"reconnect","timeout":60000,"interval":0},"clientId":"02102d77","supportedConnectionTypes":["streaming"]}]

Adrian_Matala · October 17, 2018, 4:04pm

Log (cont’d):

10/17 17:49:23 Trace: [squeezebox/server] [COMET] GOT [{"clientId":"02102d77","connectionType":"streaming","channel":"\/meta\/connect"},{"clientId":"02102d77","subscription":"\/02102d77\/**","channel":"\/meta\/subscribe"}]
10/17 17:49:23 Trace: [squeezebox/server] [COMET] [{"successful":true,"clientId":"02102d77","channel":"/meta/connect","timestamp":"Wed, 17 Oct 2018 15:49:23 GMT","advice":{"interval":5000}},{"successful":true,"clientId":"02102d77","subscription":"/02102d77/**","channel":"/meta/subscribe"}]
10/17 17:49:23 Trace: [squeezebox/server] [COMET] GOT [{"id":1,"data":{"request":["",["serverstatus",0,50,"subscribe:60"]],"response":"\/02102d77\/slim\/serverstatus"},"channel":"\/slim\/subscribe"},{"id":2,"data":{"request":["",["firmwareupgrade","firmwareVersion:7.5.4 r9408","inSetup:0","machine:jive","subscribe:0"]],"response":"\/02102d77\/slim\/firmwarestatus"},"channel":"\/slim\/subscribe"}]
10/17 17:49:23 Trace: [squeezebox/server] [COMET] SENT [{"successful":true,"clientId":"02102d77","channel":"/slim/subscribe","id":"1"},{"successful":true,"clientId":"02102d77","channel":"/slim/subscribe","id":"2"}]
10/17 17:49:23 Trace: [squeezebox/server] [COMET] [{"id":"2","data":{"firmwareUpgrade":0},"channel":"/02102d77/slim/firmwarestatus"}]
10/17 17:49:29 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 17:49:29 Trace: [push] retrying connection in 40500ms
10/17 17:49:30 Trace: [zone TR2] PlayPause
10/17 17:49:30 Trace: [zone TR2] Unpause
10/17 17:49:30 Trace: [zone TR2] Selecting Source state=Paused
10/17 17:49:30 Trace: [zone TR2] Unsuspend
10/17 17:49:30 Info: [TR2] [zoneplayer] Playing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\01 Prize.flac
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914195815 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:30 Info: [TR2] [zoneplayer]     Open Result (Playing):Result[Status=Success]
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914195857 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:30 Info: [TR2] [zoneplayer] Performing initial seek to 0
10/17 17:49:30 Info: SEEK MS 0
10/17 17:49:30 Info: [TR2] [zoneplayer] Starting playback
10/17 17:49:30 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/248 sec
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=s autostart=1 formatbyte=f pcmsamplesize=? pcmsamplerate=? pcmchannels=? pcmendian=? threshold=255 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=GET /b446b494816d486a96dbd8a41f09598d HTTP/1.0


10/17 17:49:30 Info: [zone TR2] OnPlayFeedback Playing
10/17 17:49:30 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [PLAYING @ 0:00/4:08] Prize - Gavin Harrison / Osric
10/17 17:49:30 Trace: [musicpowerstate] music is playing, preventing idle sleep
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914195917 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMc crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914195918 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMe crlf_count=0 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914195920 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:30 Info: [TR2] [zoneplayer] Queueing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\02 Identitas.flac
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMh crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914195957 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:30 Info: [TR2] [zoneplayer] Open result (Queueing): Result[Status=Success]
10/17 17:49:30 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/305 sec
10/17 17:49:30 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMs crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=301624 bytes_received=0 wireless_signal=65535 jiffies=2914196144 output_buffer_size=3528000 output_buffer_fullness=64640 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:31 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Flac 44100/16/2 BitRate=786 Quality=Lossless
    Output OutputType=Squeezebox Quality=Lossless SubType= Model=Squeezebox Transporter
------------------------------------------------------------
10/17 17:49:35 Info: [stats] 7987mb Virtual, 2560mb Physical, 2063mb Managed, 1794 Handles, 89 Threads
10/17 17:49:40 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 17:49:40 Trace: [push] connecting to 104.248.55.243:9200
10/17 17:49:40 Trace: [push] connected
10/17 17:49:40 Trace: [zone TR2] PlayPause
10/17 17:49:40 Trace: [zone TR2] Pause
10/17 17:49:40 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 0:00/4:08] Prize - Gavin Harrison / Osric
10/17 17:49:40 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=p autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:40 Info: [zone TR2] OnPlayFeedback Paused
10/17 17:49:40 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PAUSED @ 0:00/4:08] Prize - Gavin Harrison / Osric
10/17 17:49:40 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMp crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=3145727 bytes_received=0 wireless_signal=65535 jiffies=2914205934 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:42 Trace: [zone TR2] PlayPause
10/17 17:49:42 Trace: [zone TR2] Unpause
10/17 17:49:42 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=u autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:42 Info: [zone TR2] OnPlayFeedback Playing
10/17 17:49:42 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 0:00/4:08] Prize - Gavin Harrison / Osric
10/17 17:49:42 Trace: [musicpowerstate] music is playing, preventing idle sleep
10/17 17:49:42 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMr crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=3145727 bytes_received=0 wireless_signal=65535 jiffies=2914207398 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [zone TR2] Next
10/17 17:49:44 Info: [zone TR2] OnPlayFeedback Stopped
10/17 17:49:44 Debug: [zone TR2] _Advance
10/17 17:49:44 Trace: [zone TR2] Selecting Source state=Stopped
10/17 17:49:44 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
10/17 17:49:44 Info: [audio/env] [zoneplayer] All streams were disposed
10/17 17:49:44 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [LOADING @ 0:00] Identitas - Gavin Harrison / Osric
10/17 17:49:44 Trace: [analysis] prioritizing next track LibraryTrack[20730162, Gavin Harrison, Osric, 05ric - The Man Who Sold Himself - The Man Who Sold Himself IsAvailable=True IsDeleted=False ] for zone 22:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 17:49:44 Trace: [analysis] analyzing (high priority) trackid=20730162 url=\\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\03 The Man Who Sold Himself.flac
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:44 Info: [TR2] [zoneplayer] Playing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\02 Identitas.flac
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:44 Info: [TR2] [zoneplayer] Queueing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\03 The Man Who Sold Himself.flac
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210158 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Info: [TR2] [zoneplayer]     Open Result (Playing):Result[Status=Success]
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:44 Info: [TR2] [zoneplayer] Starting playback
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=s autostart=1 formatbyte=f pcmsamplesize=? pcmsamplerate=? pcmchannels=? pcmendian=? threshold=255 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=GET /9469dd888c264253a549877ca42d1cc4 HTTP/1.0


10/17 17:49:44 Info: [zone TR2] OnPlayFeedback Playing
10/17 17:49:44 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 0:00] Identitas - Gavin Harrison / Osric
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210159 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210160 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/305 sec
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210161 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210162 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMc crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210163 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMe crlf_count=0 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210184 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:44 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMh crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914210196 output_buffer_size=3528000 output_buffer_fullness=3505280 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:45 Info: [TR2] [zoneplayer] Open result (Queueing): Result[Status=Success]
10/17 17:49:45 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/203 sec
10/17 17:49:45 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Flac 44100/16/2 BitRate=809 Quality=Lossless
    Output OutputType=Squeezebox Quality=Lossless SubType= Model=Squeezebox Transporter
------------------------------------------------------------
10/17 17:49:47 Trace: [analysis] analysis completed in 2471ms for 203s of FLAC 44.1kHz 16bit audio. loudness=-17,6729033223848LUFS dbTP=0,0844013881079958 noisestartms=182 noiseendms=197184 isdts=False mqa=0 for track 20730162 url=\\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\03 The Man Who Sold Himself.flac
10/17 17:49:47 Trace: [library] finished with 1 dirty tracks 1 dirty albums 4 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 8 changed objects
10/17 17:49:47 Debug: [library/index] updating search indices: 2 ops 0 adds, 0 removes
10/17 17:49:47 Trace: [dbperf] flush 5014 bytes, 2 ops in 3 ms (cumulative 9928 bytes, 4 ops in 17164 ms)
10/17 17:49:47 Info: [audiodevice] updating analysis info for next track because analysis finished
10/17 17:49:47 Info: [zoneplayer/signal] update playparams to gain=0dB peak=dB basems=0 noisestartms=156 noiseendms=301470
10/17 17:49:47 Info: [zoneplayer/signal] update playparams to gain=0dB peak=dB basems=0 noisestartms=156 noiseendms=301470
10/17 17:49:47 Info: [zoneplayer/signal] update playparams to gain=0dB peak=dB basems=0 noisestartms=182 noiseendms=197184
10/17 17:49:49 Trace: [zone TR2] Next
10/17 17:49:49 Info: [zone TR2] OnPlayFeedback Stopped
10/17 17:49:49 Debug: [zone TR2] _Advance
10/17 17:49:49 Trace: [zone TR2] Selecting Source state=Stopped
10/17 17:49:49 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:49 Info: [audio/env] [zoneplayer] All streams were disposed
10/17 17:49:49 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [LOADING @ 0:00] The Man Who Sold Himself - Gavin Harrison / Osric
10/17 17:49:49 Trace: [analysis] prioritizing next track LibraryTrack[20731186, Gavin Harrison, Osric, 05ric - The Man Who Sold Himself - Own IsAvailable=True IsDeleted=False ] for zone 22:1:b5c97230-9c8a-8806-ceda-428deec6b131
10/17 17:49:49 Trace: [analysis] analyzing (high priority) trackid=20731186 url=\\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\04 Own.flac
10/17 17:49:49 Info: [TR2] [zoneplayer] Playing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\03 The Man Who Sold Himself.flac
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:49 Info: [TR2] [zoneplayer] Queueing: \\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\04 Own.flac
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=3144436 bytes_received=0 wireless_signal=65535 jiffies=2914214586 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214587 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Info: [TR2] [zoneplayer]     Open Result (Playing):Result[Status=Success]
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:49:49 Info: [TR2] [zoneplayer] Starting playback
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=s autostart=1 formatbyte=f pcmsamplesize=? pcmsamplerate=? pcmchannels=? pcmendian=? threshold=255 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=GET /82b48e2456f9479082ca0c2eb492d03e HTTP/1.0


10/17 17:49:49 Info: [zone TR2] OnPlayFeedback Playing
10/17 17:49:49 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 0:00] The Man Who Sold Himself - Gavin Harrison / Osric
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214591 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/203 sec
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214594 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214595 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMc crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214596 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMe crlf_count=0 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214617 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMh crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914214618 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:49:49 Info: [TR2] [zoneplayer] Open result (Queueing): Result[Status=Success]
10/17 17:49:49 Trace: [prebuffer] ready 149940/441000 (34%) @ 0/169 sec
10/17 17:49:49 Info: 
--[ SignalPath ]---------------------------------------------
SignalPath Quality = Lossless
Elements:
    Source Format=Flac 44100/16/2 BitRate=771 Quality=Lossless
    Output OutputType=Squeezebox Quality=Lossless SubType= Model=Squeezebox Transporter
------------------------------------------------------------
10/17 17:49:50 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 17:49:50 Trace: [push] retrying connection in 39136ms
10/17 17:49:50 Info: [stats] 8045mb Virtual, 2576mb Physical, 2068mb Managed, 1908 Handles, 101 Threads
10/17 17:49:51 Trace: [analysis] analysis completed in 2113ms for 169s of FLAC 44.1kHz 16bit audio. loudness=-15,5113533624309LUFS dbTP=-0,0240840120939882 noisestartms=156 noiseendms=163436 isdts=False mqa=0 for track 20731186 url=\\musicserver\1M\@G\G[A-E]\Gavin Harrison & 05Ric\[2012] The Man Who Sold Himself\04 Own.flac
10/17 17:49:51 Trace: [library] finished with 1 dirty tracks 1 dirty albums 4 dirty performers 1 dirty works 1 dirty performances 0 clumping tracks, 0 clumping auxfiles 0 compute tracks, 0 deleted tracks, 1 tracks to (re)load, 0 tracks to retain, 0 auxfiles to (re)load, 0 auxfiles to retain, and 8 changed objects
10/17 17:49:51 Debug: [library/index] updating search indices: 2 ops 0 adds, 0 removes
10/17 17:49:51 Trace: [dbperf] flush 4845 bytes, 2 ops in 3 ms (cumulative 14773 bytes, 6 ops in 17167 ms)
10/17 17:49:51 Info: [audiodevice] updating analysis info for next track because analysis finished
10/17 17:49:51 Info: [zoneplayer/signal] update playparams to gain=0dB peak=dB basems=0 noisestartms=182 noiseendms=197184
10/17 17:49:51 Info: [zoneplayer/signal] update playparams to gain=0dB peak=dB basems=0 noisestartms=182 noiseendms=197184
10/17 17:49:51 Info: [zoneplayer/signal] update playparams to gain=0dB peak=dB basems=0 noisestartms=156 noiseendms=163436
10/17 17:50:00 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 17:50:00 Trace: [push] connecting to 104.248.55.243:9200
10/17 17:50:00 Trace: [push] connected
10/17 17:50:05 Info: [stats] 8015mb Virtual, 2567mb Physical, 2070mb Managed, 1904 Handles, 96 Threads
10/17 17:50:10 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 17:50:10 Trace: [push] retrying connection in 52723ms
10/17 17:50:20 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 17:50:20 Trace: [push] connecting to 104.248.55.243:9200
10/17 17:50:20 Trace: [push] connected
10/17 17:50:20 Info: [stats] 8019mb Virtual, 2568mb Physical, 2069mb Managed, 1904 Handles, 97 Threads
10/17 17:50:30 Trace: [push] restarting connection (Unable to read data from the transport connection: A blocking operation was interrupted by a call to WSACancelBlockingCall.)
10/17 17:50:30 Trace: [push] retrying connection in 86136ms
10/17 17:50:35 Debug: UI-NAV: queue
10/17 17:50:35 Debug: GMS: saving nav stack
10/17 17:50:35 Debug: UI-NAV: queue
10/17 17:50:35 Trace: [dbperf] flush 0 bytes, 0 ops in 1 ms (cumulative 14773 bytes, 6 ops in 17168 ms)
10/17 17:50:35 Debug: GMS: done saving nav stack
10/17 17:50:35 Info: [stats] 8008mb Virtual, 2575mb Physical, 2074mb Managed, 1897 Handles, 94 Threads
10/17 17:50:40 Trace: Successful POST response from https://push.roonlabs.com/push/1/connect
10/17 17:50:40 Trace: [push] connecting to 104.248.55.243:9200
10/17 17:50:41 Trace: [push] connected
10/17 17:50:43 Trace: [zone System Output] Suspend
10/17 17:50:43 Trace: [zone System Output] Stop
10/17 17:50:43 Trace: [zone TR2] Suspend
10/17 17:50:43 Trace: [zone TR2] Stop
10/17 17:50:43 Info: [zone TR2] OnPlayFeedback Stopped
10/17 17:50:43 Trace: [TR2] [Lossless, 16/44 FLAC => 16/44] [100% buf] [PLAYING @ 0:00] The Man Who Sold Himself - Gavin Harrison / Osric
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:50:43 Trace: [transport] disabling transport
10/17 17:50:43 Trace: [zone System Output] Suspend
10/17 17:50:43 Info: [audio/env] [zoneplayer -> stream] All streams were disposed
10/17 17:50:43 Info: [audio/env] [zoneplayer] All streams were disposed
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:50:43 Trace: [radio] [1] dispose session
10/17 17:50:43 Trace: [zone TR2] Suspend
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] SENT strm command=q autostart=0 formatbyte=p pcmsamplesize=1 pcmsamplerate=3 pcmchannels=2 pcmendian=1 threshold=0 spdif_enable=0 trans_period=0 trans_type=0, flags=0, output_threshold=0, replay_gain=0, http_header=
10/17 17:50:43 Trace: [raat] disposing
10/17 17:50:43 Trace: [airplay] disposing
10/17 17:50:43 Trace: [devialet] disposing
10/17 17:50:43 Trace: [devicemanager/sonos] disposing
10/17 17:50:43 Trace: [devicemanager/kef] disposing
10/17 17:50:43 Debug: [upnp/discovery] disposing tracker
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] State Change Connected => Disconnected
10/17 17:50:43 Info: [squeezebox] device TR-12 (Squeezebox Transporter# 00:04:20:10:05:5b @ 192.168.1.39:62804) removed
10/17 17:50:43 Trace: [hqplayer] disposing
10/17 17:50:43 Trace: [meridian] disposing
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=3145727 bytes_received=0 wireless_signal=65535 jiffies=2914268520 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914268527 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914268534 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0
10/17 17:50:43 Trace: [squeezebox/client] [192.168.1.39:62804] GOT STAT event_code=STMf crlf_count=4 mas_initialized=  mas_mode=0 buffer_size=3145728 fullness=0 bytes_received=0 wireless_signal=65535 jiffies=2914268535 output_buffer_size=3528000 output_buffer_fullness=3506176 elapsed_seconds=0 voltage=0 elapsed_milliseconds=0 server_timestamp=0 error_code=0

noris · October 17, 2018, 5:39pm

Hello @Adrian_Matala,

Thanks for contacting support, I’d be happy to assist here. I have a few questions as to begin troubleshooting here:

Can you please provide more information regarding you network setup here? Please list the model/manufacturer of your Router, any Switches you have and how your Core and Logitech devices are connected (WiFi from Access Point/WiFi from Router/Ethernet from Router/Switch, ect).
Are the Transporters connected via WiFi or Ethernet? If they are connected via WiFi, can you try connecting them via Ethernet to your Router or an Unmanaged switch to verify if the same behavior occurs?
Are you using multiple subnets in your setup?
Have you restarted your Core and the Transporters after the other LMS instance has been stopped?
Are the Transporters using the most recent firmware from Logitech?
Do you by any chance have a firewall or Antivirus active on your Core/Router that could be blocking the connection to the Transporter? Can you please try temporarily disabling it if so?
Are your other Endpoints playing content ok? If you do not have other endpoints, does “System Output” play properly on the computer’s speakers?
I have gone ahead and enabled diagnostics mode on your account and what this action will do is next time your Core is active, a set of logs will automatically be generated and uploaded to our servers for analysis. I will be sure to let you know once those have reached our servers and will get a case started for you with our QA team.

Please let me know your reply to the above questions when possible and I will create a case for you regarding this issue.

Thanks,
Noris

Adrian_Matala · October 17, 2018, 6:36pm

Hi, here are the answers to your questions:

Can you please provide more information regarding you network setup here? Please list the model/manufacturer of your Router, any Switches you have and how your Core and Logitech devices are connected (WiFi from Access Point/WiFi from Router/Ethernet from Router/Switch, ect).

My DSL modem is a Proximus b-box3, I have 3 gigabit switches on my network: TRENDnet TEG-S16D, TP-LINK TL-SG1016D, Level One GEU-1628. All devices are cabled to the various switches in the different rooms: roon core and one Transporter to Level One GEU-1628, other Transporter to TRENDnet TEG-S16D, the PC which holds my music shared folder is connected to the TP-LINK TL-SG1016D. No Wifi access points in the path.

Are the Transporters connected via WiFi or Ethernet? If they are connected via WiFi, can you try connecting them via Ethernet to your Router or an Unmanaged switch to verify if the same behavior occurs?
Everything is connected to Ethernet via unmanaged switches.
Are you using multiple subnets in your setup?
No
Have you restarted your Core and the Transporters after the other LMS instance has been stopped?
Yes
Are the Transporters using the most recent firmware from Logitech?
Yes
Do you by any chance have a firewall or Antivirus active on your Core/Router that could be blocking the connection to the Transporter? Can you please try temporarily disabling it if so?
I have Symantec Endpoint Protection running on the PC where the core is running. I have stopped it and then it started working fine, but after restarting roon it stopped working again… I have tried starting and stopping roon several times while the SEP is still disabled, but can’t have it working again… Is it related or was it just a coincidence?
Are your other Endpoints playing content ok? If you do not have other endpoints, does “System Output” play properly on the computer’s speakers?
I don’t have any other endpoints, but System Output is playing fine on the speakers.
I have gone ahead and enabled diagnostics mode on your account and what this action will do is next time your Core is active, a set of logs will automatically be generated and uploaded to our servers for analysis. I will be sure to let you know once those have reached our servers and will get a case started for you with our QA team.
I have done quite a few tests now, so there should be enough info in the logs, if more is needed, please let me know!

Thank you for your time!

Adrian_Matala · October 17, 2018, 6:41pm

The only blocked packets I am seeing in my firewall logs are these below, coming from the rule that block UPnP discovery requests from outside networks, in the local network all TCP and UDP traffic is allowed:

17/10/2018 20:39:52 Blocked 3 Outgoing UDP 239.255.255.250 01-00-5E-7F-FF-FA 1900 192.168.1.56 60-45-CB-A9-1F-26 1900 C:\Users\amata\AppData\Local\Roon\Application\Roon.exe sas HOMEPCNEW Default 10 17/10/2018 20:39:38 17/10/2018 20:39:43 Block UPnP Discovery

But now I can’t make it work again, even with the firewall stopped…

noris · October 17, 2018, 10:37pm

Hello @Adrian_Matala,

Thank you for your responses, I can confirm that the diagnostics from your machine have successfully reached our servers and I have started a case for you with QA, I will be sure to update you once they have completed their report and have passed it back to me.

While this analysis occurs on our end, I would double check any firewall setting you have active and see if you can temporarily disable it and verify your experience afterwards. If you can retrace the steps you used to make the Transporters work after disabling Symantec then this will give us a great data point. At the very least, I would try disabling Symantec, and then reboot the Core, Transporters and Networking Gear you have as to see if that changes anything.

Our Networking Best Practices Guide may provide some additional clues or recommendations here. Ensuring that RAATServer is added as an exception to all of your firewalls and allowing access to all ports will further eliminate some firewall possibilities.

I will be sure to let you know once I have more information to share, but please do keep me posted if you find any other causes that can contribute to this behavior in the meantime.

Thanks,
Noris

Adrian_Matala · October 18, 2018, 5:29am

Hi Noris,

I have tried to retrace my exact steps from yesterday when I managed to make it work, but I couldn’t succeed again…:

stopped LMS on the remote server. At this time the Transporter was still connected to that server, so it shut down.
completely stopped Symantec Endpoint Protection on the roon core computer (all components were down, antivirus and firewall)
started core
started the Transporter and connected it to core via the IR remote
once Transporter was visible in roon, started playback, but it hang again…

So basically my only successful test so far was the first one from yesterday when I first stopped SEP (I don’t know if you get separate logs uploaded to your system every time I restart roon, but that successful test should be in the first log from yesterday evening, after that all tests have failed)…

Also, yesterday during that single successful test when the Transporter was playing, I started and stopped SEP on the core computer several times, but playback didn’t stop, I could still play another tracks without problem, until I restarted the core and after that I couldn’t make it run again with SEP on or off… So I really can’t figure out what was different for that one time when it worked.

If I can find out anything more about why it worked that one time I’ll let you know, but that requirement to stop LMS on the remote server is really limiting my possibilities to run too many tests during the day because it means I have to stop playing music, which is a big show stopper for me…

Thanks,
Adrian

Adrian_Matala · October 18, 2018, 6:53pm

Hi @noris,

As an update, I have been running a few more tests this evening. I also have 3 Squeezebox3 players in my setup and they all seem to be playing fine, no issues even when SEP is fully enabled. (My latest log contains info from my SB3 tests).

However I couldn’t manage to make any of my 3 Transporters work again, so the problem seems to be really related to Transporters… I have a one SB3 and one Transporter placed in each different room. SB1 and TR1 connected to TRENDnet TEG-S16D, SB2 and TR2 connected to Level One GEU-1628 and SB3 and TR3 connected to TP-LINK TL-SG1016D, so each of the pairs is sharing the same network path and devices… and yet only the SB3’s are working, not the Transporters…

Hope this can help a bit…

Adrian