Oct 17 10:12:06 volumio qobuz-connect[2617]: 20261017 10:12:06.368 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Need to send state update Oct 17 10:12:06 volumio qobuz-connect[2617]: 20261017 10:12:06.368 [2617.2617] INFO QConnectMessageSender: [0x55be5a25cc40]: Sending StateUpdated message Oct 17 10:12:06 volumio qobuz-connect[2617]: 20261017 10:12:06.368 [2617.2617] INFO QwspMessageSender: [0x55be5a0cf740]: Sending Payload message Oct 17 10:12:06 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:06 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:12:06 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:12:06 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:12:06 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:12:06 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:12:06 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:12:06 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:06 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:06.371+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=329712 volume=100 Oct 17 10:12:06 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:06.371+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="Cluster One" Oct 17 10:12:06 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:12:06 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 356 | title: Cluster One | previous title: Cluster One Oct 17 10:12:06 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: false | timer started at: 1792224396376 Oct 17 10:12:06 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:12:06 volumio volumio[1357]: info: [LastFM] Same state as the one previously pushed. No need to do anything... Oct 17 10:12:06 volumio volumio[1357]: info: Display-configuration --- Volumio status=play timeout=300 noifplay=true screensavertype=dpms Oct 17 10:12:06 volumio volumio[1357]: info: Display-configuration --- → Wakeup triggered Oct 17 10:12:06 volumio volumio[1357]: info: Display-configuration --- wakeupScreen: DPMS - screen on Oct 17 10:12:16 volumio qobuz-connect[2617]: 20261017 10:12:16.368 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Need to send state update Oct 17 10:12:16 volumio qobuz-connect[2617]: 20261017 10:12:16.368 [2617.2617] INFO QConnectMessageSender: [0x55be5a25cc40]: Sending StateUpdated message Oct 17 10:12:16 volumio qobuz-connect[2617]: 20261017 10:12:16.368 [2617.2617] INFO QwspMessageSender: [0x55be5a0cf740]: Sending Payload message Oct 17 10:12:16 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:16 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:12:16 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:12:16 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:12:16 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:12:16 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:12:16 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:12:16 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:16 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:16.371+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=339711 volume=100 Oct 17 10:12:16 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:16.371+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="Cluster One" Oct 17 10:12:16 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:12:16 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 356 | title: Cluster One | previous title: Cluster One Oct 17 10:12:16 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: false | timer started at: 1792224396376 Oct 17 10:12:16 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:12:16 volumio volumio[1357]: info: [LastFM] Same state as the one previously pushed. No need to do anything... Oct 17 10:12:16 volumio volumio[1357]: info: Display-configuration --- Volumio status=play timeout=300 noifplay=true screensavertype=dpms Oct 17 10:12:16 volumio volumio[1357]: info: Display-configuration --- → Wakeup triggered Oct 17 10:12:16 volumio volumio[1357]: info: Display-configuration --- wakeupScreen: DPMS - screen on Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 41]: Running audio stream Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO UrlAudioSource: [0x55be5ab36550]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=10433069&eid=47683885&fmt=27&profile=raw&app_id=174516466&cid=3860144&etsp=1792227996&hmac=GL7BCoVArD2UpZ-Q6tQBbjQCCAQ Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO ContentFetcher: [0x55be5a773ae0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=10433069&eid=47683885&fmt=27&profile=raw&app_id=174516466&cid=3860144&etsp=1792227996&hmac=GL7BCoVArD2UpZ-Q6tQBbjQCCAQ, offset: 0 Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO SampleApp: [Stream 41]: New audio stream (starting from 0ms) Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO SampleApp: [Stream 41]: Stream metadata became available: Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO SampleApp: Title: What Do You Want from Me Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO SampleApp: Artist: Pink Floyd Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO SampleApp: Album: The Division Bell Oct 17 10:12:21 volumio qobuz-connect[2617]: 20261017 10:12:21.858 [2617.2617] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/dc/9n/zkw3csyyk9ndc_600.jpg Oct 17 10:12:21 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:26 volumio qobuz-connect[2617]: 20261017 10:12:26.368 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Need to send state update Oct 17 10:12:26 volumio qobuz-connect[2617]: 20261017 10:12:26.368 [2617.2617] INFO QConnectMessageSender: [0x55be5a25cc40]: Sending StateUpdated message Oct 17 10:12:26 volumio qobuz-connect[2617]: 20261017 10:12:26.368 [2617.2617] INFO QwspMessageSender: [0x55be5a0cf740]: Sending Payload message Oct 17 10:12:26 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:26 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:12:26 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:12:26 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:12:26 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:12:26 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:12:26 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:12:26 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:26 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:26.371+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=349711 volume=100 Oct 17 10:12:26 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:26.371+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="Cluster One" Oct 17 10:12:26 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:12:26 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 356 | title: Cluster One | previous title: Cluster One Oct 17 10:12:26 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: false | timer started at: 1792224396376 Oct 17 10:12:26 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:12:26 volumio volumio[1357]: info: [LastFM] Same state as the one previously pushed. No need to do anything... Oct 17 10:12:26 volumio volumio[1357]: info: Display-configuration --- Volumio status=play timeout=300 noifplay=true screensavertype=dpms Oct 17 10:12:26 volumio volumio[1357]: info: Display-configuration --- → Wakeup triggered Oct 17 10:12:26 volumio volumio[1357]: info: Display-configuration --- wakeupScreen: DPMS - screen on Oct 17 10:12:46 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:46.836+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s Oct 17 10:12:47 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 10:12:47 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 10:12:47 volumio volumio[1357]: info: Discovery: Getting this device information Oct 17 10:12:47 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:47 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 10:12:47 volumio volumio[1357]: verbose: New Socket.io Connection to 192.168.1.244:3000 from 192.168.1.62 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Oct 17 10:12:47 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 17 10:12:47 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 17 10:12:47 volumio volumio[1357]: verbose: New Socket.io Connection to 192.168.1.244 from 192.168.1.62 UA: Mozilla/5.0 (Linux; Android 13; 2201117TY Build/TKQ1.221114.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.57 Mobile Safari/537.36 VolumioApp/6.260915.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::volumioGetVisibleSources Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 17 10:12:48 volumio volumio[1357]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 17 10:12:48 volumio volumio[1357]: info: Received Get System Info Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 10:12:48 volumio volumio[1357]: info: Discovery: Getting this device information Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:48 volumio volumio[1357]: info: Listing playlists Oct 17 10:12:48 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 17 10:12:49 volumio qobuz-connect[2617]: 20261017 10:12:49.893 [2617.2617] ERROR HttpClient: [0x55be5a773c90]: Client finished: Timeout was reached (28) Oct 17 10:12:49 volumio qobuz-connect[2617]: 20261017 10:12:49.893 [2617.2617] INFO HttpClient: [0x55be5a773c90]: Retrying connection (1 out of 1) Oct 17 10:12:49 volumio qobuz-connect[2617]: ALSA lib ./src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Oct 17 10:12:49 volumio qobuz-connect[2617]: 20261017 10:12:49.893 [2617.2617] WARNING SampleApp: Unable to query available space in ALSA audio sink, trying to recover Oct 17 10:12:49 volumio qobuz-connect[2617]: 20261017 10:12:49.894 [2617.2617] INFO CloudClient: [0x55be5a0c7dc0]: Connection closed Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.032 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 40]: Audio stream has finished Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.033 [2617.2617] INFO SampleApp: [Stream 40]: Audio stream finished Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.033 [2617.2617] INFO SampleApp: Playback is nearly finished Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.681 [2617.2617] INFO SampleApp: Playback has finished Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 40]: Disposing of audio stream Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] INFO ContentFetcher: [0x55be5a73df50]: Canceling download Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] INFO SampleApp: [Stream 40]: Audio stream has been disposed of Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] INFO StreamingEventReporter: [0x55be5a0c8690]: Reporting streaming ended event Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] INFO HttpDownloader: [0x55be5a0c8720]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] WARNING SampleApp: Unable to get buffered frame count from ALSA audio sink, trying to recover Oct 17 10:12:54 volumio qobuz-connect[2617]: 20261017 10:12:54.682 [2617.2617] INFO StreamingEventReporter: [0x55be5a0c8690]: Reporting streaming started event Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:12:54 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:12:54 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:12:54 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:12:54 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:12:54 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:12:54 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:12:54 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:12:54 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:54.686+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=0 volume=100 Oct 17 10:12:54 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:54.686+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="What Do You Want from Me" Oct 17 10:12:54 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:54.686+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=0 volume=100 Oct 17 10:12:54 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:54.686+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="What Do You Want from Me" Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:12:54 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 262 | title: What Do You Want from Me | previous title: Cluster One Oct 17 10:12:54 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: false | timer started at: 1792224396376 Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] Current track has sufficient metadata: title (What Do You Want from Me) and artist (Pink Floyd) passed on explicitly Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] Updating now playing Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] starting new timer for 131000 milliseconds [Pink Floyd - What Do You Want from Me]. Oct 17 10:12:54 volumio volumio[1357]: -------------------------------------------------// S T A R T I N G Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] Timer started with time stamp 1792224774 Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:12:54 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 262 | title: What Do You Want from Me | previous title: What Do You Want from Me Oct 17 10:12:54 volumio volumio[1357]: info: =================> [timer] is active: true | can continue: false | timer started at: 1792224774689 Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:12:54 volumio volumio[1357]: info: [LastFM] Same state as the one previously pushed. No need to do anything... Oct 17 10:12:54 volumio volumio[1357]: info: Display-configuration --- Volumio status=play timeout=300 noifplay=true screensavertype=dpms Oct 17 10:12:54 volumio volumio[1357]: info: Display-configuration --- → Wakeup triggered Oct 17 10:12:54 volumio volumio[1357]: info: Display-configuration --- Volumio status=play timeout=300 noifplay=true screensavertype=dpms Oct 17 10:12:54 volumio volumio[1357]: info: Display-configuration --- → Wakeup triggered Oct 17 10:12:54 volumio volumio[1357]: info: Display-configuration --- wakeupScreen: DPMS - screen on Oct 17 10:12:54 volumio volumio[1357]: info: Display-configuration --- wakeupScreen: DPMS - screen on Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.836+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://functions.volumio.cloud duration=9.999587451s error="Head \"https://functions.volumio.cloud\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.836+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=http://cddb.volumio.org duration=9.999625797s error="Head \"http://cddb.volumio.org\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.836+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=9.999669551s error="Head \"https://browsing-performer.dfs.volumio.org\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://www.googleapis.com duration=10.000388823s error="Head \"https://www.googleapis.com\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=http://pushupdates.volumio.org duration=9.999715545s error="Head \"http://pushupdates.volumio.org\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=10.000533738s error="Head \"https://radio-directory.firebaseapp.com\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=9.999730341s error="Head \"https://myvolumio.firebaseio.com\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://google.com duration=9.999772607s error="Head \"https://google.com\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://functions.volumio.cloud duration=9.999508232s error="Head \"https://functions.volumio.cloud\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=http://plugins.volumio.org duration=9.999753868s error="Head \"http://plugins.volumio.org\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://securetoken.googleapis.com duration=10.000505506s error="Head \"https://securetoken.googleapis.com\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=10.000525873s error="Head \"https://oauth-performer.dfs.volumio.org\": context deadline exceeded" Oct 17 10:12:56 volumio volumio5-onboarding[2039]: time=2026-10-17T10:12:56.837+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.62:47290 @ 0xc00039fe30" latency=-382.597109ms timeout=10s endpoint=https://database.volumio.cloud duration=9.999708471s error="Head \"https://database.volumio.cloud\": context deadline exceeded" Oct 17 10:12:59 volumio volumio[1357]: info: [LastFM] updated "now playing" | artist: Pink Floyd | title: What Do You Want from Me Oct 17 10:13:00 volumio volumio[1357]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"What Do You Want From Me","mbid":"01ab0723-6b8b-4636-ac68-a5913323535a","url":"https://www.last.fm/music/Pink+Floyd/_/What+Do+You+Want+From+Me","duration":"279000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"479896","playcount":"3240411","artist":{"name":"Pink Floyd","mbid":"83d91898-7763-47d7-b03b-b92132375c47","url":"https://www.last.fm/music/Pink+Floyd"},"album":{"artist":"Pink Floyd","title":"The Division Bell","url":"https://www.last.fm/music/Pink+Floyd/The+Division+Bell","image":[{"#":"https://lastfm-img.freetls.fastly.net/i/u/34s/82d5936d6b5997791c300fc7743ff3ce.png","@":{"size":"small"}},{"#":"https://lastfm-img.freetls.fastly.net/i/u/64s/82d5936d6b5997791c300fc7743ff3ce.png","@":{"size":"medium"}},{"#":"https://lastfm-img.freetls.fastly.net/i/u/174s/82d5936d6b5997791c300fc7743ff3ce.png","@":{"size":"large"}},{"#":"https://lastfm-img.freetls.fastly.net/i/u/300x300/82d5936d6b5997791c300fc7743ff3ce.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":"","wiki":{"published":"12 May 2014, 22:53","summary":"The song is a slow, yet rocking ballad. It has a drum roll introduction, followed by a keyboard solo and then a guitar solo. In an interview, David Gilmour was asked if the song returned to the theme of alienation from the audience. He responded by saying that it \"actually had more to do with personal relationships but drifted into wider territory\". The song references the miracle of walking on water as a sarcastic metaphor. Read more on Last.fm.","content":"The song is a slow, yet rocking ballad. It has a drum roll introduction, followed by a keyboard solo and then a guitar solo. In an interview, David Gilmour was asked if the song returned to the theme of alienation from the audience. He responded by saying that it \"actually had more to do with personal relationships but drifted into wider territory\". The song references the miracle of walking on water as a sarcastic metaphor. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Oct 17 10:13:00 volumio qobuz-connect[2617]: 20261017 10:13:00.575 [2617.2621] INFO SampleApp: API endpoint invoked: get-display-info Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.983 [2617.2617] ERROR HttpClient: [0x55be5a773c90]: Client finished: Timeout was reached (28) Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.983 [2617.2617] ERROR HttpClient: [0x55be5a773c90]: Failed to connect after 1 retries Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.983 [2617.2617] ERROR UrlAudioSource: [0x55be5ab36550]: Content fetcher has encountered an error Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.983 [2617.2617] INFO ContentFetcher: [0x55be5a773ae0]: Canceling download Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.983 [2617.2617] ERROR AudioStreamManager: [0x55be5a0c7680]: [Stream 41]: Audio stream has encountered an error Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] ERROR HttpClient: [0x55be5a135d80]: Client finished: Timeout was reached (28) Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] INFO HttpClient: [0x55be5a135d80]: Retrying connection (1 out of 1) Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] ERROR MediaEngine: [0x55be5a0c7550]: Current stream has encountered an error Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Stopping playback, clearing tracks Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] INFO SampleApp: Playback state changed: Stopped Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] INFO StreamingEventReporter: [0x55be5a0c8690]: Reporting streaming ended event Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] INFO AudioRenderer: [0x55be5a0c77d0]: Stopping audio renderer Oct 17 10:13:03 volumio qobuz-connect[2617]: 20261017 10:13:03.993 [2617.2617] INFO SampleApp: Stopping playback Oct 17 10:13:03 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:03 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:03 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:03 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:13:03 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:03 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:03 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:03 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:03 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:03.996+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PAUSED positionMs=0 volume=100 Oct 17 10:13:03 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:03.996+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="What Do You Want from Me" Oct 17 10:13:03 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:13:03 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: qobuzconnect | duration: 262 | title: What Do You Want from Me | previous title: What Do You Want from Me Oct 17 10:13:03 volumio volumio[1357]: info: =================> [timer] is active: true | can continue: false | timer started at: 1792224774689 Oct 17 10:13:03 volumio volumio[1357]: info: [LastFM] Song has been paused, so also pausing timer. Oct 17 10:13:03 volumio volumio[1357]: -------------------------------------------------// P A U S I N G (remaining: 121692 milliseconds) Oct 17 10:13:03 volumio volumio[1357]: info: Display-configuration --- Volumio status=pause timeout=300 noifplay=true screensavertype=dpms Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.030 [2617.2621] INFO SampleApp: API endpoint invoked: get-connect-info Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO CloudClient: [0x55be5a0c7dc0]: Connection established Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QwspMessageSender: [0x55be5a595dc0]: Sending Authenticate message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QwspMessageSender: [0x55be5a595dc0]: Sending Subscribe message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending JoinSession message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending VolumeChanged message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending VolumeMuted message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending MaxAudioQualityChanged message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending PlaybackError message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.128 [2617.2617] INFO QwspMessageSender: [0x55be5a595dc0]: Sending Payload message Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.130+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PAUSED positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.130+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="What Do You Want from Me" Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:13:04 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: qobuzconnect | duration: 262 | title: What Do You Want from Me | previous title: What Do You Want from Me Oct 17 10:13:04 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: true | timer started at: 1792224774689 Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] Song has been paused, so also pausing timer. Oct 17 10:13:04 volumio volumio[1357]: info: Display-configuration --- Volumio status=pause timeout=300 noifplay=true screensavertype=dpms Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.223 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Received SetActive message: active Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.223 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Received SetLoopMode message: Off Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.223 [2617.2617] INFO PlaybackModeManager: [0x55be5a0c7a30]: Setting new loop mode: Off Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.223 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Received SetShuffleMode message: disabled Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.223 [2617.2617] INFO PlaybackModeManager: [0x55be5a0c7a30]: Setting new shuffle mode: disabled Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Received SetState message: Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Playing state: Playing Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Playback position: 0 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Queue version: 14.1 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Current track: TID: 47683886, QID: 338, Context UUID: 772445c5-dde2-4efd-8720-bb22bf83b081 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Next track: TID: 47683887, QID: 339, Context UUID: 772445c5-dde2-4efd-8720-bb22bf83b081 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Reseting Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Stopping playback, clearing tracks Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Initiating playback Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Need to send state update Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending StateUpdated message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO QwspMessageSender: [0x55be5a595dc0]: Sending Payload message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Setting current track: 47683886, initial offset: 0ms Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Clearing all streams Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 41]: Disposing of audio stream Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: New stream: 42 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO HttpDownloader: [0x55be5a260480]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=1740472251681d84911e903065cad41a&request_ts=1792224784&track_id=47683886 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO HttpDownloader: [0x55be5a24eaf0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=47683886 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO HttpDownloader: [0x55be5a3f5d40]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=146cf1278bb9c2c0795fd71e7a2d8265&request_ts=1792224784&track_id=47683886 Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 42]: Running audio stream Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO SampleApp: [Stream 41]: Audio stream has been disposed of Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Setting next track: 47683887 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: New stream: 43 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO HttpDownloader: [0x55be5a6abae0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=5fb026ef19781e87a23086277958b999&request_ts=1792224784&track_id=47683887 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO HttpDownloader: [0x55be5a199a30]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=47683887 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO HttpDownloader: [0x55be5a199dc0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=a2e797549316e433cffb4bfd44f6d548&request_ts=1792224784&track_id=47683887 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.224 [2617.2617] INFO MediaEngine: [0x55be5a0c7550]: Waiting for current stream to start before starting audio renderer Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.226+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PAUSED positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.226+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="What Do You Want from Me" Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:13:04 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: qobuzconnect | duration: 262 | title: What Do You Want from Me | previous title: What Do You Want from Me Oct 17 10:13:04 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: true | timer started at: 1792224774689 Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] Song has been paused, so also pausing timer. Oct 17 10:13:04 volumio volumio[1357]: info: Display-configuration --- Volumio status=pause timeout=300 noifplay=true screensavertype=dpms Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.290 [2617.2617] INFO HttpDownloader: [0x55be5a0c8720]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.420 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 42]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=10433069&eid=47683886&fmt=27&profile=raw&app_id=174516466&cid=3860144&etsp=1792228384&hmac=kahlOONkgk_EVwjysjLceA1Xvs0 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.423 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 43]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=10433069&eid=47683887&fmt=27&profile=raw&app_id=174516466&cid=3860144&etsp=1792228384&hmac=UeLNofrg-cZmM2YNjAoxMUzGl9E Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.435 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 42]: stream information have been fetched Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.435 [2617.2617] INFO UrlAudioSource: [0x55be5a19a440]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=10433069&eid=47683886&fmt=27&profile=raw&app_id=174516466&cid=3860144&etsp=1792228384&hmac=kahlOONkgk_EVwjysjLceA1Xvs0 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.435 [2617.2617] INFO ContentFetcher: [0x55be5a6031c0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=10433069&eid=47683886&fmt=27&profile=raw&app_id=174516466&cid=3860144&etsp=1792228384&hmac=kahlOONkgk_EVwjysjLceA1Xvs0, offset: 0 Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.435 [2617.2617] INFO AudioRenderer: [0x55be5a0c77d0]: Starting audio renderer, initial playback state: Playing Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.435 [2617.2617] INFO SampleApp: [Stream 42]: New audio stream (starting from 0ms) Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: QobuzConnect: alread currrent service, send playback confirmation Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.435 [2617.2617] INFO SampleApp: Initiating playback, initial state: Playing Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO SampleApp: Playback state changed: Playing Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO StreamingEventReporter: [0x55be5a0c8690]: Reporting streaming started event Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO ProtocolHandler: [0x55be5a0c7fc0]: Need to send state update Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO QConnectMessageSender: [0x55be5a595de0]: Sending StateUpdated message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO QwspMessageSender: [0x55be5a595dc0]: Sending Payload message Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 42]: Metadata became available: Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Title: Poles Apart Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Artist: Pink Floyd Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Album: The Division Bell Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Album art URL: https://static.qobuz.com/images/covers/dc/9n/zkw3csyyk9ndc_600.jpg Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO HttpDownloader: [0x55be5a0c8720]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO SampleApp: [Stream 42]: Stream metadata became available: Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO SampleApp: Title: Poles Apart Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO SampleApp: Artist: Pink Floyd Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO SampleApp: Album: The Division Bell Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/dc/9n/zkw3csyyk9ndc_600.jpg Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 43]: Metadata became available: Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Title: Marooned Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Artist: Pink Floyd Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Album: The Division Bell Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: Album art URL: https://static.qobuz.com/images/covers/dc/9n/zkw3csyyk9ndc_600.jpg Oct 17 10:13:04 volumio qobuz-connect[2617]: 20261017 10:13:04.439 [2617.2617] INFO AudioStreamManager: [0x55be5a0c7680]: [Stream 43]: stream information have been fetched Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.441+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PAUSED positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.441+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title= Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::servicePushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreStateMachine::pushState Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioPushState Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output update for this device Oct 17 10:13:04 volumio volumio[1357]: info: MRS: Pushing multiroomSync output Oct 17 10:13:04 volumio volumio[1357]: info: CoreCommandRouter::volumioGetState Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.451+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.451+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.451+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title= Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.451+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title= Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.451+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.452+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" state=STATUS_PLAYING positionMs=0 volume=100 Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.452+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title="Poles Apart" Oct 17 10:13:04 volumio volumio5-onboarding[2039]: time=2026-10-17T10:13:04.452+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.62:47290 @ 0xc00039fe30" id= title= Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:13:04 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: qobuzconnect | duration: 424 | title: | previous title: What Do You Want from Me Oct 17 10:13:04 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: true | timer started at: 1792224774689 Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] Song has been paused, so also pausing timer. Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:13:04 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 424 | title: | previous title: What Do You Want from Me Oct 17 10:13:04 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: true | timer started at: 1792224774689 Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] using existing timer Oct 17 10:13:04 volumio volumio[1357]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: qobuzconnect | duration: 424 | title: undefined | previous title: Oct 17 10:13:04 volumio volumio[1357]: info: =================> [timer] is active: false | can continue: true | timer started at: 1792224774689 Oct 17 10:13:04 volumio volumio[1357]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... Oct 17 10:13:04 volumio volumio[1357]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 10:13:04 volumio volumio[1357]: TypeError: Cannot read properties of undefined (reading 'indexOf') Oct 17 10:13:04 volumio volumio[1357]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Oct 17 10:13:04 volumio volumio[1357]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Oct 17 10:13:04 volumio volumio[1357]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Oct 17 10:13:04 volumio volumio[1357]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Oct 17 10:13:04 volumio volumio[1357]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Oct 17 10:13:04 volumio volumio[1357]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Oct 17 10:13:04 volumio volumio[1357]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Oct 17 10:13:04 volumio volumio[1357]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Oct 17 10:13:04 volumio volumio[1357]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Oct 17 10:13:04 volumio volumio[1357]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Oct 17 10:13:04 volumio volumio[1357]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Oct 17 10:13:04 volumio volumio[1357]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Oct 17 10:13:04 volumio volumio[1357]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Oct 17 10:13:04 volumio volumio[1357]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Oct 17 10:13:04 volumio volumio[1357]: at Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Oct 17 10:13:04 volumio volumio[1357]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Oct 17 10:13:04 volumio volumio[1357]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 10:13:04 volumio sudo[19898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-17 10:12' Oct 17 10:13:04 volumio sudo[19898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"