-- Logs begin at Fri 2025-12-26 21:54:19 CET, end at Sat 2025-12-27 00:49:39 CET. --
Dec 27 00:48:36 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 27 00:48:36 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 27 00:48:36 primo volumio[3401]: info: Discovery: Getting this device information
Dec 27 00:48:36 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:48:36 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 27 00:48:36 primo volumio[3401]: verbose: New Socket.io Connection to 192.168.178.116:3000 from 192.168.178.110 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12
Dec 27 00:48:36 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Dec 27 00:48:36 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 27 00:48:55 primo volumio[3401]: info: Discovery: Getting this device information
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 27 00:48:55 primo volumio[3401]: verbose: New Socket.io Connection to 192.168.178.122:3000 from 192.168.178.110 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12
Dec 27 00:48:55 primo qobuz-connect[3938]: 20251227 00:48:55.427 [3938.4027] INFO SampleApp: API endpoint invoked: get-display-info
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Dec 27 00:48:55 primo qobuz-connect[3938]: 20251227 00:48:55.454 [3938.4027] INFO SampleApp: API endpoint invoked: get-connect-info
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 27 00:48:55 primo volumio[3401]: info: Discovery: Getting this device information
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 27 00:48:55 primo volumio[3401]: verbose: New Socket.io Connection to 192.168.178.116:3000 from 192.168.178.110 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Dec 27 00:48:55 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Dec 27 00:48:56 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 27 00:48:56 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 27 00:48:56 primo volumio[3401]: info: Discovery: Getting this device information
Dec 27 00:48:56 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:48:56 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 27 00:48:56 primo volumio[3401]: verbose: New Socket.io Connection to 192.168.178.122:3000 from 192.168.178.110 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12
Dec 27 00:48:56 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Dec 27 00:48:56 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.854 [3938.4027] INFO SampleApp: API endpoint invoked: connect-to-qconnect
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.854 [3938.3938] INFO EndpointManager: [0xab839ec8]: Updating API endpoint
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.854 [3938.3938] INFO EndpointManager: [0xab839ec8]: Updating QConnect endpoint
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.854 [3938.3938] INFO ActiveStateManager: [0xab838ee0]: Setting new active state: active
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.855 [3938.3938] INFO PlaybackSessionManager: [0xab83a2b8]: Starting playback session maintenance
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.855 [3938.3938] INFO HttpDownloader: [0xab83a4a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/session/start
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.855 [3938.3938] INFO CloudClient: [0xab83ab28]: Connecting to the cloud
Dec 27 00:49:00 primo qobuz-connect[3938]: 20251227 00:49:00.856 [3938.3938] INFO SampleApp: Renderer is now active
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.104 [3938.3938] INFO PlaybackSessionManager: [0xab83a2b8]: Playback session has been refreshed
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO CloudClient: [0xab83ab28]: Connection established
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Authenticate message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Subscribe message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending JoinSession message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending VolumeChanged message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending VolumeMuted message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.108 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending MaxAudioQualityChanged message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.109 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.179 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetActive message: active
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.179 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetState message:
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.179 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playing state: Paused
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playback position: 9574548
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Queue version: 3.4
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Current track: TID: 3132161, QID: 4, Context UUID: 73aa88b2-9c26-4cd1-8383-fe8639a3da22
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Next track: TID: 3132162, QID: 5, Context UUID: 73aa88b2-9c26-4cd1-8383-fe8639a3da22
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO MediaEngine: [0xab83a550]: Stopping playback, clearing tracks
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO MediaEngine: [0xab83a550]: Initiating playback
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO RendererActionAvailabilityManager: [0xab83abe0]: Renderer action 'Next' is available
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetLoopMode message: Off
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO PlaybackControlsManager: [0xab83a928]: Setting new loop mode: Off
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO MediaEngine: [0xab83a550]: Setting current track: 3132161, initial offset: 9574548ms
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Clearing all streams
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO AudioStreamManager: [0xab83a638]: New stream: 1
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO HttpDownloader: [0xab846618]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=1dee255b04caed215b22a2a330f3cac8&request_ts=1766792941&track_id=3132161
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.180 [3938.3938] INFO HttpDownloader: [0xab840e70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=3132161
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.181 [3938.3938] INFO HttpDownloader: [0xab8465d8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=20064989dd1ba8c39f5b5cfe1154df82&request_ts=1766792941&track_id=3132161
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.181 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 1]: Running audio stream
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.181 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetShuffleMode message: disabled
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.181 [3938.3938] INFO PlaybackControlsManager: [0xab83a928]: Setting new shuffle mode: disabled
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.182 [3938.3938] INFO MediaEngine: [0xab83a550]: Setting next track: 3132162
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.182 [3938.3938] INFO AudioStreamManager: [0xab83a638]: New stream: 2
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.183 [3938.3938] INFO HttpDownloader: [0xab91aae8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=404d17a28a92b6a020b2ccee21d473a9&request_ts=1766792941&track_id=3132162
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.183 [3938.3938] INFO HttpDownloader: [0xab91a6f0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=3132162
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.183 [3938.3938] INFO HttpDownloader: [0xab91c978]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=bb8bc07228f924ee329d2c012d2cfaf7&request_ts=1766792941&track_id=3132162
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.184 [3938.3938] INFO MediaEngine: [0xab83a550]: Waiting for current stream to start before starting audio renderer
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.267 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 2]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=3132162&fmt=6&profile=raw&app_id=174516466&cid=2060322&etsp=1766796541&hmac=08cJtfaRs6IPKAXo1J26AHXEyJM
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.270 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 1]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=3132161&fmt=6&profile=raw&app_id=174516466&cid=2060322&etsp=1766796541&hmac=NJqvM_aVFAQDrTpBiRMMr-0kFBI
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.285 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 1]: Metadata became available:
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.286 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Title: All And Everyone
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.286 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Artist: PJ Harvey
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.286 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album: Let England Shake
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.286 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album art URL: https://static.qobuz.com/images/covers/60/26/0060252762660_600.jpg
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.313 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 2]: Metadata became available:
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.313 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Title: On Battleship Hill
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.314 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Artist: PJ Harvey
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.314 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album: Let England Shake
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.314 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album art URL: https://static.qobuz.com/images/covers/60/26/0060252762660_600.jpg
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.352 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 2]: stream information have been fetched
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.416 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 1]: stream information have been fetched
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.416 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Starting URL audio source, initial position: 9574548ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=3132161&fmt=6&profile=raw&app_id=174516466&cid=2060322&etsp=1766796541&hmac=NJqvM_aVFAQDrTpBiRMMr-0kFBI
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.417 [3938.3938] INFO ContentFetcher: [0xab91ae78]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=3132161&fmt=6&profile=raw&app_id=174516466&cid=2060322&etsp=1766796541&hmac=NJqvM_aVFAQDrTpBiRMMr-0kFBI, offset: 0
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.417 [3938.3938] INFO AudioRenderer: [0xab83a770]: Starting audio renderer, initial playback state: Paused
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.417 [3938.3938] INFO SampleApp: [Stream 1]: New audio stream (starting from 9574547ms)
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.417 [3938.3938] INFO SampleApp: [Stream 1]: Stream metadata became available:
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.417 [3938.3938] INFO SampleApp: Title: All And Everyone
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.417 [3938.3938] INFO SampleApp: Artist: PJ Harvey
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.418 [3938.3938] INFO SampleApp: Album: Let England Shake
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.418 [3938.3938] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/60/26/0060252762660_600.jpg
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: QobuzConnect: setActiveState()
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: QobuzConnect: Set Qobuz connect default volume to 42
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.429 [3938.3938] INFO VolumeManager: [0xab83a9b8]: Setting new playback volume: 42
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: QobuzConnect: Stopping currently active service
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioStop
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::stop
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::stPlaybackTimer
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::updateTrackBlock
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrackBlock
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::serviceStop
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::serviceStop
Dec 27 00:49:01 primo volumio[3401]: info: [1766792941453] ControllerQobuz::stop
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::setConsumeUpdateService mpd
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::stop
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand stop
Dec 27 00:49:01 primo kernel: asoc-aml-card auge_sound: tdm playback stop
Dec 27 00:49:01 primo kernel: spdif_a is set to disable
Dec 27 00:49:01 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:01 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B
Dec 27 00:49:01 primo kernel: tdm playback mute: 1, lane_cnt = 8
Dec 27 00:49:01 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1
Dec 27 00:49:01 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:01 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:01 primo volumio[3401]: info:
Dec 27 00:49:01 primo volumio[3401]: ---------------------------- MPD announces state update: player
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand stop took 57 milliseconds
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::getState
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand status
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received qobuzconnect
Dec 27 00:49:01 primo volumio[3401]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect
Dec 27 00:49:01 primo volumio[3401]: info: QobuzConnect: setActiveState() completed, send playback confirmation
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:01 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:01.570+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.178.110:57474
Dec 27 00:49:01 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:01.570+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.178.110:57474
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand status took 60 milliseconds
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::parseState
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 27 00:49:01 primo volumio[3401]: info:
Dec 27 00:49:01 primo volumio[3401]: ---------------------------- MPD announces state update: player
Dec 27 00:49:01 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:01.586+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.178.110:50998
Dec 27 00:49:01 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:01.586+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.178.110:50998
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::getState
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand status
Dec 27 00:49:01 primo volumio[3401]: info:
Dec 27 00:49:01 primo volumio[3401]: ---------------------------- MPD announces state update: player
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::getState
Dec 27 00:49:01 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:01.593+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.178.110:33022
Dec 27 00:49:01 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:01.595+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.178.110:42316
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand status
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand playlistinfo took 17 milliseconds
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand status took 8 milliseconds
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand status took 5 milliseconds
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::parseTrackInfo
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::parseState
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::parseState
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.617 [3938.3938] INFO SampleApp: Initiating playback, initial state: Paused
Dec 27 00:49:01 primo volumio[3401]: info: ------------------------------ 108ms
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand playlistinfo took 28 milliseconds
Dec 27 00:49:01 primo volumio[3401]: info: sendMpdCommand playlistinfo took 28 milliseconds
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::parseTrackInfo
Dec 27 00:49:01 primo volumio[3401]: verbose: ControllerMpd::parseTrackInfo
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd
Dec 27 00:49:01 primo volumio[3401]: info: ControllerMpd::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:01 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:01 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:01 primo volumio[3401]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd
Dec 27 00:49:01 primo volumio[3401]: info: ------------------------------ 83ms
Dec 27 00:49:01 primo volumio[3401]: info: ------------------------------ 77ms
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:01 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:01 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:01 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:01 primo kernel: aml_tdm_open
Dec 27 00:49:01 primo kernel: Not init audio effects
Dec 27 00:49:01 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:01 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:01 primo qobuz-connect[3938]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 65536
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo qobuz-connect[3938]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 131072, but target_pcm volumioOutput has buffer size 65536
Dec 27 00:49:01 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1
Dec 27 00:49:01 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk
Dec 27 00:49:01 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk
Dec 27 00:49:01 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186
Dec 27 00:49:01 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d123a18, id(1), clksel(1)
Dec 27 00:49:01 primo kernel: aml_dai_set_tdm_fmt(), fmt not change
Dec 27 00:49:01 primo kernel: dump_pcm_setting(ffffffc03d123a18)
Dec 27 00:49:01 primo kernel: pcm_mode(1)
Dec 27 00:49:01 primo kernel: sysclk(11289600)
Dec 27 00:49:01 primo kernel: sysclk_bclk_ratio(4)
Dec 27 00:49:01 primo kernel: bclk(2822400)
Dec 27 00:49:01 primo kernel: bclk_lrclk_ratio(64)
Dec 27 00:49:01 primo kernel: lrclk(44100)
Dec 27 00:49:01 primo kernel: tx_mask(0x3)
Dec 27 00:49:01 primo kernel: rx_mask(0x3)
Dec 27 00:49:01 primo kernel: slots(2)
Dec 27 00:49:01 primo kernel: slot_width(32)
Dec 27 00:49:01 primo kernel: lane_mask_in(0x2)
Dec 27 00:49:01 primo kernel: lane_mask_out(0x1)
Dec 27 00:49:01 primo kernel: lane_oe_mask_in(0x0)
Dec 27 00:49:01 primo kernel: lane_oe_mask_out(0x0)
Dec 27 00:49:01 primo kernel: lane_lb_mask_in(0x0)
Dec 27 00:49:01 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk
Dec 27 00:49:01 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk
Dec 27 00:49:01 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186
Dec 27 00:49:01 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1)
Dec 27 00:49:01 primo kernel: aml_dai_set_bclk_ratio, select I2S mode
Dec 27 00:49:01 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B
Dec 27 00:49:01 primo kernel: aml_tdm_prepare(), reset fddr
Dec 27 00:49:01 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10
Dec 27 00:49:01 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0
Dec 27 00:49:01 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:01 primo kernel: tdm playback mute: 0, lane_cnt = 8
Dec 27 00:49:01 primo kernel: aml_tdm_prepare(), reset fddr
Dec 27 00:49:01 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10
Dec 27 00:49:01 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0
Dec 27 00:49:01 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:01 primo kernel: tdm playback mute: 0, lane_cnt = 8
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.731 [3938.3938] INFO SampleApp: Playback volume changed: 42
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.731 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Volume changed: 42
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.731 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending VolumeChanged message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.731 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.732 [3938.3938] INFO SampleApp: Playback state changed: Paused
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.732 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.732 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.732 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.732 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending FileAudioQualityChanged message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.733 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.733 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending DeviceAudioQualityChanged message
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.733 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:01 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:01 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:01 primo volumio[3401]: info: MCU Signalled Playback Inactive
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.958 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Content info extracted
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.959 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Size: 33539883
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.961 [3938.19070] INFO AudioDecoder: [0xababc3e0]: Stream info:
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.961 [3938.19070] INFO AudioDecoder: [0xababc3e0]: Total samples: 14988708
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.961 [3938.19070] INFO AudioDecoder: [0xababc3e0]: Sample rate: 44100
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.961 [3938.19070] INFO AudioDecoder: [0xababc3e0]: Channel count: 2
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.961 [3938.19070] INFO AudioDecoder: [0xababc3e0]: Bits per sample: 16
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.961 [3938.19070] INFO AudioDecoder: [0xababc3e0]: Duration: 339880
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.963 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Audio properties have changed
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.963 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Seeking input stream to byte offset: 33532796
Dec 27 00:49:01 primo qobuz-connect[3938]: 20251227 00:49:01.963 [3938.3938] INFO ContentFetcher: [0xab91ae78]: Adjusting download offset to: 33532796
Dec 27 00:49:02 primo qobuz-connect[3938]: 20251227 00:49:02.454 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Seeking input stream to byte offset: 33538757
Dec 27 00:49:02 primo qobuz-connect[3938]: 20251227 00:49:02.454 [3938.3938] INFO ContentFetcher: [0xab91ae78]: Adjusting download offset to: 33538757
Dec 27 00:49:02 primo qobuz-connect[3938]: 20251227 00:49:02.564 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Seeking input stream to byte offset: 33539625
Dec 27 00:49:02 primo qobuz-connect[3938]: 20251227 00:49:02.564 [3938.3938] INFO ContentFetcher: [0xab91ae78]: Adjusting download offset to: 33539625
Dec 27 00:49:02 primo qobuz-connect[3938]: 20251227 00:49:02.686 [3938.3938] INFO UrlAudioSource: [0xab919ab8]: Seeking input stream to byte offset: 33539856
Dec 27 00:49:02 primo qobuz-connect[3938]: 20251227 00:49:02.686 [3938.3938] INFO ContentFetcher: [0xab91ae78]: Adjusting download offset to: 33539856
Dec 27 00:49:03 primo volumio[3401]: info: Executing endpoint metavolumio
Dec 27 00:49:03 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetState message:
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playing state: Playing
Dec 27 00:49:13 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:13 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B
Dec 27 00:49:13 primo kernel: tdm playback mute: 1, lane_cnt = 8
Dec 27 00:49:13 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playback position: 0
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Queue version: 4.1
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Current track: TID: 367340015, QID: 0, Context UUID: b673d299-0262-429a-8545-d7bfb03201ff
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Next track: TID: 326644748, QID: 1, Context UUID: b673d299-0262-429a-8545-d7bfb03201ff
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO MediaEngine: [0xab83a550]: Stopping playback, clearing tracks
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO MediaEngine: [0xab83a550]: Initiating playback
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.864 [3938.3938] INFO AudioRenderer: [0xab83a770]: Stopping audio renderer
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.865 [3938.3938] INFO SampleApp: Stopping playback
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.865 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Clearing all streams
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.865 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 1]: Disposing of audio stream
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.865 [3938.3938] INFO ContentFetcher: [0xab91ae78]: Canceling download
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO SampleApp: Playback state changed: Stopped
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO SampleApp: [Stream 1]: Audio stream has been disposed of
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO MediaEngine: [0xab83a550]: Setting current track: 367340015, initial offset: 0ms
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Clearing all streams
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO AudioStreamManager: [0xab83a638]: New stream: 3
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.866 [3938.3938] INFO HttpDownloader: [0xab91a968]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=f95dab6c78d20c97b6dc24fe574c45a2&request_ts=1766792953&track_id=367340015
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.867 [3938.3938] INFO HttpDownloader: [0xaba05550]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=367340015
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.867 [3938.3938] INFO HttpDownloader: [0xaba7dff0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=9561822a49fa337a1b227973270cbeac&request_ts=1766792953&track_id=367340015
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.867 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 3]: Running audio stream
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.867 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.869 [3938.3938] INFO MediaEngine: [0xab83a550]: Setting next track: 326644748
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.869 [3938.3938] INFO AudioStreamManager: [0xab83a638]: New stream: 4
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.869 [3938.3938] INFO HttpDownloader: [0xab9ed408]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=bc682e5f1c7c52e8ec91fa80dd01e977&request_ts=1766792953&track_id=326644748
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.869 [3938.3938] INFO HttpDownloader: [0xaba82520]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=326644748
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.869 [3938.3938] INFO HttpDownloader: [0xaba71a50]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=c422eb7f8fee373869376ee496c22167&request_ts=1766792953&track_id=326644748
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.870 [3938.3938] INFO MediaEngine: [0xab83a550]: Waiting for current stream to start before starting audio renderer
Dec 27 00:49:13 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.915 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 3]: Metadata became available:
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.915 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Title: La Perla
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.915 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Artist: ROSALÍA
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.915 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album: LUX
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.916 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album art URL: https://static.qobuz.com/images/covers/ic/cw/yhenlptipcwic_600.jpg
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.960 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 3]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=367340015&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796553&hmac=2FEtciAZ2FdW2aWbpF4eaZORTKo
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.968 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 4]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=326644748&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796553&hmac=5wXWB2d7yanLAs5WHpXxRMRfLZA
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.978 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 4]: Metadata became available:
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.978 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Title: Poor Side Of Town
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.978 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Artist: Bruce Springsteen
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.978 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album: Tracks II: The Lost Albums
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.979 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album art URL: https://static.qobuz.com/images/covers/sc/pr/xdvivhaouprsc_600.jpg
Dec 27 00:49:13 primo qobuz-connect[3938]: 20251227 00:49:13.992 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 4]: stream information have been fetched
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.005 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 3]: stream information have been fetched
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.005 [3938.3938] INFO UrlAudioSource: [0xab91ad58]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=367340015&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796553&hmac=2FEtciAZ2FdW2aWbpF4eaZORTKo
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.005 [3938.3938] INFO ContentFetcher: [0xaba77788]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=367340015&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796553&hmac=2FEtciAZ2FdW2aWbpF4eaZORTKo, offset: 0
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.005 [3938.3938] INFO AudioRenderer: [0xab83a770]: Starting audio renderer, initial playback state: Playing
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.005 [3938.3938] INFO SampleApp: [Stream 3]: New audio stream (starting from 0ms)
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.006 [3938.3938] INFO SampleApp: [Stream 3]: Stream metadata became available:
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.006 [3938.3938] INFO SampleApp: Title: La Perla
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.006 [3938.3938] INFO SampleApp: Artist: ROSALÍA
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.006 [3938.3938] INFO SampleApp: Album: LUX
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.006 [3938.3938] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/ic/cw/yhenlptipcwic_600.jpg
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: QobuzConnect: setActiveState()
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: QobuzConnect: Set Qobuz connect default volume to 42
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.009 [3938.3938] INFO VolumeManager: [0xab83a9b8]: Setting new playback volume: 42
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: QobuzConnect: Stopping currently active service
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioStop
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::stop
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::serviceStop
Dec 27 00:49:14 primo volumio[3401]: info: Received STOP, but no service to execute it
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.023 [3938.3938] INFO UrlAudioSource: [0xab91ad58]: Content info extracted
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.023 [3938.3938] INFO UrlAudioSource: [0xab91ad58]: Size: 68921965
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.19132] INFO AudioDecoder: [0xaba75df8]: Stream info:
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.19132] INFO AudioDecoder: [0xaba75df8]: Total samples: 18772480
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.19132] INFO AudioDecoder: [0xaba75df8]: Sample rate: 96000
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.19132] INFO AudioDecoder: [0xaba75df8]: Channel count: 2
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.19132] INFO AudioDecoder: [0xaba75df8]: Bits per sample: 24
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.19132] INFO AudioDecoder: [0xaba75df8]: Duration: 195546
Dec 27 00:49:14 primo volumio[3401]: info: CorePlayQueue::getTrack 6
Dec 27 00:49:14 primo volumio[3401]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received qobuzconnect
Dec 27 00:49:14 primo volumio[3401]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.024 [3938.3938] INFO UrlAudioSource: [0xab91ad58]: Audio properties have changed
Dec 27 00:49:14 primo volumio[3401]: info: QobuzConnect: setActiveState() completed, send playback confirmation
Dec 27 00:49:14 primo kernel: aml_tdm_open
Dec 27 00:49:14 primo kernel: Not init audio effects
Dec 27 00:49:14 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1
Dec 27 00:49:14 primo kernel: set mclk:24576000, mpll:49152000, get mclk:24575987, mpll:49151974
Dec 27 00:49:14 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d123a18, id(1), clksel(1)
Dec 27 00:49:14 primo kernel: aml_dai_set_tdm_fmt(), fmt not change
Dec 27 00:49:14 primo kernel: dump_pcm_setting(ffffffc03d123a18)
Dec 27 00:49:14 primo kernel: pcm_mode(1)
Dec 27 00:49:14 primo kernel: sysclk(24576000)
Dec 27 00:49:14 primo kernel: sysclk_bclk_ratio(4)
Dec 27 00:49:14 primo kernel: bclk(6144000)
Dec 27 00:49:14 primo kernel: bclk_lrclk_ratio(64)
Dec 27 00:49:14 primo kernel: lrclk(96000)
Dec 27 00:49:14 primo kernel: tx_mask(0x3)
Dec 27 00:49:14 primo kernel: rx_mask(0x3)
Dec 27 00:49:14 primo kernel: slots(2)
Dec 27 00:49:14 primo kernel: slot_width(32)
Dec 27 00:49:14 primo kernel: lane_mask_in(0x2)
Dec 27 00:49:14 primo kernel: lane_mask_out(0x1)
Dec 27 00:49:14 primo kernel: lane_oe_mask_in(0x0)
Dec 27 00:49:14 primo kernel: lane_oe_mask_out(0x0)
Dec 27 00:49:14 primo kernel: lane_lb_mask_in(0x0)
Dec 27 00:49:14 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk
Dec 27 00:49:14 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk
Dec 27 00:49:14 primo kernel: set mclk:24576000, mpll:49152000, get mclk:24575987, mpll:49151974
Dec 27 00:49:14 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1)
Dec 27 00:49:14 primo kernel: aml_dai_set_bclk_ratio, select I2S mode
Dec 27 00:49:14 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B
Dec 27 00:49:14 primo kernel: aml_tdm_prepare(), reset fddr
Dec 27 00:49:14 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10
Dec 27 00:49:14 primo kernel: spdif_info: rate: 96000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xa00, ch1_r:0xa00
Dec 27 00:49:14 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:14 primo kernel: tdm playback mute: 0, lane_cnt = 8
Dec 27 00:49:14 primo kernel: aml_tdm_prepare(), reset fddr
Dec 27 00:49:14 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10
Dec 27 00:49:14 primo kernel: spdif_info: rate: 96000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xa00, ch1_r:0xa00
Dec 27 00:49:14 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:14 primo kernel: tdm playback mute: 0, lane_cnt = 8
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.035 [3938.3938] INFO SampleApp: Initiating playback, initial state: Playing
Dec 27 00:49:14 primo qobuz-connect[3938]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768
Dec 27 00:49:14 primo qobuz-connect[3938]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.041 [3938.3938] INFO SampleApp: Playback state changed: Playing
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.042 [3938.3938] INFO StreamingEventReporter: [0xab83b0a8]: Reporting streaming started event
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.042 [3938.3938] INFO HttpDownloader: [0xab83b100]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.042 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.042 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.045 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.046 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending FileAudioQualityChanged message
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.047 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.047 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending DeviceAudioQualityChanged message
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.050 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:14 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:14 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:14 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:14 primo volumio[3401]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.060 [3938.3938] INFO VolumeManager: [0xab83a9b8]: Setting new playback volume: 42
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.062 [3938.3938] INFO VolumeManager: [0xab83a9b8]: Setting new mute state: 0
Dec 27 00:49:14 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:14.058+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.178.110:33022
Dec 27 00:49:14 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:14.058+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.178.110:33022
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:14 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:14.072+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.178.110:43716
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:14 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:14 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:14 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:14.079+01:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.178.110:42316
Dec 27 00:49:14 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:14.080+01:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.178.110:42316
Dec 27 00:49:14 primo volumio5-onboarding[4348]: time=2025-12-27T00:49:14.090+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.178.110:56518
Dec 27 00:49:14 primo volumio[3401]: info: [LastFM] Current track has sufficient metadata: title (La Perla) and artist (ROSALÍA) passed on explicitly
Dec 27 00:49:14 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:14 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:14 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:14 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:14 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:14 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:14 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:14 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.197 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetState message:
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.197 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playing state:
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.197 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playback position:
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.197 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Queue version: 4.2
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.197 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Current track:
Dec 27 00:49:14 primo qobuz-connect[3938]: 20251227 00:49:14.197 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Next track: TID: 326644748, QID: 1, Context UUID: b673d299-0262-429a-8545-d7bfb03201ff
Dec 27 00:49:14 primo kernel: asoc-aml-card auge_sound: tdm playback enable
Dec 27 00:49:14 primo kernel: spdif_a is set to enable
Dec 27 00:49:14 primo volumio[3401]: info: MCU Signalled Playback Active
Dec 27 00:49:14 primo volumio[3401]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"La Perla","mbid":"060bdc2b-197b-4053-a9e9-53082982ad49","url":"https://www.last.fm/music/ROSAL%C3%8DA/_/La+Perla","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"322916","playcount":"2783704","artist":{"name":"ROSALÍA","mbid":"25f3abd9-63b5-471a-bd25-feb9672dfa11","url":"https://www.last.fm/music/ROSAL%C3%8DA"},"album":{"artist":"ROSALÍA","title":"LUX","url":"https://www.last.fm/music/ROSAL%C3%8DA/LUX","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/d2afdd216d7c820f1d6f6be98993970c.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/d2afdd216d7c820f1d6f6be98993970c.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/d2afdd216d7c820f1d6f6be98993970c.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/d2afdd216d7c820f1d6f6be98993970c.png","@":{"size":"extralarge"}}]},"userplaycount":"0","userloved":"0","toptags":{"tag":[{"name":"pop","url":"https://www.last.fm/tag/pop"},{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"spoken word","url":"https://www.last.fm/tag/spoken+word"},{"name":"Classical","url":"https://www.last.fm/tag/Classical"},{"name":"vocal","url":"https://www.last.fm/tag/vocal"}]},"wiki":{"published":"17 Nov 2025, 10:27","summary":"\"La Perla\" (transl. The Pearl) is the seventh track on ROSALIA's fourth studio album LUX. It features urban sierreño trio Yahritza y su Esencia. The song is a slow-paced, semi-ballad with Mexican music influences, structured as a fiercely cathartic letter. It aligns with the concept of LUX, which Rosalía describes as a work that explores the brutalities of love and feminine mysticism. Although Rosalía hasn't confirmed who the song is about, fans have interpreted it as referencing her ex-fiancé, Rauw Alejandro. Read more on Last.fm.","content":"\"La Perla\" (transl. The Pearl) is the seventh track on ROSALIA's fourth studio album LUX. It features urban sierreño trio Yahritza y su Esencia. The song is a slow-paced, semi-ballad with Mexican music influences, structured as a fiercely cathartic letter. It aligns with the concept of LUX, which Rosalía describes as a work that explores the brutalities of love and feminine mysticism. Although Rosalía hasn't confirmed who the song is about, fans have interpreted it as referencing her ex-fiancé, Rauw Alejandro. This speculation is based on perceived references in the lyrics, such as mentions of his “Playboy” persona and his “panties collection,” an allusion to the type of underwear the artist receives from fans at his shows. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}}
Dec 27 00:49:16 primo volumio[3401]: info: Executing endpoint metavolumio
Dec 27 00:49:16 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Dec 27 00:49:16 primo volumio[3401]: info: Executing endpoint metavolumio
Dec 27 00:49:16 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Dec 27 00:49:16 primo volumio[3401]: info: Executing endpoint metavolumio
Dec 27 00:49:16 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Dec 27 00:49:24 primo qobuz-connect[3938]: 20251227 00:49:24.041 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:24 primo qobuz-connect[3938]: 20251227 00:49:24.041 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:24 primo qobuz-connect[3938]: 20251227 00:49:24.042 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:24 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:24 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:24 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:24 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:24 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:24 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:24 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:24 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:24 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:24 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:24 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:24 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 27 00:49:27 primo volumio[3401]: info: Discovery: Getting this device information
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 27 00:49:27 primo volumio[3401]: verbose: New Socket.io Connection to 192.168.178.116:3000 from 192.168.178.110 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 27 00:49:27 primo volumio[3401]: info: Discovery: Getting this device information
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 27 00:49:27 primo volumio[3401]: verbose: New Socket.io Connection to 192.168.178.122:3000 from 192.168.178.110 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Dec 27 00:49:27 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Dec 27 00:49:34 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:34 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:34 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:34 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:34 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:34 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:34 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:34 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:34 primo qobuz-connect[3938]: 20251227 00:49:34.055 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:34 primo qobuz-connect[3938]: 20251227 00:49:34.055 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:34 primo qobuz-connect[3938]: 20251227 00:49:34.055 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:34 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:34 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:34 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:34 primo volumio[3401]: info: Signalling Playback active due to playback status change
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.045 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetState message:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.045 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playing state: Playing
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.045 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playback position: 0
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.045 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Queue version: 5.1
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Current track: TID: 301914865, QID: 0, Context UUID: e2807997-e216-4df0-ab96-95cec08bf903
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Next track: TID: 4294967295, QID: -1, Context UUID:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO MediaEngine: [0xab83a550]: Stopping playback, clearing tracks
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO MediaEngine: [0xab83a550]: Initiating playback
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO AudioRenderer: [0xab83a770]: Stopping audio renderer
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO RendererActionAvailabilityManager: [0xab83abe0]: Renderer action 'Next' is not available
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.046 [3938.3938] INFO SampleApp: Stopping playback
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.048 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Clearing all streams
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.048 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 3]: Disposing of audio stream
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.048 [3938.3938] INFO ContentFetcher: [0xaba77788]: Canceling download
Dec 27 00:49:38 primo kernel: asoc-aml-card auge_sound: tdm playback stop
Dec 27 00:49:38 primo kernel: spdif_a is set to disable
Dec 27 00:49:38 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:38 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B
Dec 27 00:49:38 primo kernel: tdm playback mute: 1, lane_cnt = 8
Dec 27 00:49:38 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.055 [3938.3938] INFO SampleApp: Playback state changed: Stopped
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO StreamingEventReporter: [0xab83b0a8]: Reporting streaming ended event
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO HttpDownloader: [0xab83b100]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO SampleApp: [Stream 3]: Audio stream has been disposed of
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO MediaEngine: [0xab83a550]: Setting current track: 301914865, initial offset: 0ms
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.066 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Clearing all streams
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.067 [3938.3938] INFO AudioStreamManager: [0xab83a638]: New stream: 5
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.067 [3938.3938] INFO HttpDownloader: [0xaba65ea0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=a59302a4eb748c337925a88df35b92ed&request_ts=1766792978&track_id=301914865
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.067 [3938.3938] INFO HttpDownloader: [0xab873b78]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=301914865
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.067 [3938.3938] INFO HttpDownloader: [0xab8401b0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=04795e9287df4e10603dc48186959b7e&request_ts=1766792978&track_id=301914865
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.067 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 5]: Running audio stream
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.067 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.069 [3938.3938] INFO MediaEngine: [0xab83a550]: Setting next track: NONE
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.069 [3938.3938] INFO MediaEngine: [0xab83a550]: Waiting for current stream to start before starting audio renderer
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:38 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:38 primo volumio[3401]: SPOTIFY: RECEIVED VOLUMIO VOLUME 42
Dec 27 00:49:38 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:38 primo volumio[3401]: info: Updating RAAT Signal Path
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.197 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 5]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=301914865&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796578&hmac=MqytPStFl1OIq_wBMimOIMuFW88
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.201 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 5]: stream information have been fetched
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.201 [3938.3938] INFO UrlAudioSource: [0xababb1e8]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=301914865&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796578&hmac=MqytPStFl1OIq_wBMimOIMuFW88
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.201 [3938.3938] INFO ContentFetcher: [0xaba97b08]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2853749&eid=301914865&fmt=7&profile=raw&app_id=174516466&cid=2060322&etsp=1766796578&hmac=MqytPStFl1OIq_wBMimOIMuFW88, offset: 0
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.201 [3938.3938] INFO AudioRenderer: [0xab83a770]: Starting audio renderer, initial playback state: Playing
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.202 [3938.3938] INFO SampleApp: [Stream 5]: New audio stream (starting from 0ms)
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: QobuzConnect: alread currrent service, send playback confirmation
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.204 [3938.3938] INFO SampleApp: Initiating playback, initial state: Playing
Dec 27 00:49:38 primo kernel: aml_tdm_open
Dec 27 00:49:38 primo kernel: Not init audio effects
Dec 27 00:49:38 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1
Dec 27 00:49:38 primo qobuz-connect[3938]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768
Dec 27 00:49:38 primo qobuz-connect[3938]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.208 [3938.3938] INFO SampleApp: Playback state changed: Playing
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.208 [3938.3938] INFO StreamingEventReporter: [0xab83b0a8]: Reporting streaming started event
Dec 27 00:49:38 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186
Dec 27 00:49:38 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d123a18, id(1), clksel(1)
Dec 27 00:49:38 primo kernel: aml_dai_set_tdm_fmt(), fmt not change
Dec 27 00:49:38 primo kernel: dump_pcm_setting(ffffffc03d123a18)
Dec 27 00:49:38 primo kernel: pcm_mode(1)
Dec 27 00:49:38 primo kernel: sysclk(11289600)
Dec 27 00:49:38 primo kernel: sysclk_bclk_ratio(4)
Dec 27 00:49:38 primo kernel: bclk(2822400)
Dec 27 00:49:38 primo kernel: bclk_lrclk_ratio(64)
Dec 27 00:49:38 primo kernel: lrclk(44100)
Dec 27 00:49:38 primo kernel: tx_mask(0x3)
Dec 27 00:49:38 primo kernel: rx_mask(0x3)
Dec 27 00:49:38 primo kernel: slots(2)
Dec 27 00:49:38 primo kernel: slot_width(32)
Dec 27 00:49:38 primo kernel: lane_mask_in(0x2)
Dec 27 00:49:38 primo kernel: lane_mask_out(0x1)
Dec 27 00:49:38 primo kernel: lane_oe_mask_in(0x0)
Dec 27 00:49:38 primo kernel: lane_oe_mask_out(0x0)
Dec 27 00:49:38 primo kernel: lane_lb_mask_in(0x0)
Dec 27 00:49:38 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk
Dec 27 00:49:38 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk
Dec 27 00:49:38 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186
Dec 27 00:49:38 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1)
Dec 27 00:49:38 primo kernel: aml_dai_set_bclk_ratio, select I2S mode
Dec 27 00:49:38 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B
Dec 27 00:49:38 primo kernel: aml_tdm_prepare(), reset fddr
Dec 27 00:49:38 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10
Dec 27 00:49:38 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0
Dec 27 00:49:38 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:38 primo kernel: tdm playback mute: 0, lane_cnt = 8
Dec 27 00:49:38 primo kernel: aml_tdm_prepare(), reset fddr
Dec 27 00:49:38 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10
Dec 27 00:49:38 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0
Dec 27 00:49:38 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3
Dec 27 00:49:38 primo kernel: tdm playback mute: 0, lane_cnt = 8
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.214 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Need to send state update
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.214 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending StateUpdated message
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::servicePushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreStateMachine::pushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioPushState
Dec 27 00:49:38 primo volumio[3401]: info: CoreCommandRouter::volumioGetState
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output update for this device
Dec 27 00:49:38 primo volumio[3401]: info: MRS: Pushing multiroomSync output
Dec 27 00:49:38 primo volumio[3401]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title!
Dec 27 00:49:38 primo volumio[3401]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.320 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.322 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending FileAudioQualityChanged message
Dec 27 00:49:38 primo volumio[3401]: TypeError: Cannot read property 'indexOf' of undefined
Dec 27 00:49:38 primo volumio[3401]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25)
Dec 27 00:49:38 primo volumio[3401]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26)
Dec 27 00:49:38 primo volumio[3401]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52)
Dec 27 00:49:38 primo volumio[3401]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20)
Dec 27 00:49:38 primo volumio[3401]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10)
Dec 27 00:49:38 primo volumio[3401]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12)
Dec 27 00:49:38 primo volumio[3401]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15)
Dec 27 00:49:38 primo volumio[3401]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20)
Dec 27 00:49:38 primo volumio[3401]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8)
Dec 27 00:49:38 primo volumio[3401]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15)
Dec 27 00:49:38 primo volumio[3401]: at Decoder.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20)
Dec 27 00:49:38 primo volumio[3401]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12)
Dec 27 00:49:38 primo volumio[3401]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16)
Dec 27 00:49:38 primo volumio[3401]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15)
Dec 27 00:49:38 primo volumio[3401]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20)
Dec 27 00:49:38 primo volumio[3401]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14)
Dec 27 00:49:38 primo volumio[3401]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.360 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.360 [3938.3938] INFO QConnectMessageSender: [0xab83dba0]: Sending DeviceAudioQualityChanged message
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.361 [3938.3938] INFO QwspMessageSender: [0xab8466b8]: Sending Payload message
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.362 [3938.3938] INFO HttpDownloader: [0xab83b100]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO AudioStreamManager: [0xab83a638]: [Stream 5]: Metadata became available:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Title: Floating Parade
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Artist: Michael Kiwanuka
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album: Small Changes
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO AudioStreamManager: [0xab83a638]: Album art URL: https://static.qobuz.com/images/covers/nc/z2/e6umxrtrlz2nc_600.jpg
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO SampleApp: [Stream 5]: Stream metadata became available:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO SampleApp: Title: Floating Parade
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO SampleApp: Artist: Michael Kiwanuka
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO SampleApp: Album: Small Changes
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.363 [3938.3938] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/nc/z2/e6umxrtrlz2nc_600.jpg
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.377 [3938.3938] INFO UrlAudioSource: [0xababb1e8]: Content info extracted
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.377 [3938.3938] INFO UrlAudioSource: [0xababb1e8]: Size: 46317688
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.381 [3938.19192] INFO AudioDecoder: [0xaba71930]: Stream info:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.382 [3938.19192] INFO AudioDecoder: [0xaba71930]: Total samples: 10126212
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.382 [3938.19192] INFO AudioDecoder: [0xaba71930]: Sample rate: 44100
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.382 [3938.19192] INFO AudioDecoder: [0xaba71930]: Channel count: 2
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.382 [3938.19192] INFO AudioDecoder: [0xaba71930]: Bits per sample: 24
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.382 [3938.19192] INFO AudioDecoder: [0xaba71930]: Duration: 229619
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.382 [3938.3938] INFO UrlAudioSource: [0xababb1e8]: Audio properties have changed
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.592 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Received SetState message:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.592 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playing state:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.592 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Playback position:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.592 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Queue version: 5.2
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.592 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Current track:
Dec 27 00:49:38 primo qobuz-connect[3938]: 20251227 00:49:38.592 [3938.3938] INFO ProtocolHandler: [0xab83ac90]: Next track: TID: 4294967295, QID: -1, Context UUID:
Dec 27 00:49:38 primo kernel: asoc-aml-card auge_sound: tdm playback enable
Dec 27 00:49:38 primo kernel: spdif_a is set to enable
Dec 27 00:49:39 primo sudo[19201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-27 00:48
Dec 27 00:49:39 primo sudo[19201]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
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="b43c85cc0006d3f1efecba101311ec96e334d1fd"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="primo2rev2"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 07:52:21 PM CET"
VOLUMIO_VERSION="3.886"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Primo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Primo"
VOLUMIO_HASH="060c5b31331b90c840ee52059a8e3db0"