-- Logs begin at Tue 2026-03-24 10:56:55 EET, end at Tue 2026-03-24 11:05:37 EET. -- Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.054 [32078.32078] INFO PlaybackSessionManager: [0x564820afa5f0]: Playback session has been refreshed Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO CloudClient: [0x564820afb210]: Connection established Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Authenticate message Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Subscribe message Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending JoinSession message Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeMuted message Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending MaxAudioQualityChanged message Mar 24 11:04:00 volumio qobuz-connect[32078]: 20260324 11:04:00.754 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetActive message: active Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetState message: Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playing state: Stopped Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playback position: Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Queue version: 0.0 Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Current track: TID: 4294967295, QID: -1, Context UUID: Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Next track: TID: 4294967295, QID: -1, Context UUID: Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Stopping playback, clearing tracks Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Stopping playback, keeping tracks Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetLoopMode message: Off Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO PlaybackModeManager: [0x564820afae80]: Setting new loop mode: Off Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting current track: NONE Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetShuffleMode message: disabled Mar 24 11:04:01 volumio qobuz-connect[32078]: 20260324 11:04:01.048 [32078.32078] INFO PlaybackModeManager: [0x564820afae80]: Setting new shuffle mode: disabled Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetState message: Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playing state: Playing Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playback position: 0 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Queue version: 1.1 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Current track: TID: 370964, QID: 0, Context UUID: 3aa48f55-5242-4156-afce-3672a1ea389f Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Next track: TID: 370965, QID: 1, Context UUID: 3aa48f55-5242-4156-afce-3672a1ea389f Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Stopping playback, clearing tracks Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Initiating playback Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO RendererActionAvailabilityManager: [0x564820afb2f0]: Renderer action 'Next' is available Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting current track: 370964, initial offset: 0ms Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Clearing all streams Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: New stream: 1 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO HttpDownloader: [0x564820c82650]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=de6f09d19888ce5deaf8e04c40047839&request_ts=1774343075&track_id=370964 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO HttpDownloader: [0x564820c7ca50]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=370964 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO HttpDownloader: [0x564820c74fd0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=74bf3656fa51889a0116fadbbf9c4562&request_ts=1774343075&track_id=370964 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 1]: Running audio stream Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting next track: 370965 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: New stream: 2 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO HttpDownloader: [0x564820c85cb0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=c39254af0bc53354a63373d3b62a3995&request_ts=1774343075&track_id=370965 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO HttpDownloader: [0x564820c64470]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=370965 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO HttpDownloader: [0x564820c5ab20]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=f60491ff3d1fb05cbd8adf28a7e06150&request_ts=1774343075&track_id=370965 Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.794 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Waiting for current stream to start before starting audio renderer Mar 24 11:04:35 volumio qobuz-connect[32078]: 20260324 11:04:35.944 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 2]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370965&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346675&hmac=0HtWylreZmBQOUj137nYd-X1Uug Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.032 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 1]: stream information have been fetched Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.131 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 2]: stream information have been fetched Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.200 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 2]: Metadata became available: Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.200 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Title: Hallowed Land Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.200 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Artist: Paradise Lost Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.200 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album: Draconian Times Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.200 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.401 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 1]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346676&hmac=J41Mz8J7K2djriAM6gznlZiB8GY Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.401 [32078.32078] INFO UrlAudioSource: [0x564820c446b0]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346676&hmac=J41Mz8J7K2djriAM6gznlZiB8GY Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.402 [32078.32078] INFO ContentFetcher: [0x564820d29970]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346676&hmac=J41Mz8J7K2djriAM6gznlZiB8GY, offset: 0 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.402 [32078.32078] INFO AudioRenderer: [0x564820afac20]: Starting audio renderer, initial playback state: Playing Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.402 [32078.32078] INFO SampleApp: [Stream 1]: New audio stream (starting from 0ms) Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CorePlayQueue::getTrack 0 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 1]: Metadata became available: Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Title: Enchantment Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Artist: Paradise Lost Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album: Draconian Times Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO SampleApp: [Stream 1]: Stream metadata became available: Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO SampleApp: Title: Enchantment Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO SampleApp: Artist: Paradise Lost Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO SampleApp: Album: Draconian Times Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.404 [32078.32078] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:04:36 volumio volumio[1186]: info: QobuzConnect: setActiveState() Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CorePlayQueue::getTrack 0 Mar 24 11:04:36 volumio volumio[1186]: info: QobuzConnect: Set Qobuz connect default volume to 5 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.405 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 5 Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CorePlayQueue::getTrack 0 Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CorePlayQueue::getTrack 0 Mar 24 11:04:36 volumio volumio[1186]: info: QobuzConnect: Stopping currently active service Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioStop Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::stop Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CorePlayQueue::getTrack 0 Mar 24 11:04:36 volumio volumio[1186]: verbose: STATE SERVICE {"status":"stop","service":"qobuzconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"qobuz","codec":"","seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false} Mar 24 11:04:36 volumio volumio[1186]: verbose: CURRENT POSITION 0 Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::syncState stateService stop Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::syncState currentStatus stop Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: No code Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: QobuzConnect: setActiveState(): setting Volatile state to qobuzconnect Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_STOPPED positionMs= volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_STOPPED positionMs= volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_STOPPED positionMs= volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.414+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:04:36 volumio volumio[1186]: info: QobuzConnect: setActiveState() completed, send playback confirmation Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.421 [32078.32078] INFO SampleApp: Initiating playback, initial state: Playing Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status undefined Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status undefined Mar 24 11:04:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status Mar 24 11:04:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status undefined Mar 24 11:04:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status undefined Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio volumio[1186]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.xrwioaavz2TmcyznOOnPYwt7ykk2.1feab3ecd2aa0d3d4644c14301bd5f4b.state.status' Mar 24 11:04:36 volumio volumio[1186]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.xrwioaavz2TmcyznOOnPYwt7ykk2.1feab3ecd2aa0d3d4644c14301bd5f4b.state.status' Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO SampleApp: Playback state changed: Playing Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO StreamingEventReporter: [0x564820afbae0]: Reporting streaming started event Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO HttpDownloader: [0x564820afbb70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending FileAudioQualityChanged message Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending DeviceAudioQualityChanged message Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.430 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.434 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 5 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.435 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new mute state: 0 Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.438+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.438+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.438+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.438+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.438+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.438+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:36 volumio volumio[1186]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 24 11:04:36 volumio volumio[1186]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 24 11:04:36 volumio volumio[1186]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 24 11:04:36 volumio volumio[1186]: info: [LastFM] Current track has sufficient metadata: title (Enchantment) and artist (Paradise Lost) passed on explicitly Mar 24 11:04:36 volumio volumio[1186]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:36 volumio sudo[2592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:36 volumio sudo[2592]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:36 volumio sudo[2596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:36 volumio sudo[2596]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:36 volumio sudo[2599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:36 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 24 11:04:36 volumio sudo[2599]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio sudo[2602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:36 volumio sudo[2602]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio sudo[2592]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:36 volumio sudo[2606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:36 volumio sudo[2606]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio systemd[1]: Started peppyspectrum Daemon. Mar 24 11:04:36 volumio sudo[2596]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio sudo[2599]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio sudo[2602]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio sudo[2606]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio sudo[2615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:36 volumio sudo[2615]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 24 11:04:36 volumio sudo[2615]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio volumio[1186]: error: FusionDsp - WebSocket error: [object Object] Mar 24 11:04:36 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:36 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:36 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:36 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:36 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:36 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.555 [32078.32078] INFO SampleApp: Playback volume changed: 5 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.555 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 5 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.555 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.555 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 5 Mar 24 11:04:36 volumio volumio[1186]: info: VolumeController::SetAlsaVolume5 Mar 24 11:04:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.580+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=5 Mar 24 11:04:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:36.580+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:36 volumio sudo[2627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:36 volumio sudo[2627]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio sudo[2627]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:36 volumio sudo[2630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:36 volumio sudo[2630]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:36 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:36 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:36 volumio sudo[2630]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:36 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2613]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2595]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio volumio[2595]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.32078] INFO UrlAudioSource: [0x564820c446b0]: Content info extracted Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.32078] INFO UrlAudioSource: [0x564820c446b0]: Size: 42562096 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.2736] INFO AudioDecoder: [0x564820da3890]: Stream info: Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.2736] INFO AudioDecoder: [0x564820da3890]: Total samples: 16078860 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.2736] INFO AudioDecoder: [0x564820da3890]: Sample rate: 44100 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.2736] INFO AudioDecoder: [0x564820da3890]: Channel count: 2 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.2736] INFO AudioDecoder: [0x564820da3890]: Bits per sample: 16 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.2736] INFO AudioDecoder: [0x564820da3890]: Duration: 364600 Mar 24 11:04:36 volumio qobuz-connect[32078]: 20260324 11:04:36.960 [32078.32078] INFO UrlAudioSource: [0x564820c446b0]: Audio properties have changed Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.434 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.434 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.434 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:46 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:46 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:46.440+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=5 Mar 24 11:04:46 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:46.440+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:46 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:46 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:46 volumio sudo[6034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:46 volumio sudo[6034]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:46 volumio sudo[6034]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:46 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 24 11:04:46 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:46 volumio sudo[6037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:46 volumio sudo[6037]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:46 volumio sudo[6037]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:46 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.620 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 6 Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.620 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 6 Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.771 [32078.32078] INFO SampleApp: Playback volume changed: 6 Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.771 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 6 Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.771 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.771 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:46 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 6 Mar 24 11:04:46 volumio volumio[1186]: info: VolumeController::SetAlsaVolume6 Mar 24 11:04:46 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:46 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:46 volumio qobuz-connect[32078]: 20260324 11:04:46.794 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 6 Mar 24 11:04:46 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:46.795+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=6 Mar 24 11:04:46 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:46.795+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:46 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:46 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:46 volumio sudo[6153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:46 volumio sudo[6153]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:46 volumio sudo[6153]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:46 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6 Mar 24 11:04:46 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 5 Mar 24 11:04:46 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 6 Mar 24 11:04:46 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:04:46 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:46 volumio sudo[6156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:46 volumio sudo[6156]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:46 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:46 volumio sudo[6156]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:46 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.798 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 12 Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.798 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 12 Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.948 [32078.32078] INFO SampleApp: Playback volume changed: 12 Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.949 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 12 Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.949 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.949 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:48 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:48 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 12 Mar 24 11:04:48 volumio volumio[1186]: info: VolumeController::SetAlsaVolume12 Mar 24 11:04:48 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:48 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:48 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:48 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:48 volumio qobuz-connect[32078]: 20260324 11:04:48.970 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 12 Mar 24 11:04:48 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:48.971+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=12 Mar 24 11:04:48 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:48.971+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:48 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:48 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:48 volumio sudo[6896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:48 volumio sudo[6896]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:48 volumio sudo[6896]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:48 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Mar 24 11:04:48 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 5 Mar 24 11:04:48 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 12 Mar 24 11:04:48 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 11:04:48 volumio volumio[1186]: info: Setting Spotify Volume from Volumio: 12 Mar 24 11:04:48 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:48 volumio sudo[6899]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:48 volumio sudo[6899]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:49 volumio sudo[6899]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.151 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 32 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.151 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 32 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.157 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 43 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.157 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 43 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.171 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 49 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.171 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 49 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.301 [32078.32078] INFO SampleApp: Playback volume changed: 49 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.301 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 49 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.301 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.301 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:49 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 49 Mar 24 11:04:49 volumio volumio[1186]: info: VolumeController::SetAlsaVolume49 Mar 24 11:04:49 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.316 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 49 Mar 24 11:04:49 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:49.316+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=49 Mar 24 11:04:49 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:49.316+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:49 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:49 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:49 volumio sudo[7008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:49 volumio sudo[7008]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio sudo[7008]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 12 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 49 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 11:04:49 volumio volumio[1186]: info: Setting Spotify Volume from Volumio: 49 Mar 24 11:04:49 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:49 volumio sudo[7011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:49 volumio sudo[7011]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:49 volumio sudo[7011]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.460 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 52 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.460 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 52 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 55 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.467 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 55 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.475 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 61 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.475 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 61 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.610 [32078.32078] INFO SampleApp: Playback volume changed: 61 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.610 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 61 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.610 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.610 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:49 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 61 Mar 24 11:04:49 volumio volumio[1186]: info: VolumeController::SetAlsaVolume61 Mar 24 11:04:49 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.627 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 61 Mar 24 11:04:49 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:49.627+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=61 Mar 24 11:04:49 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:49.627+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:49 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:49 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:49 volumio sudo[7106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:49 volumio sudo[7106]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio sudo[7106]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 61 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 49 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 61 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 11:04:49 volumio volumio[1186]: info: Setting Spotify Volume from Volumio: 61 Mar 24 11:04:49 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:49 volumio sudo[7109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:49 volumio sudo[7109]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:49 volumio sudo[7109]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.743 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 58 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.743 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 58 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.750 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 58 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.750 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 58 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.753 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 60 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.753 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 60 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.893 [32078.32078] INFO SampleApp: Playback volume changed: 60 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.893 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 60 Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.893 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.893 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:49 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 60 Mar 24 11:04:49 volumio volumio[1186]: info: VolumeController::SetAlsaVolume60 Mar 24 11:04:49 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:49 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:49 volumio qobuz-connect[32078]: 20260324 11:04:49.907 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 60 Mar 24 11:04:49 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:49.908+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=60 Mar 24 11:04:49 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:49.908+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:49 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:49 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:49 volumio sudo[7197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:49 volumio sudo[7197]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio sudo[7197]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 61 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 60 Mar 24 11:04:49 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:04:49 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:49 volumio sudo[7200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:49 volumio sudo[7200]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:49 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:49 volumio sudo[7200]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:49 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.069 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 63 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.069 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 63 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.077 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 64 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.077 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 64 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.088 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.088 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.219 [32078.32078] INFO SampleApp: Playback volume changed: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.219 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.219 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.219 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:50 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:50 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 65 Mar 24 11:04:50 volumio volumio[1186]: info: VolumeController::SetAlsaVolume65 Mar 24 11:04:50 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:50 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:50 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:50 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.234 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 65 Mar 24 11:04:50 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:50.235+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=65 Mar 24 11:04:50 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:50.235+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:50 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:50 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:50 volumio sudo[7302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:50 volumio sudo[7302]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:50 volumio sudo[7302]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:50 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:50 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 61 Mar 24 11:04:50 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 65 Mar 24 11:04:50 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 24 11:04:50 volumio volumio[1186]: info: Setting Spotify Volume from Volumio: 65 Mar 24 11:04:50 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:04:50 volumio sudo[7305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:50 volumio sudo[7305]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:50 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:50 volumio sudo[7305]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:50 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.369 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.369 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.372 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 65 Mar 24 11:04:50 volumio qobuz-connect[32078]: 20260324 11:04:50.372 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 65 Mar 24 11:04:51 volumio volumio[1186]: SPOTIFY: SETTING SPOTIFY VOLUME 65 Mar 24 11:04:51 volumio volumio[1186]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 11:04:56 volumio qobuz-connect[32078]: 20260324 11:04:56.438 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:04:56 volumio qobuz-connect[32078]: 20260324 11:04:56.438 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:04:56 volumio qobuz-connect[32078]: 20260324 11:04:56.438 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:56 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:56 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:56 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:56 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:56 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:56 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:56.443+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=65 Mar 24 11:04:56 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:56.443+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:56 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:56 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:56 volumio sudo[9500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:56 volumio sudo[9500]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:56 volumio sudo[9500]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:56 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:56 volumio sudo[9503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:56 volumio sudo[9503]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:56 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:56 volumio sudo[9503]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:56 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:56 volumio volumio[2595]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetState message: Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playing state: Playing Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playback position: 0 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Queue version: 2.1 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Current track: TID: 370964, QID: 0, Context UUID: 5614fa9e-faef-4f45-947b-2b9f85662135 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Next track: TID: 370965, QID: 1, Context UUID: 5614fa9e-faef-4f45-947b-2b9f85662135 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Stopping playback, clearing tracks Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Initiating playback Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO AudioRenderer: [0x564820afac20]: Stopping audio renderer Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO SampleApp: Stopping playback Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Clearing all streams Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 1]: Disposing of audio stream Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.467 [32078.32078] INFO ContentFetcher: [0x564820d29970]: Canceling download Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO SampleApp: Playback state changed: Stopped Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO StreamingEventReporter: [0x564820afbae0]: Reporting streaming ended event Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820afbb70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO SampleApp: [Stream 1]: Audio stream has been disposed of Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting current track: 370964, initial offset: 0ms Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Clearing all streams Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: New stream: 3 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820c5c180]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=3814f37c5fe456be9ed45ba77636db3a&request_ts=1774343099&track_id=370964 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820c4e130]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=370964 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820c80dc0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=4ab182a778c2b55b76b2325d94501aaf&request_ts=1774343099&track_id=370964 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 3]: Running audio stream Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting next track: 370965 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: New stream: 4 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820dcfb70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=339d2108a5de52cb9781aa69315adfcc&request_ts=1774343099&track_id=370965 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820c74fd0]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=370965 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO HttpDownloader: [0x564820aff970]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=6c7ec1b639655e2262eb247350f0c5ef&request_ts=1774343099&track_id=370965 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.468 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Waiting for current stream to start before starting audio renderer Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.473+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PAUSED positionMs=0 volume=65 Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.473+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.491+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PAUSED positionMs=0 volume=65 Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.492+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:59 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 24 11:04:59 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 24 11:04:59 volumio sudo[10556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 24 11:04:59 volumio sudo[10556]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio systemd[1]: Stopping peppymeterbasic Daemon... Mar 24 11:04:59 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=killed, status=15/TERM Mar 24 11:04:59 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status pause Mar 24 11:04:59 volumio sudo[10559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 24 11:04:59 volumio sudo[10559]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status pause Mar 24 11:04:59 volumio sudo[10562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Mar 24 11:04:59 volumio sudo[10562]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio systemd[1]: Stopping peppyspectrum Daemon... Mar 24 11:04:59 volumio systemd[1]: peppyspectrum.service: Main process exited, code=killed, status=15/TERM Mar 24 11:04:59 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:59 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:59 volumio sudo[10565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Mar 24 11:04:59 volumio sudo[10565]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:04:59 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:04:59 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:04:59 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:04:59 volumio systemd[1]: peppymeterbasic.service: Succeeded. Mar 24 11:04:59 volumio systemd[1]: Stopped peppymeterbasic Daemon. Mar 24 11:04:59 volumio sudo[10556]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio sudo[10559]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio volumio[1186]: info: peppymeterbasic Daemon Stop Mar 24 11:04:59 volumio volumio[1186]: info: peppymeterbasic Daemon Stop Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.635 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 3]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346699&hmac=QrFVhz8GTFG8Q_TrTQLeXbFsvBo Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.635 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 4]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370965&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346699&hmac=_dbhHyXMO0UlNbVhy9R3J_wb45s Mar 24 11:04:59 volumio systemd[1]: peppyspectrum.service: Succeeded. Mar 24 11:04:59 volumio systemd[1]: Stopped peppyspectrum Daemon. Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.643 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 3]: Metadata became available: Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.643 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Title: Enchantment Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.643 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Artist: Paradise Lost Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.643 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album: Draconian Times Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.643 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:04:59 volumio sudo[10565]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio sudo[10562]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio volumio[1186]: info: peppyspectrum Daemon Stop Mar 24 11:04:59 volumio volumio[1186]: info: peppyspectrum Daemon Stop Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.656 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 4]: Metadata became available: Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.656 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Title: Hallowed Land Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.656 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Artist: Paradise Lost Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.656 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album: Draconian Times Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.656 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 3]: stream information have been fetched Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO UrlAudioSource: [0x564820da58c0]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346699&hmac=QrFVhz8GTFG8Q_TrTQLeXbFsvBo Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO ContentFetcher: [0x564820da6090]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346699&hmac=QrFVhz8GTFG8Q_TrTQLeXbFsvBo, offset: 0 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO AudioRenderer: [0x564820afac20]: Starting audio renderer, initial playback state: Playing Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO SampleApp: [Stream 3]: New audio stream (starting from 0ms) Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO SampleApp: [Stream 3]: Stream metadata became available: Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO SampleApp: Title: Enchantment Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO SampleApp: Artist: Paradise Lost Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO SampleApp: Album: Draconian Times Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.673 [32078.32078] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: QobuzConnect: alread currrent service, send playback confirmation Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.674 [32078.32078] INFO SampleApp: Initiating playback, initial state: Playing Mar 24 11:04:59 volumio volumio[1186]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 24 11:04:59 volumio volumio[1186]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 24 11:04:59 volumio volumio[1186]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.677 [32078.32078] INFO SampleApp: Playback state changed: Playing Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.677 [32078.32078] INFO StreamingEventReporter: [0x564820afbae0]: Reporting streaming started event Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.677 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.677 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.677 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:04:59 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PAUSED positionMs=0 volume=65 Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=65 Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=65 Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=65 Mar 24 11:04:59 volumio volumio5-onboarding[1716]: time=2026-03-24T11:04:59.687+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.697 [32078.32078] INFO HttpDownloader: [0x564820afbb70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Mar 24 11:04:59 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 24 11:04:59 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:59 volumio sudo[10612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 24 11:04:59 volumio sudo[10612]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:59 volumio sudo[10612]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio sudo[10615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:59 volumio sudo[10615]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:04:59 volumio sudo[10619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:59 volumio sudo[10619]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status pause Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.32078] INFO UrlAudioSource: [0x564820da58c0]: Content info extracted Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.32078] INFO UrlAudioSource: [0x564820da58c0]: Size: 42562096 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.10622] INFO AudioDecoder: [0x564820e67d90]: Stream info: Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.10622] INFO AudioDecoder: [0x564820e67d90]: Total samples: 16078860 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.10622] INFO AudioDecoder: [0x564820e67d90]: Sample rate: 44100 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.10622] INFO AudioDecoder: [0x564820e67d90]: Channel count: 2 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.10622] INFO AudioDecoder: [0x564820e67d90]: Bits per sample: 16 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.10622] INFO AudioDecoder: [0x564820e67d90]: Duration: 364600 Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.738 [32078.32078] INFO UrlAudioSource: [0x564820da58c0]: Audio properties have changed Mar 24 11:04:59 volumio sudo[10623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:04:59 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 24 11:04:59 volumio sudo[10623]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio sudo[10615]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:59 volumio sudo[10619]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio sudo[10623]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio sudo[10627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Mar 24 11:04:59 volumio sudo[10627]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio sudo[10627]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:59 volumio sudo[10630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:59 volumio sudo[10630]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio systemd[1]: Started peppyspectrum Daemon. Mar 24 11:04:59 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:04:59 volumio sudo[10630]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio sudo[10634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:59 volumio sudo[10634]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio sudo[10634]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:59 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:59 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:59 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 24 11:04:59 volumio sudo[10638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:04:59 volumio sudo[10638]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:04:59 volumio volumio[1186]: error: FusionDsp - WebSocket error: [object Object] Mar 24 11:04:59 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 24 11:04:59 volumio sudo[10638]: pam_unix(sudo:session): session closed for user root Mar 24 11:04:59 volumio qobuz-connect[32078]: 20260324 11:04:59.800 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 4]: stream information have been fetched Mar 24 11:04:59 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:59 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:04:59 volumio volumio[1186]: info: peppyspectrum Daemon Stop Mar 24 11:04:59 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:59 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:59 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:04:59 volumio volumio[1186]: info: peppymeterbasic Daemon Stop Mar 24 11:04:59 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:00 volumio volumio[10633]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.261 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetVolume message, volume: 66 Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.261 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 66 Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.411 [32078.32078] INFO SampleApp: Playback volume changed: 66 Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.411 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Volume changed: 66 Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.411 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending VolumeChanged message Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.411 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:05:05 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:05 volumio volumio[1186]: info: QobuzConnect: Volume received from daemon: 66 Mar 24 11:05:05 volumio volumio[1186]: info: VolumeController::SetAlsaVolume66 Mar 24 11:05:05 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:05 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:05:05 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:05 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:05 volumio qobuz-connect[32078]: 20260324 11:05:05.432 [32078.32078] INFO VolumeManager: [0x564820afaf70]: Setting new playback volume: 66 Mar 24 11:05:05 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:05.433+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:05 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:05.433+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:05 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:05:05 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:05:05 volumio sudo[12577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:05:05 volumio sudo[12577]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:05 volumio sudo[12577]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:05 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 11:05:05 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 65 Mar 24 11:05:05 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 11:05:05 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:05:05 volumio sudo[12580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:05:05 volumio sudo[12580]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:05 volumio volumio[1186]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 24 11:05:05 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:05:05 volumio sudo[12580]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:05 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:05:09 volumio qobuz-connect[32078]: 20260324 11:05:09.678 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:05:09 volumio qobuz-connect[32078]: 20260324 11:05:09.678 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:05:09 volumio qobuz-connect[32078]: 20260324 11:05:09.678 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:05:09 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:09 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:09 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:09 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:09 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:09 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:09.694+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:09 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:09.694+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:09 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:05:09 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:05:09 volumio sudo[14049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:05:09 volumio sudo[14049]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:09 volumio sudo[14049]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:09 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 11:05:09 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 65 Mar 24 11:05:09 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 11:05:09 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:05:09 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:05:09 volumio sudo[14052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:05:09 volumio sudo[14052]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:09 volumio sudo[14052]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:09 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:05:19 volumio qobuz-connect[32078]: 20260324 11:05:19.686 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:05:19 volumio qobuz-connect[32078]: 20260324 11:05:19.686 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:05:19 volumio qobuz-connect[32078]: 20260324 11:05:19.686 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:05:19 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:19 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:19 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:19 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:19 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:19 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:19.702+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:19 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:19.702+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:19 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:05:19 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:05:19 volumio sudo[17478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:05:19 volumio sudo[17478]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:19 volumio sudo[17478]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:19 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 11:05:19 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 65 Mar 24 11:05:19 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 11:05:19 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:05:19 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:05:19 volumio sudo[17481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:05:19 volumio sudo[17481]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:19 volumio sudo[17481]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:19 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:05:20 volumio volumio[10618]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:20 volumio volumio[10618]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:20 volumio volumio[10618]: libpng warning: iCCP: known incorrect sRGB profile Mar 24 11:05:29 volumio qobuz-connect[32078]: 20260324 11:05:29.694 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:05:29 volumio qobuz-connect[32078]: 20260324 11:05:29.694 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:05:29 volumio qobuz-connect[32078]: 20260324 11:05:29.694 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:05:29 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:29 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:29 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:29 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:29 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:29 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:29.699+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:29 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:29.699+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:29 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 24 11:05:29 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status play Mar 24 11:05:29 volumio sudo[20957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 24 11:05:29 volumio sudo[20957]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:29 volumio sudo[20957]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:29 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 11:05:29 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 65 Mar 24 11:05:29 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 11:05:29 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:05:29 volumio volumio[1186]: info: peppymeterbasic Daemon Started Mar 24 11:05:29 volumio sudo[20960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Mar 24 11:05:29 volumio sudo[20960]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:29 volumio sudo[20960]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:29 volumio volumio[1186]: info: peppyspectrum Daemon Started Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Received SetState message: Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playing state: Playing Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Playback position: 0 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Queue version: 3.1 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Current track: TID: 370964, QID: 0, Context UUID: 88d91b50-6ab2-4d71-bf2f-21c2851613f7 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Next track: TID: 370965, QID: 1, Context UUID: 88d91b50-6ab2-4d71-bf2f-21c2851613f7 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Stopping playback, clearing tracks Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Initiating playback Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO AudioRenderer: [0x564820afac20]: Stopping audio renderer Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO SampleApp: Stopping playback Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Clearing all streams Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 3]: Disposing of audio stream Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.697 [32078.32078] INFO ContentFetcher: [0x564820da6090]: Canceling download Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.698 [32078.32078] INFO SampleApp: Playback state changed: Stopped Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.698 [32078.32078] INFO StreamingEventReporter: [0x564820afbae0]: Reporting streaming ended event Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820afbb70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO SampleApp: [Stream 3]: Audio stream has been disposed of Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting current track: 370964, initial offset: 0ms Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Clearing all streams Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: New stream: 5 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820c82650]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=de7ee2e6ae34550d138f0fc222a4725b&request_ts=1774343136&track_id=370964 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820c84e60]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=370964 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820c85cb0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=049c25f21c711f16645fb04f3c638457&request_ts=1774343136&track_id=370964 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 5]: Running audio stream Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Setting next track: 370965 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: New stream: 6 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820e42e10]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=94ea5771a5a1029c6a036f5b2f05aadf&request_ts=1774343136&track_id=370965 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820c98630]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=370965 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO HttpDownloader: [0x564820c4e130]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=b9650cd71e04cc886ad723761cd750bb&request_ts=1774343136&track_id=370965 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.699 [32078.32078] INFO MediaEngine: [0x564820afa9a0]: Waiting for current stream to start before starting audio renderer Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.705+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PAUSED positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.705+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.706+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PAUSED positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.706+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 24 11:05:36 volumio volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 24 11:05:36 volumio sudo[23375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 24 11:05:36 volumio sudo[23375]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:36 volumio systemd[1]: Stopping peppymeterbasic Daemon... Mar 24 11:05:36 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=killed, status=15/TERM Mar 24 11:05:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status pause Mar 24 11:05:36 volumio sudo[23378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 24 11:05:36 volumio sudo[23378]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:36 volumio volumio[1186]: info: PeppySpectrum ---peppyspectrum status pause Mar 24 11:05:36 volumio sudo[23381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Mar 24 11:05:36 volumio sudo[23381]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:36 volumio systemd[1]: Stopping peppyspectrum Daemon... Mar 24 11:05:36 volumio systemd[1]: peppyspectrum.service: Main process exited, code=killed, status=15/TERM Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 65 Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66 Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: SPOTIFY VOLUME 65 Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: VOLUMIO VOLUME 66 Mar 24 11:05:36 volumio volumio[1186]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 24 11:05:36 volumio sudo[23384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Mar 24 11:05:36 volumio sudo[23384]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 11:05:36 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:05:36 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:05:36 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:05:36 volumio volumio[1186]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 24 11:05:36 volumio systemd[1]: peppymeterbasic.service: Succeeded. Mar 24 11:05:36 volumio systemd[1]: Stopped peppymeterbasic Daemon. Mar 24 11:05:36 volumio sudo[23378]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:36 volumio sudo[23375]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:36 volumio volumio[1186]: info: peppymeterbasic Daemon Stop Mar 24 11:05:36 volumio volumio[1186]: info: peppymeterbasic Daemon Stop Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.821 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 6]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370965&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346736&hmac=aHHQFZCsXk0HetlraBmX0PwU0y4 Mar 24 11:05:36 volumio systemd[1]: peppyspectrum.service: Succeeded. Mar 24 11:05:36 volumio systemd[1]: Stopped peppyspectrum Daemon. Mar 24 11:05:36 volumio sudo[23384]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:36 volumio sudo[23381]: pam_unix(sudo:session): session closed for user root Mar 24 11:05:36 volumio volumio[1186]: info: peppyspectrum Daemon Stop Mar 24 11:05:36 volumio volumio[1186]: info: peppyspectrum Daemon Stop Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.877 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 5]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346736&hmac=zJsR0vCFl5Rh4Mxj6czkKPfXuIc Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.887 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 5]: stream information have been fetched Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.887 [32078.32078] INFO UrlAudioSource: [0x564820d6bed0]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346736&hmac=zJsR0vCFl5Rh4Mxj6czkKPfXuIc Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.887 [32078.32078] INFO ContentFetcher: [0x564820d026b0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=5653534&eid=370964&fmt=6&profile=raw&app_id=174516466&cid=4043371&etsp=1774346736&hmac=zJsR0vCFl5Rh4Mxj6czkKPfXuIc, offset: 0 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.887 [32078.32078] INFO AudioRenderer: [0x564820afac20]: Starting audio renderer, initial playback state: Playing Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.887 [32078.32078] INFO SampleApp: [Stream 5]: New audio stream (starting from 0ms) Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.888 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 6]: stream information have been fetched Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: QobuzConnect: alread currrent service, send playback confirmation Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.892 [32078.32078] INFO SampleApp: Initiating playback, initial state: Playing Mar 24 11:05:36 volumio volumio[1186]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 24 11:05:36 volumio volumio[1186]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.894 [32078.32078] INFO SampleApp: Playback state changed: Playing Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.894 [32078.32078] INFO StreamingEventReporter: [0x564820afbae0]: Reporting streaming started event Mar 24 11:05:36 volumio volumio[1186]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.894 [32078.32078] INFO HttpDownloader: [0x564820afbb70]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.894 [32078.32078] INFO ProtocolHandler: [0x564820afb410]: Need to send state update Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.894 [32078.32078] INFO QConnectMessageSender: [0x564820c91eb0]: Sending StateUpdated message Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.894 [32078.32078] INFO QwspMessageSender: [0x564820c92e60]: Sending Payload message Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 5]: Metadata became available: Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Title: Enchantment Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Artist: Paradise Lost Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album: Draconian Times Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO SampleApp: [Stream 5]: Stream metadata became available: Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO SampleApp: Title: Enchantment Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO SampleApp: Artist: Paradise Lost Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO SampleApp: Album: Draconian Times Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.895 [32078.32078] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::servicePushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreStateMachine::pushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioPushState Mar 24 11:05:36 volumio volumio[1186]: info: CoreCommandRouter::volumioGetState Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PAUSED positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.906+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title= Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.907+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" state=STATUS_PLAYING positionMs=0 volume=66 Mar 24 11:05:36 volumio volumio5-onboarding[1716]: time=2026-03-24T11:05:36.907+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.31.124:44100 @ 0xc0004010b0" id= title=Enchantment Mar 24 11:05:36 volumio volumio[1186]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Mar 24 11:05:36 volumio volumio[1186]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 11:05:36 volumio volumio[1186]: TypeError: Cannot read property 'indexOf' of undefined Mar 24 11:05:36 volumio volumio[1186]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Mar 24 11:05:36 volumio volumio[1186]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Mar 24 11:05:36 volumio volumio[1186]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Mar 24 11:05:36 volumio volumio[1186]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Mar 24 11:05:36 volumio volumio[1186]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Mar 24 11:05:36 volumio volumio[1186]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Mar 24 11:05:36 volumio volumio[1186]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Mar 24 11:05:36 volumio volumio[1186]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Mar 24 11:05:36 volumio volumio[1186]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Mar 24 11:05:36 volumio volumio[1186]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Mar 24 11:05:36 volumio volumio[1186]: at Decoder.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Mar 24 11:05:36 volumio volumio[1186]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Mar 24 11:05:36 volumio volumio[1186]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Mar 24 11:05:36 volumio volumio[1186]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Mar 24 11:05:36 volumio volumio[1186]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Mar 24 11:05:36 volumio volumio[1186]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Mar 24 11:05:36 volumio volumio[1186]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.923 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: [Stream 6]: Metadata became available: Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.923 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Title: Hallowed Land Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.923 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Artist: Paradise Lost Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.923 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album: Draconian Times Mar 24 11:05:36 volumio qobuz-connect[32078]: 20260324 11:05:36.923 [32078.32078] INFO AudioStreamManager: [0x564820afaad0]: Album art URL: https://static.qobuz.com/images/covers/27/16/0828768291627_600.jpg Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.003 [32078.32078] INFO UrlAudioSource: [0x564820d6bed0]: Content info extracted Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.003 [32078.32078] INFO UrlAudioSource: [0x564820d6bed0]: Size: 42562096 Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.23439] INFO AudioDecoder: [0x564820e1bf90]: Stream info: Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.23439] INFO AudioDecoder: [0x564820e1bf90]: Total samples: 16078860 Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.23439] INFO AudioDecoder: [0x564820e1bf90]: Sample rate: 44100 Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.23439] INFO AudioDecoder: [0x564820e1bf90]: Channel count: 2 Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.23439] INFO AudioDecoder: [0x564820e1bf90]: Bits per sample: 16 Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.23439] INFO AudioDecoder: [0x564820e1bf90]: Duration: 364600 Mar 24 11:05:37 volumio qobuz-connect[32078]: 20260324 11:05:37.004 [32078.32078] INFO UrlAudioSource: [0x564820d6bed0]: Audio properties have changed Mar 24 11:05:37 volumio sudo[23441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-24 11:04 Mar 24 11:05:37 volumio sudo[23441]: 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="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 09:58:18 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="54b3518c7dd8feba4753e0ad124ce801"