-- Logs begin at Thu 2019-02-14 19:11:58 JST, end at Sun 2025-06-29 21:45:25 JST. -- Jun 29 21:44:07 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:07 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:07 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:07 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:07 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:07 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:07 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:07 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:07 rivo-toshi qobuz-connect[9143]: 20250629 21:44:07.233 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:07 rivo-toshi qobuz-connect[9143]: 20250629 21:44:07.233 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:07 rivo-toshi qobuz-connect[9143]: 20250629 21:44:07.233 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:07 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:07 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:07 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:09 rivo-toshi volumiologrotate[2831]: ls: cannot access '/var/log/samba/log.wb-RIVO': No such file or directory Jun 29 21:44:09 rivo-toshi volumiologrotate[2831]: ls: cannot access 'TOSHI': No such file or directory Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Received SetState message: Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playing state: Playing Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playback position: 0 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Queue version: 3.1 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Current track: TID: 220679433, QID: 0, Context UUID: 85b97795-fe3b-4836-a94e-44b7abb98628 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Next track: TID: 220679434, QID: 1, Context UUID: 85b97795-fe3b-4836-a94e-44b7abb98628 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO MediaEngine: [0xac48edf8]: Stopping playback, clearing tracks Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.429 [9143.9143] INFO MediaEngine: [0xac48edf8]: Initiating playback Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.430 [9143.9143] INFO AudioRenderer: [0xac48f018]: Stopping audio renderer Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.430 [9143.9143] INFO SampleApp: Stopping playback Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.445 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Clearing all streams Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.445 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 5]: Disposing of audio stream Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.445 [9143.9143] INFO ContentFetcher: [0xac5033a0]: Canceling download Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.453 [9143.9143] INFO SampleApp: Playback state changed: Stopped Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:13 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.469 [9143.9143] INFO StreamingEventReporter: [0xac48f950]: Reporting streaming ended event Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.469 [9143.9143] INFO HttpDownloader: [0xac48f9a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO SampleApp: [Stream 5]: Audio stream has been disposed of Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO MediaEngine: [0xac48edf8]: Setting current track: 220679433, initial offset: 0ms Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Clearing all streams Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: New stream: 7 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.470 [9143.9143] INFO HttpDownloader: [0xac684d90]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=c061ef87b2fed23032bac625c8d2fee4&request_ts=1751201053&track_id=220679433 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.471 [9143.9143] INFO HttpDownloader: [0xac63dea8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=220679433 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.471 [9143.9143] INFO HttpDownloader: [0xac49a358]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=4cb738e70f6780d22af5542ab21e74cc&request_ts=1751201053&track_id=220679433 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.471 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 7]: Running audio stream Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.471 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:13 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:13 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.513 [9143.9143] INFO MediaEngine: [0xac48edf8]: Setting next track: 220679434 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.514 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: New stream: 8 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.514 [9143.9143] INFO HttpDownloader: [0xac594508]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=cd2b6f3b8afc244d8d0d2f2752982717&request_ts=1751201053&track_id=220679434 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.514 [9143.9143] INFO HttpDownloader: [0xac9c9be8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=220679434 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.514 [9143.9143] INFO HttpDownloader: [0xac59cd08]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=a7587e7f61bf9882fb895b8b77d7a2af&request_ts=1751201053&track_id=220679434 Jun 29 21:44:13 rivo-toshi qobuz-connect[9143]: 20250629 21:44:13.516 [9143.9143] INFO MediaEngine: [0xac48edf8]: Waiting for current stream to start before starting audio renderer Jun 29 21:44:13 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:13 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:13 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:13 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:13 rivo-toshi volumio[3271]: info: MCU Signalled Playback Inactive Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.383 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Received SetState message: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.383 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playing state: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.383 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playback position: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.383 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Queue version: 3.2 Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.383 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Current track: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.383 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Next track: TID: 220679434, QID: 1, Context UUID: 85b97795-fe3b-4836-a94e-44b7abb98628 Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.448 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 8]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=220679434&fmt=6&profile=raw&app_id=174516466&cid=2464732&etsp=1751204654&hmac=K7Iy3Ad7YBrZl4T0-DlATYxKBPM Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.455 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 7]: Metadata became available: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.455 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Title: Mazurka No. 31 in A-Flat Major, Op. 50 No. 2. Allegretto Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.455 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Artist: Pavel Kolesnikov Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.455 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album: Chopin: Mazurkas Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.456 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album art URL: https://static.qobuz.com/images/covers/ab/is/teemsim1disab_600.jpg Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.469 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 7]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=220679433&fmt=6&profile=raw&app_id=174516466&cid=2464732&etsp=1751204654&hmac=7QBVpwHXWlmz88KGgbRT3_9Ypak Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.535 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 7]: stream information have been fetched Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.535 [9143.9143] INFO UrlAudioSource: [0xac632ca0]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=220679433&fmt=6&profile=raw&app_id=174516466&cid=2464732&etsp=1751204654&hmac=7QBVpwHXWlmz88KGgbRT3_9Ypak Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.535 [9143.9143] INFO ContentFetcher: [0xac6b8c38]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=220679433&fmt=6&profile=raw&app_id=174516466&cid=2464732&etsp=1751204654&hmac=7QBVpwHXWlmz88KGgbRT3_9Ypak, offset: 0 Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO AudioRenderer: [0xac48f018]: Starting audio renderer, initial playback state: Playing Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO SampleApp: [Stream 7]: New audio stream (starting from 0ms) Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO SampleApp: [Stream 7]: Stream metadata became available: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO SampleApp: Title: Mazurka No. 31 in A-Flat Major, Op. 50 No. 2. Allegretto Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO SampleApp: Artist: Pavel Kolesnikov Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO SampleApp: Album: Chopin: Mazurkas Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.536 [9143.9143] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/ab/is/teemsim1disab_600.jpg Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.539 [9143.9143] INFO SampleApp: Initiating playback, initial state: Playing Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: QobuzConnect: alread currrent service, send playback confirmation Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.738 [9143.9143] INFO SampleApp: Playback state changed: Playing Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.738 [9143.9143] INFO StreamingEventReporter: [0xac48f950]: Reporting streaming started event Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.738 [9143.9143] INFO HttpDownloader: [0xac48f9a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.738 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.738 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.739 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.740 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending FileAudioQualityChanged message Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.740 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.741 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 8]: Metadata became available: Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.741 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Title: Mazurka No. 34 in C Major, Op. 56 No. 2. Vivace Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.741 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Artist: Pavel Kolesnikov Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.742 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album: Chopin: Mazurkas Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.742 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album art URL: https://static.qobuz.com/images/covers/ab/is/teemsim1disab_600.jpg Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:14 rivo-toshi volumio[3271]: info: [LastFM] Current track has sufficient metadata: title (Mazurka No. 31 in A-Flat Major, Op. 50 No. 2. Allegretto) and artist (Pavel Kolesnikov) passed on explicitly Jun 29 21:44:14 rivo-toshi volumio[3271]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:14 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:14 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:14 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:14 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:14 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:14 rivo-toshi qobuz-connect[9143]: 20250629 21:44:14.907 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 8]: stream information have been fetched Jun 29 21:44:14 rivo-toshi volumio[3271]: info: MCU Signalled Playback Active Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.618 [9143.9143] INFO UrlAudioSource: [0xac632ca0]: Content info extracted Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.619 [9143.9143] INFO UrlAudioSource: [0xac632ca0]: Size: 7737784 Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.624 [9143.11343] INFO AudioDecoder: [0xacc6c338]: Stream info: Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.624 [9143.11343] INFO AudioDecoder: [0xacc6c338]: Total samples: 8256696 Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.624 [9143.11343] INFO AudioDecoder: [0xacc6c338]: Sample rate: 44100 Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.624 [9143.11343] INFO AudioDecoder: [0xacc6c338]: Channel count: 2 Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.624 [9143.11343] INFO AudioDecoder: [0xacc6c338]: Bits per sample: 16 Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.624 [9143.11343] INFO AudioDecoder: [0xacc6c338]: Duration: 187226 Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.625 [9143.9143] INFO UrlAudioSource: [0xac632ca0]: Audio properties have changed Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.757 [9143.9143] WARNING SampleApp: Unable to query available space in ALSA audio sink, trying to recover Jun 29 21:44:16 rivo-toshi volumio[3271]: info: Executing endpoint metavolumio Jun 29 21:44:16 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 29 21:44:16 rivo-toshi volumio[3271]: info: Executing endpoint metavolumio Jun 29 21:44:16 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 29 21:44:16 rivo-toshi volumio[3271]: info: Executing endpoint metavolumio Jun 29 21:44:16 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 29 21:44:16 rivo-toshi qobuz-connect[9143]: 20250629 21:44:16.902 [9143.9143] WARNING SampleApp: Unable to query available space in ALSA audio sink, trying to recover Jun 29 21:44:24 rivo-toshi qobuz-connect[9143]: 20250629 21:44:24.737 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:24 rivo-toshi qobuz-connect[9143]: 20250629 21:44:24.738 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:24 rivo-toshi qobuz-connect[9143]: 20250629 21:44:24.738 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:24 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:24 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:24 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:24 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:34 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:34 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:34 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:34 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:34 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:34 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:34 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:34 rivo-toshi qobuz-connect[9143]: 20250629 21:44:34.748 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:34 rivo-toshi qobuz-connect[9143]: 20250629 21:44:34.753 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:34 rivo-toshi qobuz-connect[9143]: 20250629 21:44:34.753 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:34 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:34 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:34 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:34 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:44 rivo-toshi qobuz-connect[9143]: 20250629 21:44:44.737 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:44 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:44 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:44 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:44 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:44 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:44 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:44 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:44 rivo-toshi qobuz-connect[9143]: 20250629 21:44:44.744 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:44 rivo-toshi qobuz-connect[9143]: 20250629 21:44:44.744 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:44 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:44 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:44 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:44 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:44:54 rivo-toshi qobuz-connect[9143]: 20250629 21:44:54.737 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:44:54 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:54 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:44:54 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:44:54 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:44:54 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:44:54 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:44:54 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:44:54 rivo-toshi qobuz-connect[9143]: 20250629 21:44:54.744 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:44:54 rivo-toshi qobuz-connect[9143]: 20250629 21:44:54.745 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:44:54 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:44:54 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:44:54 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:44:54 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:45:04 rivo-toshi qobuz-connect[9143]: 20250629 21:45:04.737 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:45:04 rivo-toshi qobuz-connect[9143]: 20250629 21:45:04.737 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:45:04 rivo-toshi qobuz-connect[9143]: 20250629 21:45:04.737 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:45:04 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:04 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:04 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:04 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:04 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:04 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:04 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:04 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:04 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:45:04 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:45:04 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:45:09 rivo-toshi volumiologrotate[2831]: ls: cannot access '/var/log/samba/log.wb-RIVO': No such file or directory Jun 29 21:45:09 rivo-toshi volumiologrotate[2831]: ls: cannot access 'TOSHI': No such file or directory Jun 29 21:45:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:14 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:14 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:14 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:14 rivo-toshi qobuz-connect[9143]: 20250629 21:45:14.749 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:45:14 rivo-toshi qobuz-connect[9143]: 20250629 21:45:14.749 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:45:14 rivo-toshi qobuz-connect[9143]: 20250629 21:45:14.749 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:45:14 rivo-toshi volumio[3271]: info: Signalling Playback active due to playback status change Jun 29 21:45:14 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:45:14 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.607 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Received SetState message: Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.608 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playing state: Playing Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.609 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playback position: 0 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.609 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Queue version: 4.1 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.610 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Current track: TID: 121805013, QID: 4, Context UUID: 3d543cbe-02e2-473a-81ce-3af5890ee90f Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.610 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Next track: TID: 121805014, QID: 5, Context UUID: 3d543cbe-02e2-473a-81ce-3af5890ee90f Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.610 [9143.9143] INFO MediaEngine: [0xac48edf8]: Stopping playback, clearing tracks Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.611 [9143.9143] INFO MediaEngine: [0xac48edf8]: Initiating playback Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.611 [9143.9143] INFO AudioRenderer: [0xac48f018]: Stopping audio renderer Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.612 [9143.9143] INFO SampleApp: Stopping playback Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.620 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Clearing all streams Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.622 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 7]: Disposing of audio stream Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.622 [9143.9143] INFO ContentFetcher: [0xac6b8c38]: Canceling download Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.630 [9143.9143] INFO SampleApp: Playback state changed: Stopped Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.630 [9143.9143] INFO StreamingEventReporter: [0xac48f950]: Reporting streaming ended event Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO HttpDownloader: [0xac48f9a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO SampleApp: [Stream 7]: Audio stream has been disposed of Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO MediaEngine: [0xac48edf8]: Setting current track: 121805013, initial offset: 0ms Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Clearing all streams Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.631 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: New stream: 9 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.632 [9143.9143] INFO HttpDownloader: [0xac492038]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=a0a9932da82ca23ce714de492378e847&request_ts=1751201123&track_id=121805013 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.632 [9143.9143] INFO HttpDownloader: [0xac5713a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=121805013 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.632 [9143.9143] INFO HttpDownloader: [0xac9cba10]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=5e98b008071dd5f52c2bd21358c604dc&request_ts=1751201123&track_id=121805013 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.632 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 9]: Running audio stream Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.632 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.635 [9143.9143] INFO MediaEngine: [0xac48edf8]: Setting next track: 121805014 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.635 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: New stream: 10 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.635 [9143.9143] INFO HttpDownloader: [0xac4ba620]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=d0cf1071790e9a1e97a8dd85510ddc2c&request_ts=1751201123&track_id=121805014 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.635 [9143.9143] INFO HttpDownloader: [0xaca63040]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=121805014 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.635 [9143.9143] INFO HttpDownloader: [0xac503ea0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=c7614cd7fd9ff751a47dcad869b9a251&request_ts=1751201123&track_id=121805014 Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.638 [9143.9143] INFO MediaEngine: [0xac48edf8]: Waiting for current stream to start before starting audio renderer Jun 29 21:45:23 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:23 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:23 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:23 rivo-toshi volumio[3271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 29 21:45:23 rivo-toshi volumio[3271]: info: Updating RAAT Signal Path Jun 29 21:45:23 rivo-toshi volumio[3271]: info: MCU Signalled Playback Inactive Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.937 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 10]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=121805014&fmt=27&profile=raw&app_id=174516466&cid=2464732&etsp=1751204723&hmac=cvGskYHfS_V8-cs-t5SXNya6yhA Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.944 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 9]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=121805013&fmt=27&profile=raw&app_id=174516466&cid=2464732&etsp=1751204723&hmac=q5gHMEWU2LezW299LSopmQfdmi4 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.996 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 9]: stream information have been fetched Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.997 [9143.9143] INFO UrlAudioSource: [0xac9cf418]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=121805013&fmt=27&profile=raw&app_id=174516466&cid=2464732&etsp=1751204723&hmac=q5gHMEWU2LezW299LSopmQfdmi4 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.997 [9143.9143] INFO ContentFetcher: [0xac4e59f8]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=3451974&eid=121805013&fmt=27&profile=raw&app_id=174516466&cid=2464732&etsp=1751204723&hmac=q5gHMEWU2LezW299LSopmQfdmi4, offset: 0 Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.998 [9143.9143] INFO AudioRenderer: [0xac48f018]: Starting audio renderer, initial playback state: Playing Jun 29 21:45:23 rivo-toshi qobuz-connect[9143]: 20250629 21:45:23.999 [9143.9143] INFO SampleApp: [Stream 9]: New audio stream (starting from 0ms) Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: QobuzConnect: alread currrent service, send playback confirmation Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.002 [9143.9143] INFO SampleApp: Initiating playback, initial state: Playing Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.375 [9143.9143] INFO SampleApp: Playback state changed: Playing Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.375 [9143.9143] INFO StreamingEventReporter: [0xac48f950]: Reporting streaming started event Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.375 [9143.9143] INFO HttpDownloader: [0xac48f9a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.375 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Need to send state update Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.376 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending StateUpdated message Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.376 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending FileAudioQualityChanged message Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Received SetState message: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playing state: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Playback position: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Queue version: 4.2 Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Current track: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.377 [9143.9143] INFO ProtocolHandler: [0xac48f538]: Next track: TID: 121805014, QID: 5, Context UUID: 3d543cbe-02e2-473a-81ce-3af5890ee90f Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.378 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.378 [9143.9143] INFO QConnectMessageSender: [0xac615038]: Sending DeviceAudioQualityChanged message Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.378 [9143.9143] INFO QwspMessageSender: [0xac57f880]: Sending Payload message Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 10]: Metadata became available: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Title: Mazurka No. 37 in A-Flat Major, Op. 59 No. 2 Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Artist: マルタ・アルゲリッチ Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album: Chopin: The Legendary 1965 Recording (2021 Remastered Version) Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album art URL: https://static.qobuz.com/images/covers/cc/ka/sizpxmoywkacc_600.jpg Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 10]: stream information have been fetched Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: [Stream 9]: Metadata became available: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Title: Mazurka No. 36 in A Minor, Op. 59 No. 1 Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Artist: マルタ・アルゲリッチ Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album: Chopin: The Legendary 1965 Recording (2021 Remastered Version) Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.380 [9143.9143] INFO AudioStreamManager: [0xac48eee0]: Album art URL: https://static.qobuz.com/images/covers/cc/ka/sizpxmoywkacc_600.jpg Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.381 [9143.9143] INFO SampleApp: [Stream 9]: Stream metadata became available: Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.381 [9143.9143] INFO SampleApp: Title: Mazurka No. 36 in A Minor, Op. 59 No. 1 Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.381 [9143.9143] INFO SampleApp: Artist: マルタ・アルゲリッチ Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.381 [9143.9143] INFO SampleApp: Album: Chopin: The Legendary 1965 Recording (2021 Remastered Version) Jun 29 21:45:24 rivo-toshi qobuz-connect[9143]: 20250629 21:45:24.381 [9143.9143] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/cc/ka/sizpxmoywkacc_600.jpg Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::servicePushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreStateMachine::pushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioPushState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: CoreCommandRouter::volumioGetState Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output update for this device Jun 29 21:45:24 rivo-toshi volumio[3271]: info: MRS: Pushing multiroomSync output Jun 29 21:45:24 rivo-toshi volumio[3271]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Jun 29 21:45:24 rivo-toshi volumio[3271]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 29 21:45:24 rivo-toshi volumio[3271]: TypeError: Cannot read property 'indexOf' of undefined Jun 29 21:45:24 rivo-toshi volumio[3271]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25) Jun 29 21:45:24 rivo-toshi volumio[3271]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Decoder.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/node_modules/component-emitter/index.js:134:20) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Decoder.add (/data/plugins/user_interface/lastfm/node_modules/socket.io-parser/index.js:246:12) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Manager.ondata (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:322:16) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20) Jun 29 21:45:24 rivo-toshi volumio[3271]: at Socket.onPacket (/data/plugins/user_interface/lastfm/node_modules/engine.io-client/lib/socket.js:451:14) Jun 29 21:45:24 rivo-toshi volumio[3271]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 29 21:45:25 rivo-toshi sudo[11531]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-29 21:44 Jun 29 21:45:25 rivo-toshi sudo[11531]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 06:24:39 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="c8a59422b1bfedffc72f72cef58ad20b"