-- Logs begin at Fri 2025-06-13 17:41:16 CEST, end at Fri 2025-06-13 18:28:51 CEST. -- Jun 13 18:27:02 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:02 raspamp volumio[835]: info: Listing playlists Jun 13 18:27:02 raspamp volumio[835]: info: Listing playlists Jun 13 18:27:08 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 13 18:27:08 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 13 18:27:08 raspamp volumio[835]: info: Discovery: Getting this device information Jun 13 18:27:08 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:08 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 13 18:27:09 raspamp kernel: hwmon hwmon1: Voltage normalised Jun 13 18:27:11 raspamp kernel: hwmon hwmon1: Undervoltage detected! Jun 13 18:27:12 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:22 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:22 raspamp volumio[835]: info: Listing playlists Jun 13 18:27:27 raspamp go-librespot[1157]: time="2025-06-13T18:27:27+02:00" level=trace msg="received accesspoint ping" Jun 13 18:27:27 raspamp go-librespot[1157]: time="2025-06-13T18:27:27+02:00" level=trace msg="received accesspoint pong ack" Jun 13 18:27:28 raspamp go-librespot[1157]: time="2025-06-13T18:27:28+02:00" level=trace msg="sent dealer ping" Jun 13 18:27:28 raspamp go-librespot[1157]: time="2025-06-13T18:27:28+02:00" level=trace msg="received dealer pong" Jun 13 18:27:32 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.547 [1595.3968] INFO SampleApp: API endpoint invoked: get-connect-info Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.733 [1595.3968] INFO SampleApp: API endpoint invoked: connect-to-qconnect Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.734 [1595.1595] INFO EndpointManager: [0x1d56fe8]: Updating API endpoint Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.734 [1595.1595] INFO EndpointManager: [0x1d56fe8]: Updating QConnect endpoint Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.734 [1595.1595] INFO ActiveStateManager: [0x1d56000]: Setting new active state: active Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.734 [1595.1595] INFO PlaybackSessionManager: [0x1d573d8]: Starting playback session maintenance Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.734 [1595.1595] INFO CloudClient: [0x1d57c48]: Connecting to the cloud Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.745 [1595.1595] INFO SampleApp: Renderer is now active Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.992 [1595.1595] INFO CloudClient: [0x1d57c48]: Connection established Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.992 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Authenticate message Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.992 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Subscribe message Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.993 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending JoinSession message Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.993 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending VolumeChanged message Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.993 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending VolumeMuted message Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.993 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending MaxAudioQualityChanged message Jun 13 18:27:32 raspamp qobuz-connect[1595]: 20250613 18:27:32.993 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Payload message Jun 13 18:27:33 raspamp nmbd[872]: [2025/06/13 18:27:33.178558, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jun 13 18:27:33 raspamp nmbd[872]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.72.162 for name WORKGROUP<1d>. Jun 13 18:27:33 raspamp nmbd[872]: This response was from IP 192.168.72.234, reporting an IP address of 192.168.72.234. Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.948 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetActive message: active Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetState message: Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Playing state: Paused Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Playback position: 184749 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Queue version: 4.1 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Current track: TID: 2761773, QID: 7, Context UUID: 0c7dd86c-b52b-49e1-8435-a1d37b916d13 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Next track: TID: 57393613, QID: 8, Context UUID: 0c7dd86c-b52b-49e1-8435-a1d37b916d13 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO MediaEngine: [0x1d57670]: Stopping playback, clearing tracks Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO MediaEngine: [0x1d57670]: Initiating playback Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetLoopMode message: Off Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO PlaybackControlsManager: [0x1d57a48]: Setting new loop mode: Off Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting current track: 2761773, initial offset: 184749ms Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Clearing all streams Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.949 [1595.1595] INFO AudioStreamManager: [0x1d57758]: New stream: 3 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.950 [1595.1595] INFO HttpDownloader: [0x1d5e3b8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d7e0fefa4d2ce37c3fe16d45eaa2b998&request_ts=1749832054&track_id=2761773 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.950 [1595.1595] INFO HttpDownloader: [0x1f38688]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=2761773 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.950 [1595.1595] INFO HttpDownloader: [0x1f5f250]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=2caa53066d1630cc1c90c7bbcc3c7fc0&request_ts=1749832054&track_id=2761773 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.950 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 3]: Running audio stream Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.950 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetShuffleMode message: disabled Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.950 [1595.1595] INFO PlaybackControlsManager: [0x1d57a48]: Setting new shuffle mode: disabled Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.952 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting next track: 57393613 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.952 [1595.1595] INFO AudioStreamManager: [0x1d57758]: New stream: 4 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.952 [1595.1595] INFO HttpDownloader: [0x1efbaa8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d85b22a53f1d957f4a2dea10449cd509&request_ts=1749832054&track_id=57393613 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.952 [1595.1595] INFO HttpDownloader: [0x1e30bc8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=57393613 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.952 [1595.1595] INFO HttpDownloader: [0x1f3abb8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=fae675f69233dcae0cce4423a1a72021&request_ts=1749832054&track_id=57393613 Jun 13 18:27:34 raspamp qobuz-connect[1595]: 20250613 18:27:34.955 [1595.1595] INFO MediaEngine: [0x1d57670]: Waiting for current stream to start before starting audio renderer Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.874 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 4]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=57393613&fmt=6&profile=raw&app_id=174516466&cid=2725398&etsp=1749835655&hmac=JnbQKFpkS9lNz7uprGK26RIMUc0 Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.927 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 4]: stream information have been fetched Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.952 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 3]: Metadata became available: Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.952 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Title: Surf City Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.952 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Artist: Jan & Dean Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.952 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album: Surf City And Other Swingin' Cities Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.952 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album art URL: https://static.qobuz.com/images/covers/59/46/5099994834659_600.jpg Jun 13 18:27:35 raspamp qobuz-connect[1595]: 20250613 18:27:35.955 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 3]: stream information have been fetched Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.000 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 4]: Metadata became available: Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.000 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Title: The Like In I Love You Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.000 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Artist: Brian Wilson Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.000 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album: Brian Wilson Reimagines Gershwin Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.000 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album art URL: https://static.qobuz.com/images/covers/3b/1u/bjteef1bp1u3b_600.jpg Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.035 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 3]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=2761773&fmt=6&profile=raw&app_id=174516466&cid=2725398&etsp=1749835655&hmac=FRZ8fAy2w1JsaupX92p1AjRwEPU Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.035 [1595.1595] INFO UrlAudioSource: [0x2122278]: Starting URL audio source, initial position: 184749ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=2761773&fmt=6&profile=raw&app_id=174516466&cid=2725398&etsp=1749835655&hmac=FRZ8fAy2w1JsaupX92p1AjRwEPU Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.035 [1595.1595] INFO ContentFetcher: [0x1f39ca8]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=2761773&fmt=6&profile=raw&app_id=174516466&cid=2725398&etsp=1749835655&hmac=FRZ8fAy2w1JsaupX92p1AjRwEPU, offset: 0 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.036 [1595.1595] INFO AudioRenderer: [0x1d57890]: Starting audio renderer, initial playback state: Paused Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.036 [1595.1595] INFO SampleApp: [Stream 3]: New audio stream (starting from 184748ms) Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.037 [1595.1595] INFO SampleApp: [Stream 3]: Stream metadata became available: Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.037 [1595.1595] INFO SampleApp: Title: Surf City Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.037 [1595.1595] INFO SampleApp: Artist: Jan & Dean Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.037 [1595.1595] INFO SampleApp: Album: Surf City And Other Swingin' Cities Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.037 [1595.1595] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/59/46/5099994834659_600.jpg Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: QobuzConnect: setActiveState() Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: QobuzConnect: Set Qobuz connect default volume to 76 Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.049 [1595.1595] INFO VolumeManager: [0x1d57ad8]: Setting new playback volume: 76 Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: QobuzConnect: Stopping currently active service Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioStop Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::stop Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::updateTrackBlock Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrackBlock Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::serviceStop Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::serviceStop Jun 13 18:27:36 raspamp volumio[835]: info: [1749832056066] ControllerQobuz::stop Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::stop Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand stop Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand stop took 46 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received qobuzconnect Jun 13 18:27:36 raspamp volumio[835]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect Jun 13 18:27:36 raspamp volumio[835]: info: QobuzConnect: setActiveState() completed, send playback confirmation Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.154 [1595.1595] INFO SampleApp: Initiating playback, initial state: Paused Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 42 milliseconds Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: info: Jun 13 18:27:36 raspamp volumio[835]: ---------------------------- MPD announces state update: player Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::getState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 37 milliseconds Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.193 [1595.1595] INFO SampleApp: Playback state changed: Paused Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.193 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Need to send state update Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.193 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending StateUpdated message Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.193 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Payload message Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.194 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending FileAudioQualityChanged message Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.194 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Payload message Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.194 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending DeviceAudioQualityChanged message Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 35 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 33 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 32 milliseconds Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.195 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Payload message Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 28 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 27 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand status took 25 milliseconds Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.199 [1595.1595] INFO SampleApp: Playback volume changed: 76 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.199 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Volume changed: 76 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.199 [1595.1595] INFO QConnectMessageSender: [0x1f70778]: Sending VolumeChanged message Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.199 [1595.1595] INFO QwspMessageSender: [0x1f70768]: Sending Payload message Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseState Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 115ms Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: info: sendMpdCommand playlistinfo took 30 milliseconds Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ControllerMpd::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:27:36 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:27:36 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 169ms Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 168ms Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 166ms Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 166ms Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 164ms Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 163ms Jun 13 18:27:36 raspamp volumio[835]: info: ------------------------------ 162ms Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:27:36 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.466 [1595.1595] INFO UrlAudioSource: [0x2122278]: Content info extracted Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.466 [1595.1595] INFO UrlAudioSource: [0x2122278]: Size: 17496509 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.472 [1595.8251] INFO AudioDecoder: [0x1defad0]: Stream info: Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.472 [1595.8251] INFO AudioDecoder: [0x1defad0]: Total samples: 6494460 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.472 [1595.8251] INFO AudioDecoder: [0x1defad0]: Sample rate: 44100 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.472 [1595.8251] INFO AudioDecoder: [0x1defad0]: Channel count: 2 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.472 [1595.8251] INFO AudioDecoder: [0x1defad0]: Bits per sample: 16 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.472 [1595.8251] INFO AudioDecoder: [0x1defad0]: Duration: 147266 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.475 [1595.1595] INFO UrlAudioSource: [0x2122278]: Audio properties have changed Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.475 [1595.1595] INFO UrlAudioSource: [0x2122278]: Seeking input stream to byte offset: 17489117 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.475 [1595.1595] INFO ContentFetcher: [0x1f39ca8]: Adjusting download offset to: 17489117 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.699 [1595.1595] INFO UrlAudioSource: [0x2122278]: Seeking input stream to byte offset: 17494752 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.699 [1595.1595] INFO ContentFetcher: [0x1f39ca8]: Adjusting download offset to: 17494752 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.725 [1595.1595] INFO UrlAudioSource: [0x2122278]: Seeking input stream to byte offset: 17496282 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.725 [1595.1595] INFO ContentFetcher: [0x1f39ca8]: Adjusting download offset to: 17496282 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.951 [1595.1595] INFO UrlAudioSource: [0x2122278]: Seeking input stream to byte offset: 17496482 Jun 13 18:27:36 raspamp qobuz-connect[1595]: 20250613 18:27:36.951 [1595.1595] INFO ContentFetcher: [0x1f39ca8]: Adjusting download offset to: 17496482 Jun 13 18:27:38 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 13 18:27:38 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 13 18:27:38 raspamp volumio[835]: info: Discovery: Getting this device information Jun 13 18:27:38 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:38 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.210 [1595.1595] ERROR ProtocolHandler: [0x1d57db0]: Received QConnect.Error message: Message too old for connectionId: IAAAAAABXT6i, age: 3900ms, currentInstant: 11993, msgInstant: 11954 (code 1003) Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.215 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received QWSP.Disconnect message (reconnect: 0) Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.215 [1595.1595] INFO CloudClient: [0x1d57c48]: Disconnecting from the cloud Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.215 [1595.1595] INFO CloudClient: [0x1d57c48]: Connection closed Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO PlaybackSessionManager: [0x1d573d8]: Stopping playback session maintenance Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO ActiveStateManager: [0x1d56000]: Setting new active state: inactive Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO MediaEngine: [0x1d57670]: Stopping playback, clearing tracks Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO MediaEngine: [0x1d57670]: Reseting Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO SampleApp: Renderer is now inactive Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO AudioRenderer: [0x1d57890]: Stopping audio renderer Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.226 [1595.1595] INFO SampleApp: Stopping playback Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.231 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Clearing all streams Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.231 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 3]: Disposing of audio stream Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.231 [1595.1595] INFO ContentFetcher: [0x1f39ca8]: Canceling download Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.232 [1595.1595] INFO SampleApp: Playback state changed: Stopped Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.232 [1595.1595] INFO SampleApp: [Stream 3]: Audio stream has been disposed of Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.233 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting current track: NONE Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.233 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting next track: NONE Jun 13 18:27:40 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.234 [1595.1595] INFO EndpointManager: [0x1d56fe8]: API endpoint has been cleared Jun 13 18:27:40 raspamp qobuz-connect[1595]: 20250613 18:27:40.234 [1595.1595] INFO EndpointManager: [0x1d56fe8]: QConnect endpoint has been cleared Jun 13 18:27:42 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:42 raspamp volumio[835]: info: Listing playlists Jun 13 18:27:42 raspamp volumio[835]: info: Listing playlists Jun 13 18:27:52 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:27:57 raspamp kernel: hwmon hwmon1: Voltage normalised Jun 13 18:27:58 raspamp go-librespot[1157]: time="2025-06-13T18:27:58+02:00" level=trace msg="sent dealer ping" Jun 13 18:27:58 raspamp go-librespot[1157]: time="2025-06-13T18:27:58+02:00" level=trace msg="received dealer pong" Jun 13 18:27:59 raspamp kernel: hwmon hwmon1: Undervoltage detected! Jun 13 18:28:02 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:02 raspamp volumio[835]: info: Listing playlists Jun 13 18:28:02 raspamp volumio[835]: info: Listing playlists Jun 13 18:28:03 raspamp kernel: hwmon hwmon1: Voltage normalised Jun 13 18:28:05 raspamp kernel: hwmon hwmon1: Undervoltage detected! Jun 13 18:28:12 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:18 raspamp qobuz-connect[1595]: 20250613 18:28:18.958 [1595.3968] INFO SampleApp: API endpoint invoked: get-connect-info Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.137 [1595.3968] INFO SampleApp: API endpoint invoked: connect-to-qconnect Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.137 [1595.1595] INFO EndpointManager: [0x1d56fe8]: Updating API endpoint Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.137 [1595.1595] INFO EndpointManager: [0x1d56fe8]: Updating QConnect endpoint Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.137 [1595.1595] INFO ActiveStateManager: [0x1d56000]: Setting new active state: active Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.137 [1595.1595] INFO PlaybackSessionManager: [0x1d573d8]: Starting playback session maintenance Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.137 [1595.1595] INFO CloudClient: [0x1d57c48]: Connecting to the cloud Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.138 [1595.1595] INFO SampleApp: Renderer is now active Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.354 [1595.1595] INFO CloudClient: [0x1d57c48]: Connection established Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.354 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Authenticate message Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.354 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Subscribe message Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.355 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending JoinSession message Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.355 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending VolumeChanged message Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.355 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending VolumeMuted message Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.355 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending MaxAudioQualityChanged message Jun 13 18:28:19 raspamp qobuz-connect[1595]: 20250613 18:28:19.355 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.097 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetActive message: active Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.097 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetState message: Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Playing state: Playing Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Playback position: 1000 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Queue version: 5.1 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Current track: TID: 39440024, QID: 0, Context UUID: a91cd721-a890-4ce4-a801-9effab942033 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Next track: TID: 4294967295, QID: -1, Context UUID: Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO MediaEngine: [0x1d57670]: Stopping playback, clearing tracks Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO MediaEngine: [0x1d57670]: Initiating playback Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO RendererActionAvailabilityManager: [0x1d57d00]: Renderer action 'Next' is not available Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetLoopMode message: Off Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO PlaybackControlsManager: [0x1d57a48]: Setting new loop mode: Off Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting current track: 39440024, initial offset: 1000ms Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Clearing all streams Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.098 [1595.1595] INFO AudioStreamManager: [0x1d57758]: New stream: 5 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.099 [1595.1595] INFO HttpDownloader: [0x1f62018]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=3be1188943d4dd90345d5b8ed0a28f53&request_ts=1749832101&track_id=39440024 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.099 [1595.1595] INFO HttpDownloader: [0x21c47b8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=39440024 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.099 [1595.1595] INFO HttpDownloader: [0x21c23a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=41fddb6861fbc49acd453004215acabf&request_ts=1749832101&track_id=39440024 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.099 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 5]: Running audio stream Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.099 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetShuffleMode message: disabled Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.099 [1595.1595] INFO PlaybackControlsManager: [0x1d57a48]: Setting new shuffle mode: disabled Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.101 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting next track: NONE Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.101 [1595.1595] INFO MediaEngine: [0x1d57670]: Waiting for current stream to start before starting audio renderer Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 13 18:28:21 raspamp volumio[835]: info: Discovery: Getting this device information Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 13 18:28:21 raspamp volumio[835]: info: Discovery: Getting this device information Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.262 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 5]: Metadata became available: Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.262 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Title: Manitoumani Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.263 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Artist: Lamomali Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.263 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album: Lamomali Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.263 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album art URL: https://static.qobuz.com/images/covers/26/80/3596973448026_600.jpg Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.268 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 5]: stream information have been fetched Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.369 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 5]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=39440024&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835701&hmac=FLU-nmWzlNz7BU9mAo3iGAS3Frw Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.370 [1595.1595] INFO UrlAudioSource: [0x22db320]: Starting URL audio source, initial position: 1000ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=39440024&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835701&hmac=FLU-nmWzlNz7BU9mAo3iGAS3Frw Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.370 [1595.1595] INFO ContentFetcher: [0x1db8af8]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=39440024&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835701&hmac=FLU-nmWzlNz7BU9mAo3iGAS3Frw, offset: 0 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.371 [1595.1595] INFO AudioRenderer: [0x1d57890]: Starting audio renderer, initial playback state: Playing Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.371 [1595.1595] INFO SampleApp: [Stream 5]: New audio stream (starting from 1000ms) Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.371 [1595.1595] INFO SampleApp: [Stream 5]: Stream metadata became available: Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.371 [1595.1595] INFO SampleApp: Title: Manitoumani Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.371 [1595.1595] INFO SampleApp: Artist: Lamomali Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.371 [1595.1595] INFO SampleApp: Album: Lamomali Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.372 [1595.1595] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/26/80/3596973448026_600.jpg Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: QobuzConnect: setActiveState() Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: QobuzConnect: Set Qobuz connect default volume to 76 Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.376 [1595.1595] INFO VolumeManager: [0x1d57ad8]: Setting new playback volume: 76 Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: QobuzConnect: Stopping currently active service Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioStop Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::stop Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::serviceStop Jun 13 18:28:21 raspamp volumio[835]: info: Received STOP, but no service to execute it Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CorePlayQueue::getTrack 0 Jun 13 18:28:21 raspamp volumio[835]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received qobuzconnect Jun 13 18:28:21 raspamp volumio[835]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect Jun 13 18:28:21 raspamp volumio[835]: info: QobuzConnect: setActiveState() completed, send playback confirmation Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.393 [1595.1595] INFO SampleApp: Initiating playback, initial state: Playing Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.432 [1595.1595] INFO SampleApp: Playback state changed: Playing Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.432 [1595.1595] INFO StreamingEventReporter: [0x1d581c8]: Reporting streaming started event Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.433 [1595.1595] INFO HttpDownloader: [0x1d58220]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.433 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Need to send state update Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.433 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending StateUpdated message Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.433 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.435 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending FileAudioQualityChanged message Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.435 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.435 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending DeviceAudioQualityChanged message Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.436 [1595.1595] INFO UrlAudioSource: [0x22db320]: Content info extracted Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.436 [1595.1595] INFO UrlAudioSource: [0x22db320]: Size: 73372100 Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.439 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.442 [1595.8370] INFO AudioDecoder: [0x1d893b8]: Stream info: Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.442 [1595.8370] INFO AudioDecoder: [0x1d893b8]: Total samples: 20007680 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.442 [1595.8370] INFO AudioDecoder: [0x1d893b8]: Sample rate: 96000 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.442 [1595.8370] INFO AudioDecoder: [0x1d893b8]: Channel count: 2 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.442 [1595.8370] INFO AudioDecoder: [0x1d893b8]: Bits per sample: 24 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.443 [1595.8370] INFO AudioDecoder: [0x1d893b8]: Duration: 208413 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.444 [1595.1595] INFO UrlAudioSource: [0x22db320]: Audio properties have changed Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.445 [1595.1595] INFO UrlAudioSource: [0x22db320]: Seeking input stream to byte offset: 303106 Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.445 [1595.1595] INFO ContentFetcher: [0x1db8af8]: Adjusting download offset to: 303106 Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp qobuz-connect[1595]: 20250613 18:28:21.459 [1595.1595] INFO VolumeManager: [0x1d57ad8]: Setting new playback volume: 76 Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:21 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:21 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:21 raspamp volumio[835]: info: [LastFM] Current track has sufficient metadata: title (Manitoumani) and artist (Lamomali) passed on explicitly Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:28:21 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:28:21 raspamp volumio[835]: verbose: New Socket.io Connection to 192.168.72.162:3000 from 192.168.72.230 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Jun 13 18:28:21 raspamp volumio[835]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Manitoumani","url":"https://www.last.fm/music/Lamomali/_/Manitoumani","duration":"208000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"2422","playcount":"4797","artist":{"name":"Lamomali","url":"https://www.last.fm/music/Lamomali"},"userplaycount":"1","userloved":"0","toptags":""}} Jun 13 18:28:22 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:22 raspamp volumio[835]: info: Listing playlists Jun 13 18:28:22 raspamp volumio[835]: info: Listing playlists Jun 13 18:28:28 raspamp go-librespot[1157]: time="2025-06-13T18:28:28+02:00" level=trace msg="sent dealer ping" Jun 13 18:28:28 raspamp go-librespot[1157]: time="2025-06-13T18:28:28+02:00" level=trace msg="received dealer pong" Jun 13 18:28:31 raspamp qobuz-connect[1595]: 20250613 18:28:31.432 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Need to send state update Jun 13 18:28:31 raspamp qobuz-connect[1595]: 20250613 18:28:31.432 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending StateUpdated message Jun 13 18:28:31 raspamp qobuz-connect[1595]: 20250613 18:28:31.432 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:31 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:31 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:31 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:31 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:31 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:31 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:31 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:31 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:31 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Jun 13 18:28:31 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:28:31 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 76 Jun 13 18:28:31 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 13 18:28:32 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:34 raspamp qobuz-connect[1595]: 20250613 18:28:34.843 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetVolume message, volume: 79 Jun 13 18:28:34 raspamp qobuz-connect[1595]: 20250613 18:28:34.843 [1595.1595] INFO VolumeManager: [0x1d57ad8]: Setting new playback volume: 79 Jun 13 18:28:34 raspamp qobuz-connect[1595]: 20250613 18:28:34.993 [1595.1595] INFO SampleApp: Playback volume changed: 79 Jun 13 18:28:34 raspamp qobuz-connect[1595]: 20250613 18:28:34.993 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Volume changed: 79 Jun 13 18:28:34 raspamp qobuz-connect[1595]: 20250613 18:28:34.993 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending VolumeChanged message Jun 13 18:28:34 raspamp qobuz-connect[1595]: 20250613 18:28:34.994 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:34 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:34 raspamp volumio[835]: info: QobuzConnect: Volume received from daemon: 79 Jun 13 18:28:34 raspamp volumio[835]: info: VolumeController::SetAlsaVolume79 Jun 13 18:28:35 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:35 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:35 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:35 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:35 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:35 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:35 raspamp qobuz-connect[1595]: 20250613 18:28:35.060 [1595.1595] INFO VolumeManager: [0x1d57ad8]: Setting new playback volume: 79 Jun 13 18:28:35 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Jun 13 18:28:35 raspamp volumio[835]: SPOTIFY: SPOTIFY VOLUME 77 Jun 13 18:28:35 raspamp volumio[835]: SPOTIFY: VOLUMIO VOLUME 79 Jun 13 18:28:35 raspamp volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: true Jun 13 18:28:35 raspamp volumio[835]: info: Setting Spotify Volume from Volumio: 79 Jun 13 18:28:36 raspamp volumio[835]: SPOTIFY: SETTING SPOTIFY VOLUME 79 Jun 13 18:28:36 raspamp volumio[835]: info: Sending Spotify command with payload to local API: /player/volume Jun 13 18:28:36 raspamp go-librespot[1157]: time="2025-06-13T18:28:36+02:00" level=debug msg="update volume to 51772/65535" Jun 13 18:28:37 raspamp go-librespot[1157]: time="2025-06-13T18:28:37+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 13 18:28:37 raspamp go-librespot[1157]: time="2025-06-13T18:28:37+02:00" level=trace msg="emitting websocket event: volume" Jun 13 18:28:37 raspamp volumio[835]: SPOTIFY: received: {"type":"volume","data":{"value":79,"max":100}} Jun 13 18:28:37 raspamp volumio[835]: SPOTIFY: RECEIVED SPOTIFY VOLUME 79 Jun 13 18:28:41 raspamp qobuz-connect[1595]: 20250613 18:28:41.432 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Need to send state update Jun 13 18:28:41 raspamp qobuz-connect[1595]: 20250613 18:28:41.432 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending StateUpdated message Jun 13 18:28:41 raspamp qobuz-connect[1595]: 20250613 18:28:41.432 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:41 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:41 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:41 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:41 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:41 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:41 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:41 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:41 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:41 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Jun 13 18:28:42 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:42 raspamp volumio[835]: info: Listing playlists Jun 13 18:28:42 raspamp volumio[835]: info: Listing playlists Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.653 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Received SetState message: Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.653 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Playing state: Playing Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Playback position: 0 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Queue version: 6.1 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Current track: TID: 39440024, QID: 0, Context UUID: 335ce0ab-c2e6-4405-bbbd-834ffe5e2986 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Next track: TID: 27496388, QID: 1, Context UUID: 335ce0ab-c2e6-4405-bbbd-834ffe5e2986 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO MediaEngine: [0x1d57670]: Stopping playback, clearing tracks Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO MediaEngine: [0x1d57670]: Initiating playback Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO AudioRenderer: [0x1d57890]: Stopping audio renderer Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO RendererActionAvailabilityManager: [0x1d57d00]: Renderer action 'Next' is available Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.654 [1595.1595] INFO SampleApp: Stopping playback Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.660 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Clearing all streams Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.660 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 5]: Disposing of audio stream Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.660 [1595.1595] INFO ContentFetcher: [0x1db8af8]: Canceling download Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.674 [1595.1595] INFO SampleApp: Playback state changed: Stopped Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.674 [1595.1595] INFO StreamingEventReporter: [0x1d581c8]: Reporting streaming ended event Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.675 [1595.1595] INFO HttpDownloader: [0x1d58220]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.675 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Need to send state update Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.675 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending StateUpdated message Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.675 [1595.1595] INFO SampleApp: [Stream 5]: Audio stream has been disposed of Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting current track: 39440024, initial offset: 0ms Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Clearing all streams Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO AudioStreamManager: [0x1d57758]: New stream: 6 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO HttpDownloader: [0x1db7b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=18e4eb00c613686ee27ef06d532caa4b&request_ts=1749832129&track_id=39440024 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO HttpDownloader: [0x2113888]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=39440024 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO HttpDownloader: [0x207c250]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=b712fe65d340dc047b0d521f5c696ada&request_ts=1749832129&track_id=39440024 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.676 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 6]: Running audio stream Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.677 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.681 [1595.1595] INFO MediaEngine: [0x1d57670]: Setting next track: 27496388 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.681 [1595.1595] INFO AudioStreamManager: [0x1d57758]: New stream: 7 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.681 [1595.1595] INFO HttpDownloader: [0x1da89b0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d0cdfec00c0486495a92e3056c322abf&request_ts=1749832129&track_id=27496388 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.681 [1595.1595] INFO HttpDownloader: [0x1e31b30]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=27496388 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.681 [1595.1595] INFO HttpDownloader: [0x1f3c228]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=c8a314c29bf754f6ba61ee9a57d4d8e5&request_ts=1749832129&track_id=27496388 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.684 [1595.1595] INFO MediaEngine: [0x1d57670]: Waiting for current stream to start before starting audio renderer Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Jun 13 18:28:49 raspamp volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.859 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 6]: stream information have been fetched Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.859 [1595.1595] INFO UrlAudioSource: [0x21c7ee8]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=39440024&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835729&hmac=nq0HSxarF4N9FXOSFrAM3Y6Md1U Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.860 [1595.1595] INFO ContentFetcher: [0x227a138]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=39440024&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835729&hmac=nq0HSxarF4N9FXOSFrAM3Y6Md1U, offset: 0 Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.860 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 7]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=27496388&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835729&hmac=kvsbwxykLOJCrRgQQ_pF3QmPSGE Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.860 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 6]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=496358&eid=39440024&fmt=7&profile=raw&app_id=174516466&cid=2725398&etsp=1749835729&hmac=nq0HSxarF4N9FXOSFrAM3Y6Md1U Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.860 [1595.1595] INFO AudioRenderer: [0x1d57890]: Starting audio renderer, initial playback state: Playing Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.860 [1595.1595] INFO SampleApp: [Stream 6]: New audio stream (starting from 0ms) Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: QobuzConnect: alread currrent service, send playback confirmation Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.864 [1595.1595] INFO SampleApp: Initiating playback, initial state: Playing Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.914 [1595.1595] INFO SampleApp: Playback state changed: Playing Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.914 [1595.1595] INFO StreamingEventReporter: [0x1d581c8]: Reporting streaming started event Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.915 [1595.1595] INFO HttpDownloader: [0x1d58220]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.915 [1595.1595] INFO ProtocolHandler: [0x1d57db0]: Need to send state update Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.915 [1595.1595] INFO QConnectMessageSender: [0x1df4ed8]: Sending StateUpdated message Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.915 [1595.1595] INFO QwspMessageSender: [0x1df4ec8]: Sending Payload message Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.918 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 7]: Metadata became available: Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.918 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Title: Tais-toi Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.918 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Artist: Zazie Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.918 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album: Encore heureux Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.918 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album art URL: https://static.qobuz.com/images/covers/56/29/0060254762956_600.jpg Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:49 raspamp qobuz-connect[1595]: 20250613 18:28:49.941 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 7]: stream information have been fetched Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::servicePushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreStateMachine::pushState Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioPushState Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output update for this device Jun 13 18:28:49 raspamp volumio[835]: info: MRS: Pushing multiroomSync output Jun 13 18:28:49 raspamp volumio[835]: info: CoreCommandRouter::volumioGetState Jun 13 18:28:49 raspamp volumio[835]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Jun 13 18:28:50 raspamp volumio[835]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 13 18:28:50 raspamp volumio[835]: TypeError: Cannot read property 'indexOf' of undefined Jun 13 18:28:50 raspamp volumio[835]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Jun 13 18:28:50 raspamp volumio[835]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Jun 13 18:28:50 raspamp volumio[835]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Jun 13 18:28:50 raspamp volumio[835]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Jun 13 18:28:50 raspamp volumio[835]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Jun 13 18:28:50 raspamp volumio[835]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Jun 13 18:28:50 raspamp volumio[835]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Jun 13 18:28:50 raspamp volumio[835]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Jun 13 18:28:50 raspamp volumio[835]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Jun 13 18:28:50 raspamp volumio[835]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Jun 13 18:28:50 raspamp volumio[835]: at Decoder.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Jun 13 18:28:50 raspamp volumio[835]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Jun 13 18:28:50 raspamp volumio[835]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Jun 13 18:28:50 raspamp volumio[835]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Jun 13 18:28:50 raspamp volumio[835]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Jun 13 18:28:50 raspamp volumio[835]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Jun 13 18:28:50 raspamp volumio[835]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.136 [1595.1595] INFO AudioStreamManager: [0x1d57758]: [Stream 6]: Metadata became available: Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Title: Manitoumani Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Artist: Lamomali Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album: Lamomali Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO AudioStreamManager: [0x1d57758]: Album art URL: https://static.qobuz.com/images/covers/26/80/3596973448026_600.jpg Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO SampleApp: [Stream 6]: Stream metadata became available: Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO SampleApp: Title: Manitoumani Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO SampleApp: Artist: Lamomali Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO SampleApp: Album: Lamomali Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.137 [1595.1595] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/26/80/3596973448026_600.jpg Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.156 [1595.1595] INFO UrlAudioSource: [0x21c7ee8]: Content info extracted Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.156 [1595.1595] INFO UrlAudioSource: [0x21c7ee8]: Size: 73372100 Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.159 [1595.8416] INFO AudioDecoder: [0x23a4d80]: Stream info: Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.159 [1595.8416] INFO AudioDecoder: [0x23a4d80]: Total samples: 20007680 Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.159 [1595.8416] INFO AudioDecoder: [0x23a4d80]: Sample rate: 96000 Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.159 [1595.8416] INFO AudioDecoder: [0x23a4d80]: Channel count: 2 Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.159 [1595.8416] INFO AudioDecoder: [0x23a4d80]: Bits per sample: 24 Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.159 [1595.8416] INFO AudioDecoder: [0x23a4d80]: Duration: 208413 Jun 13 18:28:50 raspamp qobuz-connect[1595]: 20250613 18:28:50.160 [1595.1595] INFO UrlAudioSource: [0x21c7ee8]: Audio properties have changed Jun 13 18:28:51 raspamp sudo[8433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-13 18:27 Jun 13 18:28:51 raspamp sudo[8433]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"