-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Fri 2026-04-03 19:17:54 EDT. -- Apr 03 19:16:05 volumio-salon qobuz-connect[2450]: 20260403 19:16:05.093 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:05 volumio-salon qobuz-connect[2450]: 20260403 19:16:05.094 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:05 volumio-salon qobuz-connect[2450]: 20260403 19:16:05.094 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:05 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:05 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:05 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:05 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:05 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:05 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:05 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:05.107-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=49936 volume=100 Apr 03 19:16:05 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:05.107-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title="Go Down Moses" Apr 03 19:16:05 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:05 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:09 volumio-salon kernel: hwmon hwmon1: Undervoltage detected! Apr 03 19:16:15 volumio-salon qobuz-connect[2450]: 20260403 19:16:15.094 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:15 volumio-salon qobuz-connect[2450]: 20260403 19:16:15.095 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:15 volumio-salon qobuz-connect[2450]: 20260403 19:16:15.095 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:15 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:15 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:15 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:15 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:15 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:15 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:15 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:15.109-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=59936 volume=100 Apr 03 19:16:15 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:15.110-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title="Go Down Moses" Apr 03 19:16:15 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:15 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:15 volumio-salon kernel: hwmon hwmon1: Voltage normalised Apr 03 19:16:25 volumio-salon qobuz-connect[2450]: 20260403 19:16:25.095 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:25 volumio-salon qobuz-connect[2450]: 20260403 19:16:25.095 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:25 volumio-salon qobuz-connect[2450]: 20260403 19:16:25.095 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:25 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:25 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:25 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:25 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:25 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:25 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:25 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:25.113-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=69936 volume=100 Apr 03 19:16:25 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:25.113-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title="Go Down Moses" Apr 03 19:16:25 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:25 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:29 volumio-salon kernel: hwmon hwmon1: Undervoltage detected! Apr 03 19:16:34 volumio-salon kernel: hwmon hwmon1: Voltage normalised Apr 03 19:16:35 volumio-salon qobuz-connect[2450]: 20260403 19:16:35.096 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:35 volumio-salon qobuz-connect[2450]: 20260403 19:16:35.096 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:35 volumio-salon qobuz-connect[2450]: 20260403 19:16:35.096 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:35 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:35 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:35 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:35 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:35 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:35 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:35 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:35.109-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=79938 volume=100 Apr 03 19:16:35 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:35.109-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title="Go Down Moses" Apr 03 19:16:35 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:35 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:37 volumio-salon volumiologrotate[582]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Apr 03 19:16:37 volumio-salon volumiologrotate[582]: ls: cannot access 'SALON': No such file or directory Apr 03 19:16:40 volumio-salon kernel: hwmon hwmon1: Undervoltage detected! Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Received SetState message: Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Playing state: Playing Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Playback position: 0 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Queue version: 3.1 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Current track: TID: 235889055, QID: 7, Context UUID: cf7281fe-b51d-4d31-b67b-ea4ea800060e Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Next track: TID: 392210562, QID: 8, Context UUID: cf7281fe-b51d-4d31-b67b-ea4ea800060e Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO MediaEngine: [0x1091548]: Stopping playback, clearing tracks Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO MediaEngine: [0x1091548]: Initiating playback Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO AudioRenderer: [0x10916b0]: Stopping audio renderer Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.295 [2450.2450] INFO SampleApp: Stopping playback Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.296 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Clearing all streams Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.296 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 3]: Disposing of audio stream Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.296 [2450.2450] INFO ContentFetcher: [0x127d8e0]: Canceling download Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.303 [2450.2450] INFO SampleApp: Playback state changed: Stopped Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.303 [2450.2450] INFO StreamingEventReporter: [0x1091ed0]: Reporting streaming ended event Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.305 [2450.2450] INFO HttpDownloader: [0x1091f28]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.305 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.306 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.306 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO SampleApp: [Stream 3]: Audio stream has been disposed of Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO MediaEngine: [0x1091548]: Setting current track: 235889055, initial offset: 0ms Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Clearing all streams Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO AudioStreamManager: [0x10915f8]: New stream: 5 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO HttpDownloader: [0x12ab4b0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=6234b9c026f401ff0d4f6551ee2350f5&request_ts=1775258202&track_id=235889055 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO HttpDownloader: [0x1243878]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=235889055 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO HttpDownloader: [0x12fd330]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=161957652968b3aee48a825320ee73ce&request_ts=1775258202&track_id=235889055 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 5]: Running audio stream Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO MediaEngine: [0x1091548]: Setting next track: 392210562 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO AudioStreamManager: [0x10915f8]: New stream: 6 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO HttpDownloader: [0x12fd118]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=aaa85856439109985f5e43f0995db795&request_ts=1775258202&track_id=392210562 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO HttpDownloader: [0x12a2838]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=392210562 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.307 [2450.2450] INFO HttpDownloader: [0x10d1518]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=2d5f8f1cc4611f70245787046d96e3cf&request_ts=1775258202&track_id=392210562 Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.310 [2450.2450] INFO MediaEngine: [0x1091548]: Waiting for current stream to start before starting audio renderer Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.317-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PAUSED positionMs=79938 volume=100 Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.317-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title="Go Down Moses" Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.330-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PAUSED positionMs=0 volume=100 Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.331-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title="Go Down Moses" Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] CurState: pause PrevState: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] CurState: pause PrevState: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: pause Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Handling event: musicPause Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] *** musicPause *** Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: pause Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause) Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.489 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 5]: Metadata became available: Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.489 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Title: Vrimmel Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.489 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Artist: Frida Ånnevik Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.489 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album: Møtested - en hyllest til Anne Grete Preus Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.489 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album art URL: https://static.qobuz.com/images/covers/na/8g/kp3d88jyb8gna_600.jpg Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.492 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 6]: Metadata became available: Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.492 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Title: Sarniezz Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.492 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Artist: Angine de Poitrine Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.492 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album: Vol.II Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.492 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album art URL: https://static.qobuz.com/images/covers/dv/hk/xetru34w7hkdv_600.jpg Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.492 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 5]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=235889055&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261802&hmac=aaPLqvL4xfB8VilKGYBkP71s7k0 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.507 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 6]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=392210562&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261802&hmac=mvur9mwHLPzUeQi_a88iYdJ0mkw Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.520 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 6]: stream information have been fetched Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.530 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 5]: stream information have been fetched Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.530 [2450.2450] INFO UrlAudioSource: [0x116cab8]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=235889055&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261802&hmac=aaPLqvL4xfB8VilKGYBkP71s7k0 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO ContentFetcher: [0x12a2be0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=235889055&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261802&hmac=aaPLqvL4xfB8VilKGYBkP71s7k0, offset: 0 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO AudioRenderer: [0x10916b0]: Starting audio renderer, initial playback state: Playing Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO SampleApp: [Stream 5]: New audio stream (starting from 0ms) Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO SampleApp: [Stream 5]: Stream metadata became available: Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO SampleApp: Title: Vrimmel Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO SampleApp: Artist: Frida Ånnevik Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO SampleApp: Album: Møtested - en hyllest til Anne Grete Preus Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.531 [2450.2450] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/na/8g/kp3d88jyb8gna_600.jpg Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: QobuzConnect: alread currrent service, send playback confirmation Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.535 [2450.2450] INFO SampleApp: Initiating playback, initial state: Playing Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.562 [2450.2450] INFO SampleApp: Playback state changed: Playing Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.562 [2450.2450] INFO StreamingEventReporter: [0x1091ed0]: Reporting streaming started event Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.562 [2450.2450] INFO HttpDownloader: [0x1091f28]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.562 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.562 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.562 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.563 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending FileAudioQualityChanged message Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.563 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.563 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending DeviceAudioQualityChanged message Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.564 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.581-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.581-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.582-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PAUSED positionMs=0 volume=100 Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.582-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:42 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.602-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.603-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:16:42 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:42.603-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] CurState: pause PrevState: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: pause Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Handling event: musicPlay Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] *** musicPlay *** Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:42 volumio-salon volumio[2022]: info: [LastFM] Current track has sufficient metadata: title (Vrimmel) and artist (Frida Ånnevik) passed on explicitly Apr 03 19:16:42 volumio-salon volumio[2022]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Apr 03 19:16:42 volumio-salon volumio[2022]: info: [GPIO_Control] Turning GPIO 6 On (musicPlay) Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2450] INFO UrlAudioSource: [0x116cab8]: Content info extracted Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2450] INFO UrlAudioSource: [0x116cab8]: Size: 40502770 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2780] INFO AudioDecoder: [0x127ca98]: Stream info: Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2780] INFO AudioDecoder: [0x127ca98]: Total samples: 9194240 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2780] INFO AudioDecoder: [0x127ca98]: Sample rate: 48000 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2780] INFO AudioDecoder: [0x127ca98]: Channel count: 2 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2780] INFO AudioDecoder: [0x127ca98]: Bits per sample: 24 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2780] INFO AudioDecoder: [0x127ca98]: Duration: 191546 Apr 03 19:16:42 volumio-salon qobuz-connect[2450]: 20260403 19:16:42.828 [2450.2450] INFO UrlAudioSource: [0x116cab8]: Audio properties have changed Apr 03 19:16:44 volumio-salon kernel: hwmon hwmon1: Voltage normalised Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Received SetState message: Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Playing state: Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Playback position: 39037 Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Queue version: Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Current track: Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Next track: Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO MediaEngine: [0x1091548]: Seeking to time offset: 39037ms Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO AudioRenderer: [0x10916b0]: Seek is in progress Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 5]: Seeking to time offset: 39037ms Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO UrlAudioSource: [0x116cab8]: Seeking URL audio source to time offset: 39037ms Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO SampleApp: Seek is in progress Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO UrlAudioSource: [0x116cab8]: Seeking input stream to byte offset: 7450108 Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.639 [2450.2450] INFO ContentFetcher: [0x12a2be0]: Adjusting download offset to: 7450108 Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.648 [2450.2450] INFO SampleApp: Playback state changed: Seeking Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.648 [2450.2450] INFO StreamingEventReporter: [0x1091ed0]: Reporting streaming ended event Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.648 [2450.2450] INFO HttpDownloader: [0x1091f28]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.648 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.648 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.648 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.658-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.659-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:45 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.821 [2450.2450] INFO MediaEngine: [0x1091548]: Current stream has been seeked Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.822 [2450.2450] INFO AudioRenderer: [0x10916b0]: Seek has finished Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.822 [2450.2450] INFO SampleApp: [Stream 5]: Audio stream seeked: 39037ms Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.823 [2450.2450] INFO SampleApp: Playback state changed: Playing Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.823 [2450.2450] INFO StreamingEventReporter: [0x1091ed0]: Reporting streaming started event Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.823 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.823 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.823 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.867-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=39037 volume=100 Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.868-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=39037 volume=100 Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.868-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.868-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.868-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=39037 volume=100 Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.869-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.869-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=39037 volume=100 Apr 03 19:16:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:45.870-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:45 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:45 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:16:45 volumio-salon qobuz-connect[2450]: 20260403 19:16:45.906 [2450.2450] INFO HttpDownloader: [0x1091f28]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Apr 03 19:16:46 volumio-salon kernel: hwmon hwmon1: Undervoltage detected! Apr 03 19:16:52 volumio-salon kernel: hwmon hwmon1: Voltage normalised Apr 03 19:16:55 volumio-salon qobuz-connect[2450]: 20260403 19:16:55.823 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:16:55 volumio-salon qobuz-connect[2450]: 20260403 19:16:55.823 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:16:55 volumio-salon qobuz-connect[2450]: 20260403 19:16:55.823 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:16:55 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:55 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:16:55 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:16:55 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:16:55 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:16:55 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:16:55 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:55.838-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=49035 volume=100 Apr 03 19:16:55 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:16:55.839-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:16:55 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:16:55 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:05 volumio-salon qobuz-connect[2450]: 20260403 19:17:05.822 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:05 volumio-salon qobuz-connect[2450]: 20260403 19:17:05.822 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:05 volumio-salon qobuz-connect[2450]: 20260403 19:17:05.822 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:05 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:05 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:05 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:05 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:05 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:05 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:05 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:05.838-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=59035 volume=100 Apr 03 19:17:05 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:05.838-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:05 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:05 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:15 volumio-salon qobuz-connect[2450]: 20260403 19:17:15.823 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:15 volumio-salon qobuz-connect[2450]: 20260403 19:17:15.823 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:15 volumio-salon qobuz-connect[2450]: 20260403 19:17:15.823 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:15 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:15 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:15 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:15 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:15 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:15 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:15 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:15.838-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=69036 volume=100 Apr 03 19:17:15 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:15.838-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:15 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:15 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:19 volumio-salon kernel: hwmon hwmon1: Undervoltage detected! Apr 03 19:17:23 volumio-salon kernel: hwmon hwmon1: Voltage normalised Apr 03 19:17:25 volumio-salon qobuz-connect[2450]: 20260403 19:17:25.823 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:25 volumio-salon qobuz-connect[2450]: 20260403 19:17:25.823 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:25 volumio-salon qobuz-connect[2450]: 20260403 19:17:25.823 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:25 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:25 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:25 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:25 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:25 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:25 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:25 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:25.846-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=79036 volume=100 Apr 03 19:17:25 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:25.846-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:25 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:25 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:35 volumio-salon qobuz-connect[2450]: 20260403 19:17:35.823 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:35 volumio-salon qobuz-connect[2450]: 20260403 19:17:35.823 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:35 volumio-salon qobuz-connect[2450]: 20260403 19:17:35.823 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:35 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:35 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:35 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:35 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:35 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:35 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:35 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:35.838-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=89035 volume=100 Apr 03 19:17:35 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:35.838-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:35 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:35 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:37 volumio-salon volumiologrotate[582]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Apr 03 19:17:37 volumio-salon volumiologrotate[582]: ls: cannot access 'SALON': No such file or directory Apr 03 19:17:45 volumio-salon qobuz-connect[2450]: 20260403 19:17:45.823 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:45 volumio-salon qobuz-connect[2450]: 20260403 19:17:45.823 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:45 volumio-salon qobuz-connect[2450]: 20260403 19:17:45.823 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:45 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:45 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:45 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:45 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:45.843-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=99036 volume=100 Apr 03 19:17:45 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:45.843-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:45 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:45 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:48 volumio-salon kernel: hwmon hwmon1: Undervoltage detected! Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Received SetState message: Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Playing state: Playing Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Playback position: 0 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Queue version: 3.1 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Current track: TID: 392210562, QID: 8, Context UUID: cf7281fe-b51d-4d31-b67b-ea4ea800060e Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Next track: TID: 102691696, QID: 9, Context UUID: cf7281fe-b51d-4d31-b67b-ea4ea800060e Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO MediaEngine: [0x1091548]: Stopping playback, clearing tracks Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO MediaEngine: [0x1091548]: Initiating playback Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO AudioRenderer: [0x10916b0]: Stopping audio renderer Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.839 [2450.2450] INFO SampleApp: Stopping playback Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.840 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Clearing all streams Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.840 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 5]: Disposing of audio stream Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.840 [2450.2450] INFO ContentFetcher: [0x12a2be0]: Canceling download Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.846 [2450.2450] INFO SampleApp: Playback state changed: Stopped Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.846 [2450.2450] INFO StreamingEventReporter: [0x1091ed0]: Reporting streaming ended event Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.848 [2450.2450] INFO HttpDownloader: [0x1091f28]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.849 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.849 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.849 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO SampleApp: [Stream 5]: Audio stream has been disposed of Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO MediaEngine: [0x1091548]: Setting current track: 392210562, initial offset: 0ms Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Clearing all streams Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO AudioStreamManager: [0x10915f8]: New stream: 7 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO HttpDownloader: [0x1096f50]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=6cd3aed841d330883c9c82eb0f23ed1a&request_ts=1775258273&track_id=392210562 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO HttpDownloader: [0x13112a0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=392210562 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO HttpDownloader: [0x12fd808]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=b29f64d2238a33975b87dde41dbbffc7&request_ts=1775258273&track_id=392210562 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.850 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 7]: Running audio stream Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.852 [2450.2450] INFO MediaEngine: [0x1091548]: Setting next track: 102691696 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.852 [2450.2450] INFO AudioStreamManager: [0x10915f8]: New stream: 8 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.852 [2450.2450] INFO HttpDownloader: [0x12ab4d8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=78f3c6cd9005d903d409fe430e649366&request_ts=1775258273&track_id=102691696 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.852 [2450.2450] INFO HttpDownloader: [0x120c388]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=102691696 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.852 [2450.2450] INFO HttpDownloader: [0x10cd880]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=dec6f7683308b6087fcd9efe6f52a3b3&request_ts=1775258273&track_id=102691696 Apr 03 19:17:53 volumio-salon qobuz-connect[2450]: 20260403 19:17:53.854 [2450.2450] INFO MediaEngine: [0x1091548]: Waiting for current stream to start before starting audio renderer Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:53 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:53.862-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PAUSED positionMs=99036 volume=100 Apr 03 19:17:53 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:53.863-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:53 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:53 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:53.878-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PAUSED positionMs=0 volume=100 Apr 03 19:17:53 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:53.878-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Vrimmel Apr 03 19:17:53 volumio-salon volumio[2022]: info: [ASDebug] CurState: pause PrevState: play Apr 03 19:17:53 volumio-salon volumio[2022]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Apr 03 19:17:53 volumio-salon volumio[2022]: info: [ASDebug] CurState: pause PrevState: play Apr 03 19:17:53 volumio-salon volumio[2022]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Apr 03 19:17:53 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: pause Apr 03 19:17:53 volumio-salon volumio[2022]: info: [GPIO_Control] Handling event: musicPause Apr 03 19:17:53 volumio-salon volumio[2022]: info: [GPIO_Control] *** musicPause *** Apr 03 19:17:53 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: pause Apr 03 19:17:53 volumio-salon volumio[2022]: info: [GPIO_Control] Turning GPIO 6 Off (musicPause) Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.029 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 8]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=102691696&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261873&hmac=qICP5V1jdUvFmWo-CXFKfuVFiZE Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.063 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 7]: stream information have been fetched Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.066 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 8]: Metadata became available: Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.066 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Title: Shape of My Heart (Duet with Leslie Odom Jr.) Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.066 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Artist: Josh Groban Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.066 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album: Harmony Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.066 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album art URL: https://static.qobuz.com/images/covers/eb/1g/qn1qrohhv1geb_600.jpg Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.100 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 8]: stream information have been fetched Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.172 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 7]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=392210562&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261874&hmac=cBPCm2Fr4gidEcY5Ubi9iPWOMoA Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.172 [2450.2450] INFO UrlAudioSource: [0x1097188]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=392210562&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261874&hmac=cBPCm2Fr4gidEcY5Ubi9iPWOMoA Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.172 [2450.2450] INFO ContentFetcher: [0x1209be8]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2487270&eid=392210562&fmt=7&profile=raw&app_id=174516466&cid=1726506&etsp=1775261874&hmac=cBPCm2Fr4gidEcY5Ubi9iPWOMoA, offset: 0 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.172 [2450.2450] INFO AudioRenderer: [0x10916b0]: Starting audio renderer, initial playback state: Playing Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.172 [2450.2450] INFO SampleApp: [Stream 7]: New audio stream (starting from 0ms) Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: QobuzConnect: alread currrent service, send playback confirmation Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.174 [2450.2450] INFO SampleApp: Initiating playback, initial state: Playing Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.179 [2450.2450] INFO SampleApp: Playback state changed: Playing Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.179 [2450.2450] INFO StreamingEventReporter: [0x1091ed0]: Reporting streaming started event Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.179 [2450.2450] INFO ProtocolHandler: [0x1091b20]: Need to send state update Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.179 [2450.2450] INFO QConnectMessageSender: [0x121c2a8]: Sending StateUpdated message Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.179 [2450.2450] INFO QwspMessageSender: [0x121c298]: Sending Payload message Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO AudioStreamManager: [0x10915f8]: [Stream 7]: Metadata became available: Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Title: Sarniezz Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Artist: Angine de Poitrine Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album: Vol.II Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO AudioStreamManager: [0x10915f8]: Album art URL: https://static.qobuz.com/images/covers/dv/hk/xetru34w7hkdv_600.jpg Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO SampleApp: [Stream 7]: Stream metadata became available: Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO SampleApp: Title: Sarniezz Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO SampleApp: Artist: Angine de Poitrine Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.196 [2450.2450] INFO SampleApp: Album: Vol.II Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.197 [2450.2450] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/dv/hk/xetru34w7hkdv_600.jpg Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.197-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.198-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title= Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.199-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PAUSED positionMs=0 volume=100 Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.199-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title= Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::servicePushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreStateMachine::pushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioPushState Apr 03 19:17:54 volumio-salon volumio[2022]: info: CoreCommandRouter::volumioGetState Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.228-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.228-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title= Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.229-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.228-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" state=STATUS_PLAYING positionMs=0 volume=100 Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.229-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title=Sarniezz Apr 03 19:17:54 volumio-salon volumio5-onboarding[1126]: time=2026-04-03T19:17:54.229-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.170:49980 @ 0x1fb6810" id= title= Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.234 [2450.2450] INFO HttpDownloader: [0x1091f28]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Apr 03 19:17:54 volumio-salon volumio[2022]: info: [ASDebug] CurState: pause PrevState: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [ASDebug] InitTimeout - Amp off in: 60000 ms Apr 03 19:17:54 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [ASDebug] CurState: play PrevState: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: pause Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] Handling event: musicPlay Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] *** musicPlay *** Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [GPIO_Control] Status changed: play Apr 03 19:17:54 volumio-salon volumio[2022]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Apr 03 19:17:54 volumio-salon volumio[2022]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 19:17:54 volumio-salon volumio[2022]: TypeError: Cannot read property 'indexOf' of undefined Apr 03 19:17:54 volumio-salon volumio[2022]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Apr 03 19:17:54 volumio-salon volumio[2022]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Apr 03 19:17:54 volumio-salon volumio[2022]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Apr 03 19:17:54 volumio-salon volumio[2022]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Apr 03 19:17:54 volumio-salon volumio[2022]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Apr 03 19:17:54 volumio-salon volumio[2022]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Apr 03 19:17:54 volumio-salon volumio[2022]: at Decoder.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Apr 03 19:17:54 volumio-salon volumio[2022]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Apr 03 19:17:54 volumio-salon volumio[2022]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Apr 03 19:17:54 volumio-salon volumio[2022]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Apr 03 19:17:54 volumio-salon volumio[2022]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2450] INFO UrlAudioSource: [0x1097188]: Content info extracted Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2450] INFO UrlAudioSource: [0x1097188]: Size: 57626669 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2940] INFO AudioDecoder: [0x128fd70]: Stream info: Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2940] INFO AudioDecoder: [0x128fd70]: Total samples: 13228799 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2940] INFO AudioDecoder: [0x128fd70]: Sample rate: 48000 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2940] INFO AudioDecoder: [0x128fd70]: Channel count: 2 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2940] INFO AudioDecoder: [0x128fd70]: Bits per sample: 24 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.432 [2450.2940] INFO AudioDecoder: [0x128fd70]: Duration: 275599 Apr 03 19:17:54 volumio-salon qobuz-connect[2450]: 20260403 19:17:54.433 [2450.2450] INFO UrlAudioSource: [0x1097188]: Audio properties have changed Apr 03 19:17:54 volumio-salon sudo[2942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-03 19:16 Apr 03 19:17:54 volumio-salon sudo[2942]: 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="5c0e72e4b5817fe66c91c9d15d75ff13b8e3f4ba" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 30 Mar 2026 02:51:29 PM CEST" VOLUMIO_VERSION="3.914" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="98fe12c88d8ff391f569279e2f874892"