-- Logs begin at Thu 2025-07-17 14:12:37 EDT, end at Fri 2025-07-18 13:04:34 EDT. --
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Received SetState message:
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playing state: Playing
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playback position: 0
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Queue version: 911.4
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Current track: TID: 52211414, QID: 16, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Next track: TID: 52211436, QID: 38, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO MediaEngine: [0x22d0788]: Stopping playback, clearing tracks
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO MediaEngine: [0x22d0788]: Initiating playback
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Stopping audio renderer
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.621 [2042.2042] INFO SampleApp: Stopping playback
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.622 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.622 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 251]: Disposing of audio stream
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.622 [2042.2042] INFO ContentFetcher: [0x243f958]: Canceling download
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.629 [2042.2042] INFO SampleApp: Playback state changed: Stopped
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.629 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming ended event
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:01 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO SampleApp: [Stream 251]: Audio stream has been disposed of
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting current track: 52211414, initial offset: 0ms
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.630 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 253
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.631 [2042.2042] INFO HttpDownloader: [0x28b4850]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=e10adb0cb434d12f017a86ebf6e0e8bd&request_ts=1752858181&track_id=52211414
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.631 [2042.2042] INFO HttpDownloader: [0x28c0e88]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211414
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.631 [2042.2042] INFO HttpDownloader: [0x2ab38b0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=79e65775432cfa334fc9ac690754e114&request_ts=1752858181&track_id=52211414
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.631 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 253]: Running audio stream
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.631 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.634 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting next track: 52211436
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.634 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 254
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.634 [2042.2042] INFO HttpDownloader: [0x2592388]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=f338e3bdda39f918e90e39b2dc2c761f&request_ts=1752858181&track_id=52211436
Jul 18 13:03:01 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.634 [2042.2042] INFO HttpDownloader: [0x29ab798]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211436
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.634 [2042.2042] INFO HttpDownloader: [0x2ced380]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=7888c05d35fd3a519401ae27fd78c8a7&request_ts=1752858181&track_id=52211436
Jul 18 13:03:01 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.636 [2042.2042] INFO MediaEngine: [0x22d0788]: Waiting for current stream to start before starting audio renderer
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:01 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:01 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:01 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:01 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:01 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:01 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPause
Jul 18 13:03:01 volumio volumio[879]: info: [GPIO_Control] *** musicPause ***
Jul 18 13:03:01 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:01 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:01 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:01 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:01 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:01 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause)
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.783 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 254]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211436&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861781&hmac=AgNtPmP9v8Q32OmPhuZq-8yGeDA
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.784 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 253]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211414&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861781&hmac=QZqsX2Fx-lomCZ_z_1tl-EczDFI
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.827 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 254]: stream information have been fetched
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.889 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 253]: Metadata became available:
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.889 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: Solitaire (Remastered)
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.889 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.889 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold (Remastered)
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.889 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.997 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 254]: Metadata became available:
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.997 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: A Song For You (1987 Remix)
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.997 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.997 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold (1987 Remix)
Jul 18 13:03:01 volumio qobuz-connect[2042]: 20250718 13:03:01.997 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.173 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 253]: stream information have been fetched
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.173 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211414&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861781&hmac=QZqsX2Fx-lomCZ_z_1tl-EczDFI
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.173 [2042.2042] INFO ContentFetcher: [0x243f958]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211414&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861781&hmac=QZqsX2Fx-lomCZ_z_1tl-EczDFI, offset: 0
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Starting audio renderer, initial playback state: Playing
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO SampleApp: [Stream 253]: New audio stream (starting from 0ms)
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO SampleApp: [Stream 253]: Stream metadata became available:
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO SampleApp: Title: Solitaire (Remastered)
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO SampleApp: Artist: The Carpenters
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO SampleApp: Album: Carpenters Gold (Remastered)
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.174 [2042.2042] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: QobuzConnect: alread currrent service, send playback confirmation
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.176 [2042.2042] INFO SampleApp: Initiating playback, initial state: Playing
Jul 18 13:03:02 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:02 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.180 [2042.2042] INFO SampleApp: Playback state changed: Playing
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.180 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming started event
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.180 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.180 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.180 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.180 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.181 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending FileAudioQualityChanged message
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.182 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:02 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:02 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPlay
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] *** musicPlay ***
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:02 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:02 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:02 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:02 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:02 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:02 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 On (musicPlay)
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.851 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Content info extracted
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.851 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Size: 30216691
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.854 [2042.11875] INFO AudioDecoder: [0x26fdf80]: Stream info:
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.855 [2042.11875] INFO AudioDecoder: [0x26fdf80]: Total samples: 12402096
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.855 [2042.11875] INFO AudioDecoder: [0x26fdf80]: Sample rate: 44100
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.855 [2042.11875] INFO AudioDecoder: [0x26fdf80]: Channel count: 2
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.855 [2042.11875] INFO AudioDecoder: [0x26fdf80]: Bits per sample: 16
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.855 [2042.11875] INFO AudioDecoder: [0x26fdf80]: Duration: 281226
Jul 18 13:03:02 volumio qobuz-connect[2042]: 20250718 13:03:02.855 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Audio properties have changed
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Received SetState message:
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playing state: Playing
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playback position: 0
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Queue version: 911.4
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Current track: TID: 52211436, QID: 38, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Next track: TID: 52211426, QID: 28, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO MediaEngine: [0x22d0788]: Stopping playback, clearing tracks
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.136 [2042.2042] INFO MediaEngine: [0x22d0788]: Initiating playback
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.137 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Stopping audio renderer
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.137 [2042.2042] INFO SampleApp: Stopping playback
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.137 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.138 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 253]: Disposing of audio stream
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.138 [2042.2042] INFO ContentFetcher: [0x243f958]: Canceling download
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.145 [2042.2042] INFO SampleApp: Playback state changed: Stopped
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.145 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming ended event
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.145 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.145 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.145 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO SampleApp: [Stream 253]: Audio stream has been disposed of
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting current track: 52211436, initial offset: 0ms
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 255
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO HttpDownloader: [0x2926210]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=c8564056794c4e2a6f159b307460e66b&request_ts=1752858185&track_id=52211436
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO HttpDownloader: [0x2a65b40]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211436
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO HttpDownloader: [0x2a6eb78]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=d7cf872736b1cadd5a60adf8e9f9c64a&request_ts=1752858185&track_id=52211436
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 255]: Running audio stream
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.146 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.149 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting next track: 52211426
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.149 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 256
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.149 [2042.2042] INFO HttpDownloader: [0x23e1910]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d7ae9bd43ceffa342a67151555725397&request_ts=1752858185&track_id=52211426
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.149 [2042.2042] INFO HttpDownloader: [0x230c408]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211426
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.149 [2042.2042] INFO HttpDownloader: [0x27695c0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=18ff63a192a589c15ed769abd33bec3f&request_ts=1752858185&track_id=52211426
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.151 [2042.2042] INFO MediaEngine: [0x22d0788]: Waiting for current stream to start before starting audio renderer
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPause
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] *** musicPause ***
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause)
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.268 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 255]: Metadata became available:
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.268 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: A Song For You (1987 Remix)
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.268 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.268 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold (1987 Remix)
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.268 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.297 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 256]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211426&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861785&hmac=4Dr9IsT41I4ndQ5Y-zUbJ-tui2I
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.300 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 255]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211436&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861785&hmac=YdzPguSKO-6aBpHahli4VMqQr44
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.369 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 256]: Metadata became available:
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.369 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: Make Believe It's Your First Time
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.369 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.370 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.370 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.387 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 256]: stream information have been fetched
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.390 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 255]: stream information have been fetched
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.391 [2042.2042] INFO UrlAudioSource: [0x22c5978]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211436&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861785&hmac=YdzPguSKO-6aBpHahli4VMqQr44
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.391 [2042.2042] INFO ContentFetcher: [0x26c3f38]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211436&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861785&hmac=YdzPguSKO-6aBpHahli4VMqQr44, offset: 0
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.391 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Starting audio renderer, initial playback state: Playing
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.391 [2042.2042] INFO SampleApp: [Stream 255]: New audio stream (starting from 0ms)
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.391 [2042.2042] INFO SampleApp: [Stream 255]: Stream metadata became available:
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.392 [2042.2042] INFO SampleApp: Title: A Song For You (1987 Remix)
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.392 [2042.2042] INFO SampleApp: Artist: The Carpenters
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.392 [2042.2042] INFO SampleApp: Album: Carpenters Gold (1987 Remix)
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.392 [2042.2042] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: QobuzConnect: alread currrent service, send playback confirmation
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.393 [2042.2042] INFO SampleApp: Initiating playback, initial state: Playing
Jul 18 13:03:05 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:05 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.397 [2042.2042] INFO SampleApp: Playback state changed: Playing
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.397 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming started event
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.397 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.398 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.398 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.398 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.398 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending FileAudioQualityChanged message
Jul 18 13:03:05 volumio qobuz-connect[2042]: 20250718 13:03:05.399 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:05 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:05 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPlay
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] *** musicPlay ***
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:05 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:05 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 On (musicPlay)
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.2042] INFO UrlAudioSource: [0x22c5978]: Content info extracted
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.2042] INFO UrlAudioSource: [0x22c5978]: Size: 27745334
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.11879] INFO AudioDecoder: [0x2660c40]: Stream info:
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.11879] INFO AudioDecoder: [0x2660c40]: Total samples: 12235104
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.11879] INFO AudioDecoder: [0x2660c40]: Sample rate: 44100
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.11879] INFO AudioDecoder: [0x2660c40]: Channel count: 2
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.11879] INFO AudioDecoder: [0x2660c40]: Bits per sample: 16
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.067 [2042.11879] INFO AudioDecoder: [0x2660c40]: Duration: 277440
Jul 18 13:03:06 volumio qobuz-connect[2042]: 20250718 13:03:06.068 [2042.2042] INFO UrlAudioSource: [0x22c5978]: Audio properties have changed
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.214 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Received SetState message:
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playing state: Playing
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playback position: 0
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Queue version: 911.4
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Current track: TID: 52211426, QID: 28, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Next track: TID: 52211421, QID: 23, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO MediaEngine: [0x22d0788]: Stopping playback, clearing tracks
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO MediaEngine: [0x22d0788]: Initiating playback
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Stopping audio renderer
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.215 [2042.2042] INFO SampleApp: Stopping playback
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.216 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.216 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 255]: Disposing of audio stream
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.216 [2042.2042] INFO ContentFetcher: [0x26c3f38]: Canceling download
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.223 [2042.2042] INFO SampleApp: Playback state changed: Stopped
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.223 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming ended event
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.223 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO SampleApp: [Stream 255]: Audio stream has been disposed of
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting current track: 52211426, initial offset: 0ms
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 257
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO HttpDownloader: [0x289d9a0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=89f4d82fafa72b11ccb8ef57d9469c96&request_ts=1752858190&track_id=52211426
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO HttpDownloader: [0x2ab33b8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211426
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.224 [2042.2042] INFO HttpDownloader: [0x2a65b40]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=73fee5c1074978b95d5bbc1bac304c49&request_ts=1752858190&track_id=52211426
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.225 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 257]: Running audio stream
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.225 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.227 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting next track: 52211421
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.227 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 258
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.227 [2042.2042] INFO HttpDownloader: [0x25033f8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=c875d36ff94a692c5af7a839d2d63367&request_ts=1752858190&track_id=52211421
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.227 [2042.2042] INFO HttpDownloader: [0x26ea120]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211421
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.227 [2042.2042] INFO HttpDownloader: [0x22e5e30]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=d4cb9023440a3b9728a26abdbf806089&request_ts=1752858190&track_id=52211421
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.229 [2042.2042] INFO MediaEngine: [0x22d0788]: Waiting for current stream to start before starting audio renderer
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPause
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] *** musicPause ***
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause)
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.388 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 257]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211426&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861790&hmac=-Kli09dilCwaE8ls-0-ECTwWzXI
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.391 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 258]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211421&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861790&hmac=mQpYMyERkVomUxWMQkIq5xidxo4
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.412 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 257]: stream information have been fetched
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.412 [2042.2042] INFO UrlAudioSource: [0x2856f00]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211426&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861790&hmac=-Kli09dilCwaE8ls-0-ECTwWzXI
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.412 [2042.2042] INFO ContentFetcher: [0x26c3f38]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211426&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861790&hmac=-Kli09dilCwaE8ls-0-ECTwWzXI, offset: 0
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.412 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Starting audio renderer, initial playback state: Playing
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.412 [2042.2042] INFO SampleApp: [Stream 257]: New audio stream (starting from 0ms)
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: QobuzConnect: alread currrent service, send playback confirmation
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.414 [2042.2042] INFO SampleApp: Initiating playback, initial state: Playing
Jul 18 13:03:10 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:10 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.418 [2042.2042] INFO SampleApp: Playback state changed: Playing
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.418 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming started event
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.418 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.418 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.418 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.418 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending FileAudioQualityChanged message
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.419 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPlay
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] *** musicPlay ***
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:10 volumio volumio[879]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7tkdl03w1WPRMjAf5SkfxdQ59ml1.50dba51bf1713482ef050a5ac747a0bb.state.track'
Jul 18 13:03:10 volumio volumio[879]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7tkdl03w1WPRMjAf5SkfxdQ59ml1.50dba51bf1713482ef050a5ac747a0bb.state.track'
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 On (musicPlay)
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.527 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 258]: Metadata became available:
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: I Need To Be In Love (1990 Remix)
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold (1990 Remix)
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 258]: stream information have been fetched
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 257]: Metadata became available:
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: Make Believe It's Your First Time
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.528 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.529 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.529 [2042.2042] INFO SampleApp: [Stream 257]: Stream metadata became available:
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.529 [2042.2042] INFO SampleApp: Title: Make Believe It's Your First Time
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.529 [2042.2042] INFO SampleApp: Artist: The Carpenters
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.529 [2042.2042] INFO SampleApp: Album: Carpenters Gold
Jul 18 13:03:10 volumio qobuz-connect[2042]: 20250718 13:03:10.529 [2042.2042] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:10 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:10 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:10 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.449 [2042.2042] INFO UrlAudioSource: [0x2856f00]: Content info extracted
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.449 [2042.2042] INFO UrlAudioSource: [0x2856f00]: Size: 24416169
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.11880] INFO AudioDecoder: [0x23dace8]: Stream info:
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.11880] INFO AudioDecoder: [0x23dace8]: Total samples: 10965024
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.11880] INFO AudioDecoder: [0x23dace8]: Sample rate: 44100
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.11880] INFO AudioDecoder: [0x23dace8]: Channel count: 2
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.11880] INFO AudioDecoder: [0x23dace8]: Bits per sample: 16
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.11880] INFO AudioDecoder: [0x23dace8]: Duration: 248640
Jul 18 13:03:11 volumio qobuz-connect[2042]: 20250718 13:03:11.452 [2042.2042] INFO UrlAudioSource: [0x2856f00]: Audio properties have changed
Jul 18 13:03:12 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:03:12 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1211) (YouTube) Incoming message: 'noop'
Jul 18 13:03:12 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1211) (YouTube) Not handled: 'noop'
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Received SetState message:
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playing state: Playing
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playback position: 0
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Queue version: 911.4
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Current track: TID: 52211421, QID: 23, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Next track: TID: 52211402, QID: 4, Context UUID: ef2f1b59-2533-4a91-9041-48f73ad39082
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO MediaEngine: [0x22d0788]: Stopping playback, clearing tracks
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO MediaEngine: [0x22d0788]: Initiating playback
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Stopping audio renderer
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.933 [2042.2042] INFO SampleApp: Stopping playback
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.934 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.934 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 257]: Disposing of audio stream
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.934 [2042.2042] INFO ContentFetcher: [0x26c3f38]: Canceling download
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.942 [2042.2042] INFO SampleApp: Playback state changed: Stopped
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.942 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming ended event
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.942 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:19 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO SampleApp: [Stream 257]: Audio stream has been disposed of
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting current track: 52211421, initial offset: 0ms
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 259
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO HttpDownloader: [0x2810bb0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=68301211d06ac6c2c3323fb23416230a&request_ts=1752858199&track_id=52211421
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO HttpDownloader: [0x2ab33b8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211421
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO HttpDownloader: [0x2a65b40]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=7d1f065d40d2060af662944ec880ec62&request_ts=1752858199&track_id=52211421
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 259]: Running audio stream
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.943 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.946 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting next track: 52211402
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.946 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 260
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.946 [2042.2042] INFO HttpDownloader: [0x2538918]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=22c678058f0dba7cbb85429477125c5d&request_ts=1752858199&track_id=52211402
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.946 [2042.2042] INFO HttpDownloader: [0x23abf98]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=52211402
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.946 [2042.2042] INFO HttpDownloader: [0x23f55e8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=821529a9293bdf0c617d00f51498132f&request_ts=1752858199&track_id=52211402
Jul 18 13:03:19 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:19 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:19 volumio qobuz-connect[2042]: 20250718 13:03:19.948 [2042.2042] INFO MediaEngine: [0x22d0788]: Waiting for current stream to start before starting audio renderer
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:19 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:19 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:19 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:19 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:19 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:19 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPause
Jul 18 13:03:19 volumio volumio[879]: info: [GPIO_Control] *** musicPause ***
Jul 18 13:03:19 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:19 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:19 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:19 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:19 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:19 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause)
Jul 18 13:03:20 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:03:20 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 6385) (YouTube Music) Incoming message: 'noop'
Jul 18 13:03:20 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 6385) (YouTube Music) Not handled: 'noop'
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.097 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 260]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211402&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861800&hmac=8nc7ASHmiz0euhuiRRYBVwzQLzI
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.099 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 259]: Metadata became available:
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.099 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: I Need To Be In Love (1990 Remix)
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.099 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.099 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold (1990 Remix)
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.099 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.102 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 259]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211421&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861800&hmac=3NHK0vumMkTNscpai_mP-J5V5TE
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.143 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 260]: stream information have been fetched
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.187 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 260]: Metadata became available:
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.187 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: Let Me Be The One
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.187 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: The Carpenters
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.188 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Carpenters Gold
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.188 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.301 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 259]: stream information have been fetched
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.301 [2042.2042] INFO UrlAudioSource: [0x2384388]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211421&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861800&hmac=3NHK0vumMkTNscpai_mP-J5V5TE
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO ContentFetcher: [0x243f958]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=52211421&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861800&hmac=3NHK0vumMkTNscpai_mP-J5V5TE, offset: 0
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Starting audio renderer, initial playback state: Playing
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO SampleApp: [Stream 259]: New audio stream (starting from 0ms)
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO SampleApp: [Stream 259]: Stream metadata became available:
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO SampleApp: Title: I Need To Be In Love (1990 Remix)
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO SampleApp: Artist: The Carpenters
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.302 [2042.2042] INFO SampleApp: Album: Carpenters Gold (1990 Remix)
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.303 [2042.2042] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/3a/g1/j6h6fccu6g13a_600.jpg
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: QobuzConnect: alread currrent service, send playback confirmation
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.304 [2042.2042] INFO SampleApp: Initiating playback, initial state: Playing
Jul 18 13:03:20 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:20 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.308 [2042.2042] INFO SampleApp: Playback state changed: Playing
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.308 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming started event
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.308 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.308 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.309 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.309 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending FileAudioQualityChanged message
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.309 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.320 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:20 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPlay
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] *** musicPlay ***
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:20 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:20 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:20 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:20 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:20 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:20 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 On (musicPlay)
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.950 [2042.2042] INFO UrlAudioSource: [0x2384388]: Content info extracted
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.950 [2042.2042] INFO UrlAudioSource: [0x2384388]: Size: 22628765
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.11934] INFO AudioDecoder: [0x2785360]: Stream info:
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.11934] INFO AudioDecoder: [0x2785360]: Total samples: 10134180
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.11934] INFO AudioDecoder: [0x2785360]: Sample rate: 44100
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.11934] INFO AudioDecoder: [0x2785360]: Channel count: 2
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.11934] INFO AudioDecoder: [0x2785360]: Bits per sample: 16
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.11934] INFO AudioDecoder: [0x2785360]: Duration: 229800
Jul 18 13:03:20 volumio qobuz-connect[2042]: 20250718 13:03:20.953 [2042.2042] INFO UrlAudioSource: [0x2384388]: Audio properties have changed
Jul 18 13:03:30 volumio qobuz-connect[2042]: 20250718 13:03:30.308 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:30 volumio qobuz-connect[2042]: 20250718 13:03:30.309 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:30 volumio qobuz-connect[2042]: 20250718 13:03:30.309 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:30 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:30 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:30 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:30 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:30 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:30 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:30 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:30 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:30 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:30 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:37 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:03:37 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1212) (YouTube) Incoming message: 'noop'
Jul 18 13:03:37 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1212) (YouTube) Not handled: 'noop'
Jul 18 13:03:40 volumio qobuz-connect[2042]: 20250718 13:03:40.308 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:40 volumio qobuz-connect[2042]: 20250718 13:03:40.308 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:40 volumio qobuz-connect[2042]: 20250718 13:03:40.308 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:40 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:40 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:40 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:40 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:40 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:40 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:40 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:40 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:40 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:40 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:46 volumio volumio[879]: verbose: [yt-cast-receiver] RPC connection disconnected. Reconnecting...
Jul 18 13:03:46 volumio volumio[879]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=6385&CI=0&RID=rpc&SID=F81C1D7EBBF7AD8C&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=mPtzc3DBnsXY0XIKGUnxTCmAL7KQeppg0WLE2j0WaKc&id=4da401c1-1537-4db6-9fdb-cabbca9b7461&loungeIdToken=AGdO5p9bk2fXmMoKIDppM2abvJ7XZIBH5BJ_KWXWRrFktAvZizMPxbscuosvkSZWn-RKib9Cl6Oyr3QgDYUY9B79dw06193cB3YSJuRFU9aysWvhrzoPDLI&mdxVersion=2&name=YouTube%20on%20Volumio&obfuscatedGaiaId=&t=1&theme=m&v=2&zx=dd0aae2d9785
Jul 18 13:03:46 volumio volumio[879]: verbose: [yt-cast-receiver] RPC connection established.
Jul 18 13:03:46 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:03:46 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 6387) (YouTube Music) Incoming message: 'noop'
Jul 18 13:03:46 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 6387) (YouTube Music) Not handled: 'noop'
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.537 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Received SetState message:
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.537 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playing state: Playing
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.537 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playback position: 0
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.537 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Queue version: 912.1
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.537 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Current track: TID: 641936, QID: 0, Context UUID: 0d12ffdc-75e2-439e-9453-f8e4be4b2738
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.538 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Next track: TID: 641941, QID: 5, Context UUID: 0d12ffdc-75e2-439e-9453-f8e4be4b2738
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.538 [2042.2042] INFO MediaEngine: [0x22d0788]: Stopping playback, clearing tracks
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.538 [2042.2042] INFO MediaEngine: [0x22d0788]: Initiating playback
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.538 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Stopping audio renderer
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.538 [2042.2042] INFO SampleApp: Stopping playback
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.539 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.539 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 259]: Disposing of audio stream
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.539 [2042.2042] INFO ContentFetcher: [0x243f958]: Canceling download
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.546 [2042.2042] INFO SampleApp: Playback state changed: Stopped
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.546 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming ended event
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.546 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO SampleApp: [Stream 259]: Audio stream has been disposed of
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting current track: 641936, initial offset: 0ms
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Clearing all streams
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 261
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO HttpDownloader: [0x253bda0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=453f7b7f1ad36da471b6efae8c20c562&request_ts=1752858227&track_id=641936
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO HttpDownloader: [0x2ab38b0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=641936
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.547 [2042.2042] INFO HttpDownloader: [0x2a0ad88]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=4bd46d5103e57405c34630a18f52ba3e&request_ts=1752858227&track_id=641936
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.548 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 261]: Running audio stream
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.548 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.550 [2042.2042] INFO MediaEngine: [0x22d0788]: Setting next track: 641941
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.550 [2042.2042] INFO AudioStreamManager: [0x22d0870]: New stream: 262
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.551 [2042.2042] INFO HttpDownloader: [0x239ff58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d8b50897d721466f8ed415609614eb4e&request_ts=1752858227&track_id=641941
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.551 [2042.2042] INFO HttpDownloader: [0x29fbb78]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=641941
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.551 [2042.2042] INFO HttpDownloader: [0x240ab18]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=080db41aa57c9a15ddab3904b5037440&request_ts=1752858227&track_id=641941
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.553 [2042.2042] INFO MediaEngine: [0x22d0788]: Waiting for current stream to start before starting audio renderer
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPause
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] *** musicPause ***
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:47 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:47 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:47 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:47 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.761 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 261]: Metadata became available:
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.762 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: I Love Being Here With You (Live)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.762 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: Diana Krall
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.762 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Live In Paris (Live)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.762 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/92/10/0004400651092_600.jpg
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.823 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 261]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=641936&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861827&hmac=HGXqB6vsGhf-WFMINEbLA5KZEpg
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.847 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 262]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=641941&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861827&hmac=gUIh4fz-Le1iAOaVEs9oExTYNa0
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.894 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 262]: Metadata became available:
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.894 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Title: I've Got You Under My Skin (Live)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.894 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Artist: Diana Krall
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.894 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album: Live In Paris (Live)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.894 [2042.2042] INFO AudioStreamManager: [0x22d0870]: Album art URL: https://static.qobuz.com/images/covers/92/10/0004400651092_600.jpg
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.915 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 262]: stream information have been fetched
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.959 [2042.2042] INFO AudioStreamManager: [0x22d0870]: [Stream 261]: stream information have been fetched
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.959 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=641936&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861827&hmac=HGXqB6vsGhf-WFMINEbLA5KZEpg
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.960 [2042.2042] INFO ContentFetcher: [0x243f958]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=641936&fmt=6&profile=raw&app_id=174516466&cid=1726506&etsp=1752861827&hmac=HGXqB6vsGhf-WFMINEbLA5KZEpg, offset: 0
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.960 [2042.2042] INFO AudioRenderer: [0x22d09a8]: Starting audio renderer, initial playback state: Playing
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.960 [2042.2042] INFO SampleApp: [Stream 261]: New audio stream (starting from 0ms)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.960 [2042.2042] INFO SampleApp: [Stream 261]: Stream metadata became available:
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.961 [2042.2042] INFO SampleApp: Title: I Love Being Here With You (Live)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.961 [2042.2042] INFO SampleApp: Artist: Diana Krall
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.961 [2042.2042] INFO SampleApp: Album: Live In Paris (Live)
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.961 [2042.2042] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/92/10/0004400651092_600.jpg
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: QobuzConnect: alread currrent service, send playback confirmation
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.962 [2042.2042] INFO SampleApp: Initiating playback, initial state: Playing
Jul 18 13:03:47 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:47 volumio qobuz-connect[2042]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 88200
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.966 [2042.2042] INFO SampleApp: Playback state changed: Playing
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.966 [2042.2042] INFO StreamingEventReporter: [0x22d12e0]: Reporting streaming started event
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.966 [2042.2042] INFO HttpDownloader: [0x22d1338]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.966 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.967 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.967 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.967 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending FileAudioQualityChanged message
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:47 volumio qobuz-connect[2042]: 20250718 13:03:47.968 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:47 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:47 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Status changed: pause
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] Handling event: musicPlay
Jul 18 13:03:47 volumio volumio[879]: info: [GPIO_Control] *** musicPlay ***
Jul 18 13:03:48 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:48 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:48 volumio volumio[879]: info: [ASDebug] CurState: pause PrevState: play
Jul 18 13:03:48 volumio volumio[879]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms
Jul 18 13:03:48 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:48 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:48 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:03:48 volumio volumio[879]: info: [GPIO_Control] Turning GPIO 6 On (musicPlay)
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.651 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Content info extracted
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.652 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Size: 37508012
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.654 [2042.11985] INFO AudioDecoder: [0x2454750]: Stream info:
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.654 [2042.11985] INFO AudioDecoder: [0x2454750]: Total samples: 13779780
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.654 [2042.11985] INFO AudioDecoder: [0x2454750]: Sample rate: 44100
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.654 [2042.11985] INFO AudioDecoder: [0x2454750]: Channel count: 2
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.654 [2042.11985] INFO AudioDecoder: [0x2454750]: Bits per sample: 16
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.654 [2042.11985] INFO AudioDecoder: [0x2454750]: Duration: 312466
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.655 [2042.2042] INFO UrlAudioSource: [0x28b58b8]: Audio properties have changed
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.895 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Received SetState message:
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.895 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playing state:
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.895 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Playback position:
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.895 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Queue version: 912.2
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.895 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Current track:
Jul 18 13:03:48 volumio qobuz-connect[2042]: 20250718 13:03:48.895 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Next track: TID: 641941, QID: 5, Context UUID: 0d12ffdc-75e2-439e-9453-f8e4be4b2738
Jul 18 13:03:57 volumio qobuz-connect[2042]: 20250718 13:03:57.966 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:03:57 volumio qobuz-connect[2042]: 20250718 13:03:57.966 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:03:57 volumio qobuz-connect[2042]: 20250718 13:03:57.966 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:03:57 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:57 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:03:57 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:03:57 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:03:57 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:03:57 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:03:57 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:03:57 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:03:57 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:03:57 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:04:03 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1213) (YouTube) Incoming message: 'noop'
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1213) (YouTube) Not handled: 'noop'
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] RPC connection disconnected. Reconnecting...
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=1213&CI=0&RID=rpc&SID=F16E93325185EB11&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=0p6PJ8kqjPQJoTjoN378AHEhkD6tqncndEqqVt2vPvY&id=2932825a-2eb3-497d-96cf-95bca36acd68&loungeIdToken=AGdO5p-BEZnDRGCnrQ3e1HhXrpN1jjmBEsXm2sbXooPQ3IKxaS0bb4x4ae4_z-dFZBseiPtytZ_EVPfifVVz1iZlcx18PFsSDUtw8Yp0ycrIIvIc0rQXSB4&mdxVersion=2&name=YouTube%20on%20Volumio&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=203785256ef0
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] RPC connection established.
Jul 18 13:04:03 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1214) (YouTube) Incoming message: 'noop'
Jul 18 13:04:03 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1214) (YouTube) Not handled: 'noop'
Jul 18 13:04:07 volumio qobuz-connect[2042]: 20250718 13:04:07.966 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:04:07 volumio qobuz-connect[2042]: 20250718 13:04:07.966 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:04:07 volumio qobuz-connect[2042]: 20250718 13:04:07.967 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:04:07 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:07 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:04:07 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:04:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:04:07 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:04:07 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:04:07 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:04:07 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:07 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:04:07 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:04:10 volumio kernel: hwmon hwmon1: Undervoltage detected!
Jul 18 13:04:10 volumio sudo[12021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jul 18 13:04:10 volumio sudo[12021]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 18 13:04:10 volumio sudo[12023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jul 18 13:04:10 volumio sudo[12023]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 18 13:04:10 volumio sudo[12021]: pam_unix(sudo:session): session closed for user root
Jul 18 13:04:10 volumio sudo[12023]: pam_unix(sudo:session): session closed for user root
Jul 18 13:04:10 volumio volumio[879]: verbose: New Socket.io Connection to 192.168.0.220 from 192.168.0.167 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 7
Jul 18 13:04:10 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 18 13:04:11 volumio volumio[879]: xcb_connection_has_error() returned true
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Jul 18 13:04:11 volumio volumio[879]: xcb_connection_has_error() returned true
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jul 18 13:04:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Jul 18 13:04:12 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Jul 18 13:04:12 volumio volumio[879]: info: Received Get System Info
Jul 18 13:04:12 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 18 13:04:12 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 18 13:04:12 volumio volumio[879]: info: Discovery: Getting this device information
Jul 18 13:04:12 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:12 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 18 13:04:12 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:04:12 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 6388) (YouTube Music) Incoming message: 'noop'
Jul 18 13:04:12 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 6388) (YouTube Music) Not handled: 'noop'
Jul 18 13:04:13 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Jul 18 13:04:13 volumio volumio[879]: info: Received Get System Info
Jul 18 13:04:13 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 18 13:04:13 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 18 13:04:13 volumio volumio[879]: info: Discovery: Getting this device information
Jul 18 13:04:13 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:13 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 18 13:04:14 volumio volumio[879]: info: CoreCommandRouter::volumioGetVisibleSources
Jul 18 13:04:14 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 18 13:04:14 volumio volumio[879]: info: CoreCommandRouter::volumioGetQueue
Jul 18 13:04:14 volumio volumio[879]: info: CoreStateMachine::getQueue
Jul 18 13:04:14 volumio volumio[879]: info: CorePlayQueue::getQueue
Jul 18 13:04:14 volumio volumio[879]: info: Listing playlists
Jul 18 13:04:16 volumio kernel: hwmon hwmon1: Voltage normalised
Jul 18 13:04:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:17 volumio volumio[879]: info: Preload queue cleared
Jul 18 13:04:17 volumio qobuz-connect[2042]: 20250718 13:04:17.966 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:04:17 volumio qobuz-connect[2042]: 20250718 13:04:17.966 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:04:17 volumio qobuz-connect[2042]: 20250718 13:04:17.966 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:04:17 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:17 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:04:17 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:04:17 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:04:17 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:04:17 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:04:17 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:04:17 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:17 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:04:17 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:04:18 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:19 volumio volumio[879]: info: Preload queue cleared
Jul 18 13:04:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:20 volumio volumio[879]: info: Preload queue cleared
Jul 18 13:04:21 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:21 volumio volumio[879]: info: Preload queue cleared
Jul 18 13:04:22 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:22 volumio volumio[879]: info: Preload queue cleared
Jul 18 13:04:24 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:24 volumio volumio[879]: info: Preload queue cleared
Jul 18 13:04:27 volumio qobuz-connect[2042]: 20250718 13:04:27.966 [2042.2042] INFO ProtocolHandler: [0x22d0ec8]: Need to send state update
Jul 18 13:04:27 volumio qobuz-connect[2042]: 20250718 13:04:27.967 [2042.2042] INFO QConnectMessageSender: [0x28b3668]: Sending StateUpdated message
Jul 18 13:04:27 volumio qobuz-connect[2042]: 20250718 13:04:27.967 [2042.2042] INFO QwspMessageSender: [0x23dcdd0]: Sending Payload message
Jul 18 13:04:27 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:27 volumio volumio[879]: info: CoreCommandRouter::servicePushState
Jul 18 13:04:27 volumio volumio[879]: info: CoreStateMachine::pushState
Jul 18 13:04:27 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 18 13:04:27 volumio volumio[879]: info: CoreCommandRouter::volumioPushState
Jul 18 13:04:27 volumio volumio[879]: info: MRS: Pushing multiroomSync output update for this device
Jul 18 13:04:27 volumio volumio[879]: info: MRS: Pushing multiroomSync output
Jul 18 13:04:27 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:27 volumio volumio[879]: info: [GPIO_Control] Status changed: play
Jul 18 13:04:27 volumio volumio[879]: info: [ASDebug] CurState: play PrevState: play
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Jul 18 13:04:29 volumio volumio[879]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Jul 18 13:04:29 volumio volumio[879]: info: Received Get System Version
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 18 13:04:29 volumio volumio[879]: info: Received Get System Info
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jul 18 13:04:29 volumio volumio[879]: info: Discovery: Getting this device information
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::volumioGetState
Jul 18 13:04:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jul 18 13:04:29 volumio volumio[879]: verbose: -----------------------------------
Jul 18 13:04:29 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1215) (YouTube) Incoming message: 'noop'
Jul 18 13:04:29 volumio volumio[879]: verbose: [yt-cast-receiver] (AID: 1215) (YouTube) Not handled: 'noop'
Jul 18 13:04:33 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Jul 18 13:04:33 volumio volumio[879]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 18 13:04:33 volumio volumio[879]: TypeError: Cannot read property 'length' of undefined
Jul 18 13:04:33 volumio volumio[879]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25
Jul 18 13:04:33 volumio volumio[879]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13
Jul 18 13:04:33 volumio volumio[879]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18)
Jul 18 13:04:33 volumio volumio[879]: at Parser.emit (events.js:315:20)
Jul 18 13:04:33 volumio volumio[879]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26)
Jul 18 13:04:33 volumio volumio[879]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35)
Jul 18 13:04:33 volumio volumio[879]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5)
Jul 18 13:04:33 volumio volumio[879]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7)
Jul 18 13:04:33 volumio volumio[879]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13)
Jul 18 13:04:33 volumio volumio[879]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31)
Jul 18 13:04:33 volumio volumio[879]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59)
Jul 18 13:04:33 volumio volumio[879]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19)
Jul 18 13:04:33 volumio volumio[879]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15)
Jul 18 13:04:33 volumio volumio[879]: at IncomingMessage.emit (events.js:327:22)
Jul 18 13:04:33 volumio volumio[879]: at endReadableNT (internal/streams/readable.js:1327:12)
Jul 18 13:04:33 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Jul 18 13:04:33 volumio volumio[879]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 18 13:04:34 volumio sudo[12126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 13:03
Jul 18 13:04:34 volumio sudo[12126]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST"
VOLUMIO_VERSION="3.816"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"