-- Logs begin at Sun 2025-12-28 19:03:25 UTC, end at Sun 2025-12-28 19:06:51 UTC. -- Dec 28 19:05:00 ifi-neo-stream3 node[505]: Can't invoke metadata.sh. Error: Command failed: /usr/bin/metadata.sh /tmp/ifi-albumart Dec 28 19:05:00 ifi-neo-stream3 node[505]: identify-im6.q16: no decode delegate for this image format `' @ error/constitute.c/ReadImage/560. Dec 28 19:05:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:00 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:00 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:01 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:05:01 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:01 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:01 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:01 ifi-neo-stream3 node[505]: volumio Dec 28 19:05:01 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.696 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 40 Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.699 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetState message: Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.700 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playing state: Paused Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.701 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playback position: Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.702 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Queue version: Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.703 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Current track: Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.704 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Next track: Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.705 [1924.1924] INFO MediaEngine: [0xab282fa8]: Pausing playback Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.705 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Pause Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.706 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Pause Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.707 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Pausing audio renderer Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.707 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback is paused Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.707 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Playing -> Pausing Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.708 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Playing -> Pausing Dec 28 19:05:02 ifi-neo-stream3 play[1886]: 20251228 19:05:02.708 [1924.1924] INFO SampleApp: Pausing playback Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Stop Qobuz Playback Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: qobuz_connect , stopQobuzPlayback Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: Qobuz Connect playback stop Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: Qobuz Connect Playback Stopped, clearing state Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::resetVolumioState Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::getcurrentVolume Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:02 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.722 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Transition to paused state has been acknowledged Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.722 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Pausing -> Paused Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Pausing -> Paused Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Playing -> Paused Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Pause Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] INFO SampleApp: Playback state changed: Paused Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] ERROR SampleApp: Unable to get buffered frame count from ALSA audio sink: device is not open Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 119892 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming ended event Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: End position: 119892ms Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Duration: 6179ms Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] ERROR SampleApp: Unable to get buffered frame count from ALSA audio sink: device is not open Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 119892 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Need to send state update Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending StateUpdated message Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Playback state: Paused Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current position: 119892 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Duration: 545866 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Queue version: 1.1 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current queue item ID: 13 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Next queue item ID: -1 Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Stopping periodic state updates Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.723 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is active but not playing, will deactivate in 3600s Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.724 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.724 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.724 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.725 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 119892ms Dec 28 19:05:03 ifi-neo-stream3 play[1886]: 20251228 19:05:03.969 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.728 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 38 Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.728 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: inactive Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.728 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Deactivate Renderer Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Deactivate Renderer Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Stopping playback session maintenance Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Stopping playback session maintenance Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer inactive Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: inactive Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine needs to be stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO MediaEngine: [0xab282fa8]: Reseting Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Reset Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO SampleApp: Renderer is now inactive Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Stopping audio renderer Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback is stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Paused -> Stopping Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Paused -> Stopping Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO SampleApp: Stopping playback Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Transition to stopped state has been acknowledged Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopping -> Stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopping -> Stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Paused -> Stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 2]: Disposing of audio stream Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.729 [1924.1924] INFO ContentFetcher: [0xab464e20]: Canceling download Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.736 [1924.1924] DEBUG Ringbuffer: [0xab437e10]: Freeing Audio Ringbuffer Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab3ff788]: Freeing Audio Stream Info Fetcher Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MetadataFetcher: [0xab367b38]: Freeing Metadata Fetcher Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab28f928]: Freeing Playback URL Fetcher Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] INFO SampleApp: Playback state changed: Stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Not sending state update because the renderer is not active Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Running -> Nonexistent Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] INFO SampleApp: [Stream 2]: Audio stream has been disposed of Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Reset Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Reset Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine has been stopped Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Invalidating track properties and device audio format Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Active -> Inactive (Connected) Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Deactivate Renderer Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: NONE Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:05:05 ifi-neo-stream3 play[1886]: 20251228 19:05:05.740 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.332 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 40 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.332 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 111 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: active Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Activate Renderer Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Activate Renderer Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer active Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: active Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Starting playback session maintenance Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Starting playback session maintenance Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE PlaybackSessionManager: [0xab282d10]: Not refreshing playback session because it's not needed Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Inactive (Connected) -> Active Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Activate Renderer Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending VolumeChanged message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Volume: 100 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending VolumeMuted message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Muted: true Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending MaxAudioQualityChanged message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Max quality: HIRES_L3 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO SampleApp: Renderer is now active Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetState message: Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playing state: Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playback position: 119892 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Queue version: 1.1 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Current track: TID: 252601475, QID: 13, Context UUID: 1c1c7e35-04eb-4f9f-b447-5ec64f1837f6 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.333 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Next track: TID: 4294967295, QID: -1, Context UUID: Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO MediaEngine: [0xab282fa8]: Initiating playback Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: InitiatePlayback Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetLoopMode message: Off Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO PlaybackControlsManager: [0xab283380]: Setting new loop mode: Off Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: 252601475, initial offset: 119892ms Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.334 [1924.1924] INFO AudioStreamManager: [0xab283090]: New stream: 3 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab28f928]: Creating Playback URL Fetcher for track: 252601475 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] INFO HttpDownloader: [0xab2879a8]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=0c7c305c11639f59fa8d8c4252bba2f4&request_ts=1766948710&track_id=252601475 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] DEBUG MetadataFetcher: [0xab4720c8]: Creating Metadata Fetcher for track: 252601475 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] INFO HttpDownloader: [0xab284668]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=252601475 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab2bec58]: Creating Audio Stream Info Fetcher for track: 252601475 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] INFO HttpDownloader: [0xab4a2348]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=37bb315fa0a27dc516e48ad44f9866af&request_ts=1766948710&track_id=252601475 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 3]: Running audio stream Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetShuffleMode message: disabled Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.335 [1924.1924] INFO PlaybackControlsManager: [0xab283380]: Setting new shuffle mode: disabled Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.337 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Nonexistent -> Created Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.337 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.337 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.337 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.337 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: InitiatePlayback Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.337 [1924.1924] INFO MediaEngine: [0xab282fa8]: Waiting for current stream to start before starting audio renderer Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.425 [1924.1924] TRACE MetadataFetcher: [0xab4720c8]: Track 252601475 doesn't have a valid version field Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] TRACE MetadataFetcher: [0xab4720c8]: Track 252601475 doesn't have a valid work field Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] TRACE MetadataFetcher: [0xab4720c8]: Track 252601475 doesn't have a valid album version field Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 3]: Metadata became available: Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] INFO AudioStreamManager: [0xab283090]: Title: Give unto the Lord, Op. 74 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] INFO AudioStreamManager: [0xab283090]: Artist: Adrian Partington Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] INFO AudioStreamManager: [0xab283090]: Album: Elgar: Cathedral Music Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.426 [1924.1924] INFO AudioStreamManager: [0xab283090]: Album art URL: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.433 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 3]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952310&hmac=7Bt0kAKyw0PUC-EIVsiMAYXz29U Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.533 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 3]: stream information have been fetched Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.533 [1924.1924] INFO UrlAudioSource: [0xab44bd08]: Starting URL audio source, initial position: 119892ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952310&hmac=7Bt0kAKyw0PUC-EIVsiMAYXz29U Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.533 [1924.1924] TRACE AudioSource: [0xab44bd08]: State changed: Idle -> Running Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.533 [1924.1924] DEBUG Ringbuffer: [0xab467398]: Creating Audio Ringbuffer Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO ContentFetcher: [0xab4b78a0]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952310&hmac=7Bt0kAKyw0PUC-EIVsiMAYXz29U, offset: 0 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Created -> Info Retrieved Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Info Retrieved -> Running Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Starting audio renderer, initial playback state: Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopped -> Initiating (Paused) Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO SampleApp: [Stream 3]: New audio stream (starting from 119891ms) Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO SampleApp: [Stream 3]: Stream metadata became available: Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO SampleApp: Title: Give unto the Lord, Op. 74 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO SampleApp: Artist: Adrian Partington Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO SampleApp: Album: Elgar: Cathedral Music Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.534 [1924.1924] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopped -> Initiating (Paused) Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] INFO SampleApp: Initiating playback, initial state: Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Playback initiated (paused state) Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Initiating (Paused) -> Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Initiating (Paused) -> Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Stopped -> Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: InitiatePlayback Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] INFO SampleApp: Playback state changed: Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] ERROR SampleApp: Unable to get buffered frame count from ALSA audio sink: device is not open Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 119890 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Need to send state update Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending StateUpdated message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Playback state: Paused Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current position: 119890 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Duration: 545866 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Queue version: 1.1 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current queue item ID: 13 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Next queue item ID: -1 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending FileAudioQualityChanged message Dec 28 19:05:10 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Sample rate: 44100 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Bit depth: 16 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Channel count: 2 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.535 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Audio quality: CD Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending DeviceAudioQualityChanged message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Sample rate: 44100 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Bit depth: 16 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.536 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Channel count: 2 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.537 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.537 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.537 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.537 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 119890ms Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.669 [1924.1924] INFO UrlAudioSource: [0xab44bd08]: Content info extracted Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.669 [1924.1924] INFO UrlAudioSource: [0xab44bd08]: Size: 32292072 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.670 [1924.3178] INFO AudioDecoder: [0xab42b768]: Stream info: Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.670 [1924.3178] INFO AudioDecoder: [0xab42b768]: Total samples: 24072720 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.670 [1924.3178] INFO AudioDecoder: [0xab42b768]: Sample rate: 44100 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.671 [1924.3178] INFO AudioDecoder: [0xab42b768]: Channel count: 2 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.671 [1924.3178] INFO AudioDecoder: [0xab42b768]: Bits per sample: 16 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.671 [1924.3178] INFO AudioDecoder: [0xab42b768]: Duration: 545866 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.673 [1924.1924] INFO UrlAudioSource: [0xab44bd08]: Audio properties have changed Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.673 [1924.1924] INFO UrlAudioSource: [0xab44bd08]: Seeking input stream to byte offset: 8100727 Dec 28 19:05:10 ifi-neo-stream3 play[1886]: 20251228 19:05:10.673 [1924.1924] INFO ContentFetcher: [0xab4b78a0]: Adjusting download offset to: 8100727 Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.138 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 40 Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.138 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetState message: Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playing state: Playing Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playback position: Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Queue version: Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Current track: Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Next track: Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO MediaEngine: [0xab282fa8]: Resuming playback Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Resume Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Resume Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Resuming audio renderer Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Paused -> Resuming Dec 28 19:05:13 ifi-neo-stream3 play[1886]: 20251228 19:05:13.139 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Paused -> Resuming Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: request:pause Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::serviceStop Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: error: Could not retrieve plugin music_service qobuz_connect Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: error: WARNING: No stop method for service qobuz_connect Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Start Qobuz PlaybackRoutine Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: qobuz_connect , startQobuzPlayback Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: Qobuz Connect playback start Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:05:13 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:13 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:13 ifi-neo-stream3 node[505]: metadata.album: http://127.0.0.1:3000 Dec 28 19:05:13 ifi-neo-stream3 node[505]: volumio Dec 28 19:05:13 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.155 [1924.1924] TRACE SampleApp: ALSA PCM's descriptor count: 1 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.155 [1924.1924] INFO SampleApp: Resuming playback Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.156 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Transition to playing state (resume) has been acknowledged Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.156 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Resuming -> Playing Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.156 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Resuming -> Playing Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.156 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Paused -> Playing Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.156 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Resume Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback started, time until playback gets near the end: 415975ms Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] INFO SampleApp: Playback state changed: Playing Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 119891 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming started event Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Track ID: 252601475 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Start position: 119891ms Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Context UUID: 1c1c7e35-04eb-4f9f-b447-5ec64f1837f6 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Blob ID: 100000.EKzbtcvIdshmxViF6LWl_ji_XgELAMtgd9qSfHtuC-ZCOonko7rhr35R3YgWHA7C.qy6YGpMWJbtHZ6RfsuhEIUs50Lg Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.157 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 119891 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Need to send state update Dec 28 19:05:14 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:14 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:14 ifi-neo-stream3 node[505]: in qobuz-connect Dec 28 19:05:14 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:14 ifi-neo-stream3 node[505]: qobuz-connect Dec 28 19:05:14 ifi-neo-stream3 node[505]: message: {"title":"Give unto the Lord, Op. 74","artist":"Adrian Partington","album":"Elgar: Cathedral Music","albumart":"https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg","duration":"545","seek":"0"} Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending StateUpdated message Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Playback state: Playing Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current position: 119891 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Duration: 545866 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Queue version: 1.1 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current queue item ID: 13 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Next queue item ID: -1 Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.158 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is actively playing Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.159 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.159 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.159 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.161 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 119891ms Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.163 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 119891ms Dec 28 19:05:14 ifi-neo-stream3 play[1886]: 20251228 19:05:14.250 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:05:14 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:14 ifi-neo-stream3 volumiologrotate[453]: ls: cannot access '/var/log/samba/log.wb-NEO': No such file or directory Dec 28 19:05:14 ifi-neo-stream3 volumiologrotate[453]: ls: cannot access 'STREAM3': No such file or directory Dec 28 19:05:14 ifi-neo-stream3 node[505]: Can't invoke metadata.sh. Error: Command failed: /usr/bin/metadata.sh /tmp/ifi-albumart Dec 28 19:05:14 ifi-neo-stream3 node[505]: identify-im6.q16: no decode delegate for this image format `' @ error/constitute.c/ReadImage/560. Dec 28 19:05:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:15 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:15 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:16 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:16 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:16 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:16 ifi-neo-stream3 node[505]: volumio Dec 28 19:05:16 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:05:16 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:17 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 38 Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: inactive Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Deactivate Renderer Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Deactivate Renderer Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Stopping playback session maintenance Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Stopping playback session maintenance Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer inactive Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: inactive Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine needs to be stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] INFO MediaEngine: [0xab282fa8]: Reseting Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Reset Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Stopping periodic state updates Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] INFO SampleApp: Renderer is now inactive Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.393 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.394 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Stopping audio renderer Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.394 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback is stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.394 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Playing -> Stopping Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.394 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Playing -> Stopping Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.394 [1924.1924] INFO SampleApp: Stopping playback Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.410 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Transition to stopped state has been acknowledged Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.410 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopping -> Stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.411 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopping -> Stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.411 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Playing -> Stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.411 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.411 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 3]: Disposing of audio stream Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.411 [1924.1924] INFO ContentFetcher: [0xab4b78a0]: Canceling download Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.419 [1924.1924] DEBUG Ringbuffer: [0xab467398]: Freeing Audio Ringbuffer Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab2bec58]: Freeing Audio Stream Info Fetcher Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] DEBUG MetadataFetcher: [0xab4720c8]: Freeing Metadata Fetcher Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab28f928]: Freeing Playback URL Fetcher Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] INFO SampleApp: Playback state changed: Stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming ended event Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: End position: 124148ms Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Duration: 4257ms Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.420 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Not sending state update because the renderer is not active Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is active but not playing, will deactivate in 3600s Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Running -> Nonexistent Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] INFO SampleApp: [Stream 3]: Audio stream has been disposed of Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Reset Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.421 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Reset Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine has been stopped Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Invalidating track properties and device audio format Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Active -> Inactive (Connected) Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Deactivate Renderer Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: NONE Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.422 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: Airplay started streaming, receiving metadatas Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: Airplay started streaming, receiving metadatas Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stPlaybackTimer Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::updateTrackBlock Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrackBlock Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:18 ifi-neo-stream3 shairport-sync[2996]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 19:05:18 ifi-neo-stream3 shairport-sync[2996]: Dload Upload Total Spent Left Speed Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: ControllerMpd::stop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: verbose: ControllerMpd::sendMpdCommand stop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:18 ifi-neo-stream3 shairport-sync[2996]: [158B blob data] Dec 28 19:05:18 ifi-neo-stream3 shairport-sync[2996]: Dload Upload Total Spent Left Speed Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: successsuccess Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: sendMpdCommand stop took 18 milliseconds Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests AirplayActive Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Dec 28 19:05:18 ifi-neo-stream3 shairport-sync[2996]: [158B blob data] Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Start Airplay PlaybackRoutine Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: Airplay playback start Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:18 ifi-neo-stream3 shairport-sync[2996]: [136B blob data] Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: success Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: Updating volume from AirPlay: -24; 20% Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: VolumeController::SetAlsaVolume20 Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:18 ifi-neo-stream3 play[1886]: 20251228 19:05:18.772 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:21 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:21 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:21 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:21 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:22 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:22 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:22 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:22 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:22 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:22 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:22 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:23 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:23 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:23 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:23 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:23 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:23 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:23 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:24 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:24 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:24 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:24 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:24 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:24 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:24 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 40 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: active Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Activate Renderer Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Activate Renderer Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer active Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: active Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Starting playback session maintenance Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Starting playback session maintenance Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] TRACE PlaybackSessionManager: [0xab282d10]: Not refreshing playback session because it's not needed Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Inactive (Connected) -> Active Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Activate Renderer Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.078 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending VolumeChanged message Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Volume: 100 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending VolumeMuted message Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Muted: true Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending MaxAudioQualityChanged message Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Max quality: HIRES_L3 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] INFO SampleApp: Renderer is now active Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.079 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 111 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetState message: Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playing state: Playing Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playback position: 130679 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Queue version: 1.1 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Current track: TID: 252601475, QID: 13, Context UUID: 1c1c7e35-04eb-4f9f-b447-5ec64f1837f6 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Next track: TID: 4294967295, QID: -1, Context UUID: Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.100 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO MediaEngine: [0xab282fa8]: Initiating playback Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: InitiatePlayback Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetLoopMode message: Off Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO PlaybackControlsManager: [0xab283380]: Setting new loop mode: Off Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: 252601475, initial offset: 130679ms Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO AudioStreamManager: [0xab283090]: New stream: 4 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab286ae8]: Creating Playback URL Fetcher for track: 252601475 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO HttpDownloader: [0xab284668]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=23862104d85ca859aaa59e95f44b2ec9&request_ts=1766948725&track_id=252601475 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG MetadataFetcher: [0xab2879a8]: Creating Metadata Fetcher for track: 252601475 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO HttpDownloader: [0xab29a718]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=252601475 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab2bec58]: Creating Audio Stream Info Fetcher for track: 252601475 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO HttpDownloader: [0xab49eea0]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=78f03a29da00bbfdd667857cf0feba46&request_ts=1766948725&track_id=252601475 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.101 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 4]: Running audio stream Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.102 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.102 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetShuffleMode message: disabled Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.102 [1924.1924] INFO PlaybackControlsManager: [0xab283380]: Setting new shuffle mode: disabled Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.103 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Nonexistent -> Created Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.104 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.104 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.104 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.104 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: InitiatePlayback Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.104 [1924.1924] INFO MediaEngine: [0xab282fa8]: Waiting for current stream to start before starting audio renderer Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] TRACE MetadataFetcher: [0xab2879a8]: Track 252601475 doesn't have a valid version field Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] TRACE MetadataFetcher: [0xab2879a8]: Track 252601475 doesn't have a valid work field Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] TRACE MetadataFetcher: [0xab2879a8]: Track 252601475 doesn't have a valid album version field Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 4]: Metadata became available: Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] INFO AudioStreamManager: [0xab283090]: Title: Give unto the Lord, Op. 74 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] INFO AudioStreamManager: [0xab283090]: Artist: Adrian Partington Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] INFO AudioStreamManager: [0xab283090]: Album: Elgar: Cathedral Music Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.225 [1924.1924] INFO AudioStreamManager: [0xab283090]: Album art URL: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.267 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 4]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952325&hmac=rNETQ8bnutRRjIgY-pu5lwfduyc Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 4]: stream information have been fetched Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO UrlAudioSource: [0xab4b0ef0]: Starting URL audio source, initial position: 130679ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952325&hmac=rNETQ8bnutRRjIgY-pu5lwfduyc Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] TRACE AudioSource: [0xab4b0ef0]: State changed: Idle -> Running Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] DEBUG Ringbuffer: [0xab28f8b0]: Creating Audio Ringbuffer Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO ContentFetcher: [0xab3fcb40]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952325&hmac=rNETQ8bnutRRjIgY-pu5lwfduyc, offset: 0 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Created -> Info Retrieved Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Info Retrieved -> Running Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Starting audio renderer, initial playback state: Playing Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopped -> Initiating (Playing) Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO SampleApp: [Stream 4]: New audio stream (starting from 130678ms) Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO SampleApp: [Stream 4]: Stream metadata became available: Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.428 [1924.1924] INFO SampleApp: Title: Give unto the Lord, Op. 74 Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.429 [1924.1924] INFO SampleApp: Artist: Adrian Partington Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.429 [1924.1924] INFO SampleApp: Album: Elgar: Cathedral Music Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.429 [1924.1924] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.429 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopped -> Initiating (Playing) Dec 28 19:05:25 ifi-neo-stream3 play[1886]: 20251228 19:05:25.429 [1924.1924] INFO SampleApp: Initiating playback, initial state: Playing Dec 28 19:05:25 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: request:pause Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::serviceStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: Airplay Stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: verbose: UNSET VOLATILE: Service: airplay_emulation Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: Stopping Airplay Playback and sending pause command to client via USR2 Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stPlaybackTimer Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::updateTrackBlock Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrackBlock Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: ControllerMpd::stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: verbose: ControllerMpd::sendMpdCommand stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: Stopping Airplay Playback and sending pause command to client via USR2 Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: sendMpdCommand stop took 52 milliseconds Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Start Qobuz PlaybackRoutine Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: qobuz_connect , startQobuzPlayback Dec 28 19:05:25 ifi-neo-stream3 sudo[3434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 2996 Dec 28 19:05:25 ifi-neo-stream3 sudo[3434]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:05:25 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:25 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:25 ifi-neo-stream3 node[505]: metadata.album: http://127.0.0.1:3000 Dec 28 19:05:25 ifi-neo-stream3 node[505]: volumio Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: Qobuz Connect playback start Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:05:25 ifi-neo-stream3 sudo[3435]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 2996 Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:25 ifi-neo-stream3 sudo[3435]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:05:25 ifi-neo-stream3 sudo[3434]: pam_unix(sudo:session): session closed for user root Dec 28 19:05:25 ifi-neo-stream3 sudo[3435]: pam_unix(sudo:session): session closed for user root Dec 28 19:05:25 ifi-neo-stream3 shairport-sync[2996]: {"time":1766948718692,"response":"startAirplayPlayback Success"} Dec 28 19:05:25 ifi-neo-stream3 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=12/USR2 Dec 28 19:05:25 ifi-neo-stream3 systemd[1]: shairport-sync.service: Failed with result 'signal'. Dec 28 19:05:25 ifi-neo-stream3 volumio[1143]: info: Shairport-Sync paused with USR2 Dec 28 19:05:25 ifi-neo-stream3 systemd[1]: Starting Internet Detect for iFi Streamer... Dec 28 19:05:25 ifi-neo-stream3 systemd[1]: ifi-system-internet.service: Succeeded. Dec 28 19:05:25 ifi-neo-stream3 systemd[1]: Started Internet Detect for iFi Streamer. Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.443 [1924.1924] TRACE SampleApp: ALSA PCM's descriptor count: 1 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.443 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Playback initiated (playing state) Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.443 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Initiating (Playing) -> Playing Dec 28 19:05:26 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:26 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:26 ifi-neo-stream3 node[505]: in qobuz-connect Dec 28 19:05:26 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:26 ifi-neo-stream3 node[505]: qobuz-connect Dec 28 19:05:26 ifi-neo-stream3 node[505]: message: {"title":"Give unto the Lord, Op. 74","artist":"Adrian Partington","album":"Elgar: Cathedral Music","albumart":"https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg","duration":"545","seek":"0"} Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.509 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Initiating (Playing) -> Playing Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.509 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Stopped -> Playing Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.509 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: InitiatePlayback Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback started, time until playback gets near the end: 405189ms Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] INFO SampleApp: Playback state changed: Playing Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 130677 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming started event Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Track ID: 252601475 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Start position: 130677ms Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Context UUID: 1c1c7e35-04eb-4f9f-b447-5ec64f1837f6 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Blob ID: 100000.kFicKxeeyAbPC1xYgn1-RPla2SSm1HsoAJUh2-zFMy5PoeHk6nVfOv1QlecYZUiu.no6FOdTMf5qI5GwT7k-uNx1zP6c Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 130677 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.529 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Need to send state update Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending StateUpdated message Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Playback state: Playing Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current position: 130677 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Duration: 545866 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Queue version: 1.1 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current queue item ID: 13 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Next queue item ID: -1 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is actively playing Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.530 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending FileAudioQualityChanged message Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Sample rate: 44100 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Bit depth: 16 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Channel count: 2 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Audio quality: CD Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.531 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending DeviceAudioQualityChanged message Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Sample rate: 44100 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Bit depth: 16 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Channel count: 2 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 130677ms Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.532 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 130677ms Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.553 [1924.1924] INFO UrlAudioSource: [0xab4b0ef0]: Content info extracted Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.553 [1924.1924] INFO UrlAudioSource: [0xab4b0ef0]: Size: 32292072 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.3463] INFO AudioDecoder: [0xab444c70]: Stream info: Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.3463] INFO AudioDecoder: [0xab444c70]: Total samples: 24072720 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.3463] INFO AudioDecoder: [0xab444c70]: Sample rate: 44100 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.3463] INFO AudioDecoder: [0xab444c70]: Channel count: 2 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.3463] INFO AudioDecoder: [0xab444c70]: Bits per sample: 16 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.3463] INFO AudioDecoder: [0xab444c70]: Duration: 545866 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.1924] INFO UrlAudioSource: [0xab4b0ef0]: Audio properties have changed Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.1924] INFO UrlAudioSource: [0xab4b0ef0]: Seeking input stream to byte offset: 8683486 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.554 [1924.1924] INFO ContentFetcher: [0xab3fcb40]: Adjusting download offset to: 8683486 Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioGetState Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: Restarting Shairport-Sync after stop Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioGetState Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: Restarting Shairport-Sync after stop Dec 28 19:05:26 ifi-neo-stream3 sudo[3465]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 28 19:05:26 ifi-neo-stream3 sudo[3465]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.677 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:05:26 ifi-neo-stream3 sudo[3468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 28 19:05:26 ifi-neo-stream3 sudo[3468]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:05:26 ifi-neo-stream3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 28 19:05:26 ifi-neo-stream3 sudo[3465]: pam_unix(sudo:session): session closed for user root Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.738 [1924.1924] INFO UrlAudioSource: [0xab4b0ef0]: Seeking input stream to byte offset: 8678004 Dec 28 19:05:26 ifi-neo-stream3 play[1886]: 20251228 19:05:26.738 [1924.1924] INFO ContentFetcher: [0xab3fcb40]: Adjusting download offset to: 8678004 Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: Shairport-Sync retarted Dec 28 19:05:26 ifi-neo-stream3 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 28 19:05:26 ifi-neo-stream3 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Dec 28 19:05:26 ifi-neo-stream3 systemd[1]: shairport-sync.service: Succeeded. Dec 28 19:05:26 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:26 ifi-neo-stream3 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 28 19:05:26 ifi-neo-stream3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 28 19:05:26 ifi-neo-stream3 sudo[3468]: pam_unix(sudo:session): session closed for user root Dec 28 19:05:26 ifi-neo-stream3 volumio[1143]: info: Shairport-Sync retarted Dec 28 19:05:27 ifi-neo-stream3 node[505]: Can't invoke metadata.sh. Error: Command failed: /usr/bin/metadata.sh /tmp/ifi-albumart Dec 28 19:05:27 ifi-neo-stream3 node[505]: identify-im6.q16: no decode delegate for this image format `' @ error/constitute.c/ReadImage/560. Dec 28 19:05:27 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:27 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:27 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:27 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:27 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:27 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:28 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:05:28 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:28 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:28 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:05:28 ifi-neo-stream3 node[505]: volumio Dec 28 19:05:28 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:29 ifi-neo-stream3 node[505]: Download data end Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.648 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 38 Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.651 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: inactive Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.652 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Deactivate Renderer Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.653 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Deactivate Renderer Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.653 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Stopping playback session maintenance Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.654 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Stopping playback session maintenance Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.655 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer inactive Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.655 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: inactive Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.656 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine needs to be stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.656 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.657 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.658 [1924.1924] INFO MediaEngine: [0xab282fa8]: Reseting Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.658 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Reset Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.659 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.659 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Stopping periodic state updates Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] INFO SampleApp: Renderer is now inactive Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Stopping audio renderer Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback is stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Playing -> Stopping Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Playing -> Stopping Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.660 [1924.1924] INFO SampleApp: Stopping playback Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.690 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Transition to stopped state has been acknowledged Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.691 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopping -> Stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.691 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopping -> Stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.691 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Playing -> Stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.691 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.691 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 4]: Disposing of audio stream Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.691 [1924.1924] INFO ContentFetcher: [0xab3fcb40]: Canceling download Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.701 [1924.1924] DEBUG Ringbuffer: [0xab28f8b0]: Freeing Audio Ringbuffer Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.702 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab2bec58]: Freeing Audio Stream Info Fetcher Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.702 [1924.1924] DEBUG MetadataFetcher: [0xab2879a8]: Freeing Metadata Fetcher Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.702 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab286ae8]: Freeing Playback URL Fetcher Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.702 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.702 [1924.1924] INFO SampleApp: Playback state changed: Stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.702 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming ended event Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: End position: 135847ms Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Duration: 5170ms Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Not sending state update because the renderer is not active Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is active but not playing, will deactivate in 3600s Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Running -> Nonexistent Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] INFO SampleApp: [Stream 4]: Audio stream has been disposed of Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Reset Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.703 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Reset Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine has been stopped Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Invalidating track properties and device audio format Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Active -> Inactive (Connected) Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Deactivate Renderer Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: NONE Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.704 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:05:31 ifi-neo-stream3 play[1886]: 20251228 19:05:31.899 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: Airplay started streaming, receiving metadatas Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: Airplay started streaming, receiving metadatas Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stPlaybackTimer Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::updateTrackBlock Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrackBlock Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: ControllerMpd::stop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: verbose: ControllerMpd::sendMpdCommand stop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: successsuccess Dec 28 19:05:33 ifi-neo-stream3 shairport-sync[3472]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 19:05:33 ifi-neo-stream3 shairport-sync[3472]: Dload Upload Total Spent Left Speed Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: sendMpdCommand stop took 17 milliseconds Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests AirplayActive Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Dec 28 19:05:33 ifi-neo-stream3 shairport-sync[3472]: [158B blob data] Dec 28 19:05:33 ifi-neo-stream3 shairport-sync[3472]: Dload Upload Total Spent Left Speed Dec 28 19:05:33 ifi-neo-stream3 shairport-sync[3472]: [158B blob data] Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Start Airplay PlaybackRoutine Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: Airplay playback start Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:05:33 ifi-neo-stream3 shairport-sync[3472]: [136B blob data] Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: success Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: Updating volume from AirPlay: -20; 33% Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: VolumeController::SetAlsaVolume33 Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:33 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:34 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:35 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:35 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:35 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:35 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:35 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:36 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:36 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:05:36 ifi-neo-stream3 node[505]: metadata.album: /albumart Dec 28 19:05:36 ifi-neo-stream3 node[505]: airplay Dec 28 19:05:36 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:37 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:37 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:38 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:38 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:39 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:39 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:40 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:40 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:41 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:41 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:42 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:42 ifi-neo-stream3 shairport-sync[3472]: {"time":1766948733763,"response":"startAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 19:05:42 ifi-neo-stream3 shairport-sync[3472]: Dload Upload Total Spent Left Speed Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Stop Airplay Playback Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: Airplay playback stop Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: Airplay Playback Stopped, clearing state Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::resetVolumioState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::getcurrentVolume Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioRetrievevolume Dec 28 19:05:42 ifi-neo-stream3 shairport-sync[3472]: [158B blob data] Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:43 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:43 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:44 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:44 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:45 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:45 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:46 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:46 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:47 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:47 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:48 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:48 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:49 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:49 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:50 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:50 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:51 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:51 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:52 ifi-neo-stream3 shairport-sync[3472]: {"time":1766948742723,"response":"stopAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 19:05:52 ifi-neo-stream3 shairport-sync[3472]: Dload Upload Total Spent Left Speed Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests AirplayInactive Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayInctive Dec 28 19:05:52 ifi-neo-stream3 shairport-sync[3472]: [158B blob data] Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:52 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:52 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:53 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:53 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:54 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:54 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:55 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:55 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:56 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:56 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:57 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:57 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:58 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:58 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:05:59 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:05:59 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:00 ifi-neo-stream3 systemd[1]: Starting Internet Detect for iFi Streamer... Dec 28 19:06:00 ifi-neo-stream3 systemd[1]: ifi-system-internet.service: Succeeded. Dec 28 19:06:00 ifi-neo-stream3 systemd[1]: Started Internet Detect for iFi Streamer. Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:00 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:00 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:01 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:01 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:02 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:02 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:03 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:03 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:04 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:04 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:05 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:05 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:06 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:06 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:07 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:07 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:08 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:08 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:09 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:09 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:10 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:10 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:11 ifi-neo-stream3 systemd[1]: Starting Internet Detect for iFi Streamer... Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:11 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:11 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:12 ifi-neo-stream3 systemd[1]: ifi-system-internet.service: Succeeded. Dec 28 19:06:12 ifi-neo-stream3 systemd[1]: Started Internet Detect for iFi Streamer. Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:12 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:12 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:13 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:13 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:14 ifi-neo-stream3 volumiologrotate[453]: ls: cannot access '/var/log/samba/log.wb-NEO': No such file or directory Dec 28 19:06:14 ifi-neo-stream3 volumiologrotate[453]: ls: cannot access 'STREAM3': No such file or directory Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:14 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:14 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:15 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:15 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:16 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:16 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:17 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:17 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 40 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: active Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Activate Renderer Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Activate Renderer Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer active Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: active Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Starting playback session maintenance Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Starting playback session maintenance Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] TRACE PlaybackSessionManager: [0xab282d10]: Not refreshing playback session because it's not needed Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Inactive (Connected) -> Active Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Activate Renderer Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending VolumeChanged message Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Volume: 100 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending VolumeMuted message Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Muted: true Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending MaxAudioQualityChanged message Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Max quality: HIRES_L3 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.879 [1924.1924] INFO SampleApp: Renderer is now active Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.880 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.880 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.880 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 111 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetState message: Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playing state: Playing Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Playback position: 183814 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Queue version: 1.1 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Current track: TID: 252601475, QID: 13, Context UUID: 1c1c7e35-04eb-4f9f-b447-5ec64f1837f6 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.918 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Next track: TID: 4294967295, QID: -1, Context UUID: Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO MediaEngine: [0xab282fa8]: Initiating playback Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: InitiatePlayback Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetLoopMode message: Off Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO PlaybackControlsManager: [0xab283380]: Setting new loop mode: Off Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: 252601475, initial offset: 183814ms Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO AudioStreamManager: [0xab283090]: New stream: 5 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab2bec10]: Creating Playback URL Fetcher for track: 252601475 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO HttpDownloader: [0xab29a718]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=da57eeef1318302abe623ddbd4089fe5&request_ts=1766948778&track_id=252601475 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MetadataFetcher: [0xab2879a8]: Creating Metadata Fetcher for track: 252601475 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO HttpDownloader: [0xab3e6358]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=252601475 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab492988]: Creating Audio Stream Info Fetcher for track: 252601475 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO HttpDownloader: [0xab4beb58]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=e7b96cf00000e66d85223dfb3ab25e37&request_ts=1766948778&track_id=252601475 Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 5]: Running audio stream Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetShuffleMode message: disabled Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] INFO PlaybackControlsManager: [0xab283380]: Setting new shuffle mode: disabled Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.919 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Nonexistent -> Created Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.920 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.920 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.920 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.921 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: InitiatePlayback Dec 28 19:06:18 ifi-neo-stream3 play[1886]: 20251228 19:06:18.921 [1924.1924] INFO MediaEngine: [0xab282fa8]: Waiting for current stream to start before starting audio renderer Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:18 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:18 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] TRACE MetadataFetcher: [0xab2879a8]: Track 252601475 doesn't have a valid version field Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] TRACE MetadataFetcher: [0xab2879a8]: Track 252601475 doesn't have a valid work field Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] TRACE MetadataFetcher: [0xab2879a8]: Track 252601475 doesn't have a valid album version field Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 5]: Metadata became available: Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] INFO AudioStreamManager: [0xab283090]: Title: Give unto the Lord, Op. 74 Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] INFO AudioStreamManager: [0xab283090]: Artist: Adrian Partington Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] INFO AudioStreamManager: [0xab283090]: Album: Elgar: Cathedral Music Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.036 [1924.1924] INFO AudioStreamManager: [0xab283090]: Album art URL: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.056 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 5]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952379&hmac=tP9WrRJrBB0KvNAp0DYV9RMD2DA Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 5]: stream information have been fetched Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO UrlAudioSource: [0xab362a38]: Starting URL audio source, initial position: 183814ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952379&hmac=tP9WrRJrBB0KvNAp0DYV9RMD2DA Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] TRACE AudioSource: [0xab362a38]: State changed: Idle -> Running Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] DEBUG Ringbuffer: [0xab488c20]: Creating Audio Ringbuffer Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO ContentFetcher: [0xab2b8d90]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=2525498&eid=252601475&fmt=6&profile=raw&app_id=239488056&cid=3439855&etsp=1766952379&hmac=tP9WrRJrBB0KvNAp0DYV9RMD2DA, offset: 0 Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Created -> Info Retrieved Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Info Retrieved -> Running Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Starting audio renderer, initial playback state: Playing Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopped -> Initiating (Playing) Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: [Stream 5]: New audio stream (starting from 183813ms) Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: [Stream 5]: Stream metadata became available: Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: Title: Give unto the Lord, Op. 74 Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: Artist: Adrian Partington Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: Album: Elgar: Cathedral Music Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopped -> Initiating (Playing) Dec 28 19:06:19 ifi-neo-stream3 play[1886]: 20251228 19:06:19.106 [1924.1924] INFO SampleApp: Initiating playback, initial state: Playing Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: request:pause Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::serviceStop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Airplay Stop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: verbose: UNSET VOLATILE: Service: airplay_emulation Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Stopping Airplay Playback and sending pause command to client via USR2 Dec 28 19:06:19 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:19 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:06:19 ifi-neo-stream3 node[505]: in qobuz-connect Dec 28 19:06:19 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:06:19 ifi-neo-stream3 node[505]: qobuz-connect Dec 28 19:06:19 ifi-neo-stream3 node[505]: message: {"title":"Give unto the Lord, Op. 74","artist":"Adrian Partington","album":"Elgar: Cathedral Music","albumart":"https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg","duration":"545","seek":"0"} Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Stopping Airplay Playback and sending pause command to client via USR2 Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Start Qobuz PlaybackRoutine Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: qobuz_connect , startQobuzPlayback Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Qobuz Connect playback start Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:19 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:06:19 ifi-neo-stream3 sudo[4229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 3472 Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:19 ifi-neo-stream3 sudo[4229]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:06:19 ifi-neo-stream3 sudo[4229]: pam_unix(sudo:session): session closed for user root Dec 28 19:06:19 ifi-neo-stream3 shairport-sync[3472]: {"time":1766948752698,"response":"airplayInactive Success"} Dec 28 19:06:19 ifi-neo-stream3 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=12/USR2 Dec 28 19:06:19 ifi-neo-stream3 systemd[1]: shairport-sync.service: Failed with result 'signal'. Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Shairport-Sync paused with USR2 Dec 28 19:06:19 ifi-neo-stream3 systemd[1]: Starting Internet Detect for iFi Streamer... Dec 28 19:06:19 ifi-neo-stream3 sudo[4231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 3472 Dec 28 19:06:19 ifi-neo-stream3 sudo[4231]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:06:19 ifi-neo-stream3 sudo[4231]: pam_unix(sudo:session): session closed for user root Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: Cannot execute Shairport-sync USR2 kill: Error: Command failed: /usr/bin/sudo /bin/kill -USR2 $(pidof shairport-sync) Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: kill: (3472): No such process Dec 28 19:06:19 ifi-neo-stream3 systemd[1]: ifi-system-internet.service: Succeeded. Dec 28 19:06:19 ifi-neo-stream3 systemd[1]: Started Internet Detect for iFi Streamer. Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:19 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:19 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.139 [1924.1924] TRACE SampleApp: ALSA PCM's descriptor count: 1 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.139 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Playback initiated (playing state) Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.139 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Initiating (Playing) -> Playing Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.140 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Initiating (Playing) -> Playing Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.140 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Stopped -> Playing Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.140 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: InitiatePlayback Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.140 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback started, time until playback gets near the end: 352054ms Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] INFO SampleApp: Playback state changed: Playing Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 183812 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming started event Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Track ID: 252601475 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Start position: 183812ms Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Context UUID: 1c1c7e35-04eb-4f9f-b447-5ec64f1837f6 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Blob ID: 100000.563wgXLKJg2Zb709o7uX_IxWjb64oPLPRk24OJo0kd2-JFnTYV6mSTG-B_gAKKYv.es74TcixPchvhk69zr99l3iMrik Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingStart Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: Playback position: 183812 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Need to send state update Dec 28 19:06:20 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:20 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:06:20 ifi-neo-stream3 node[505]: in qobuz-connect Dec 28 19:06:20 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:06:20 ifi-neo-stream3 node[505]: qobuz-connect Dec 28 19:06:20 ifi-neo-stream3 node[505]: message: {"title":"Give unto the Lord, Op. 74","artist":"Adrian Partington","album":"Elgar: Cathedral Music","albumart":"https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg","duration":"545","seek":"0"} Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending StateUpdated message Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Playback state: Playing Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current position: 183812 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Duration: 545866 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Queue version: 1.1 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Current queue item ID: 13 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Next queue item ID: -1 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.141 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is actively playing Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.142 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.142 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.142 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.143 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending FileAudioQualityChanged message Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.143 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Sample rate: 44100 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.143 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Bit depth: 16 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.143 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Channel count: 2 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.143 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Audio quality: CD Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.143 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.144 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.144 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.144 [1924.1924] INFO QConnectMessageSender: [0xab362948]: Sending DeviceAudioQualityChanged message Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.144 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Sample rate: 44100 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.144 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Bit depth: 16 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.144 [1924.1924] TRACE QConnectMessageSender: [0xab362948]: Channel count: 2 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.145 [1924.1924] INFO QwspMessageSender: [0xab362938]: Sending Payload message Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.145 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Protocol: QConnect Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.145 [1924.1924] TRACE QwspMessageSender: [0xab362938]: Channel: Backend Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.145 [1924.1924] TRACE PlaybackPositionEstimator: [0xab283c78]: Synced playback position: 183812ms Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioGetState Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: Restarting Shairport-Sync after stop Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.269 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:06:20 ifi-neo-stream3 sudo[4248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 28 19:06:20 ifi-neo-stream3 sudo[4248]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.292 [1924.1924] INFO UrlAudioSource: [0xab362a38]: Content info extracted Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.292 [1924.1924] INFO UrlAudioSource: [0xab362a38]: Size: 32292072 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.4250] INFO AudioDecoder: [0xab497f70]: Stream info: Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.4250] INFO AudioDecoder: [0xab497f70]: Total samples: 24072720 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.4250] INFO AudioDecoder: [0xab497f70]: Sample rate: 44100 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.4250] INFO AudioDecoder: [0xab497f70]: Channel count: 2 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.4250] INFO AudioDecoder: [0xab497f70]: Bits per sample: 16 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.4250] INFO AudioDecoder: [0xab497f70]: Duration: 545866 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.1924] INFO UrlAudioSource: [0xab362a38]: Audio properties have changed Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.1924] INFO UrlAudioSource: [0xab362a38]: Seeking input stream to byte offset: 12264853 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.293 [1924.1924] INFO ContentFetcher: [0xab2b8d90]: Adjusting download offset to: 12264853 Dec 28 19:06:20 ifi-neo-stream3 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 28 19:06:20 ifi-neo-stream3 sudo[4248]: pam_unix(sudo:session): session closed for user root Dec 28 19:06:20 ifi-neo-stream3 volumio[1143]: info: Shairport-Sync retarted Dec 28 19:06:20 ifi-neo-stream3 node[505]: Download data end Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.516 [1924.1924] INFO UrlAudioSource: [0xab362a38]: Seeking input stream to byte offset: 12255505 Dec 28 19:06:20 ifi-neo-stream3 play[1886]: 20251228 19:06:20.516 [1924.1924] INFO ContentFetcher: [0xab2b8d90]: Adjusting download offset to: 12255505 Dec 28 19:06:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:21 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:21 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:21 ifi-neo-stream3 node[505]: Download data end Dec 28 19:06:22 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta Dec 28 19:06:22 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:22 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:06:22 ifi-neo-stream3 node[505]: metadata.album: https://static.qobuz.com/images/covers/5b/9z/fj44t6uea9z5b_600.jpg Dec 28 19:06:22 ifi-neo-stream3 node[505]: volumio Dec 28 19:06:22 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] TRACE WebsocketClient: [0xab289b58]: Binary data received, size: 38 Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] INFO ProtocolHandler: [0xab2836e8]: Received SetActive message: inactive Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Enqueuing command: Deactivate Renderer Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Executing command: Deactivate Renderer Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Stopping playback session maintenance Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] INFO PlaybackSessionManager: [0xab282d10]: Stopping playback session maintenance Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Making the renderer inactive Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] INFO ActiveStateManager: [0xab281938]: Setting new active state: inactive Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine needs to be stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] INFO MediaEngine: [0xab282fa8]: Stopping playback, clearing tracks Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Stop Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] INFO MediaEngine: [0xab282fa8]: Reseting Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: Reset Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetCurrentTrack Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Enqueuing command: SetNextTrack Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Stopping periodic state updates Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] INFO SampleApp: Renderer is now inactive Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.446 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Stop Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.447 [1924.1924] INFO AudioRenderer: [0xab2831c8]: Stopping audio renderer Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.447 [1924.1924] DEBUG PlaybackProgressManager: [0xab283220]: Audio playback is stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.447 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Playing -> Stopping Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.447 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Playing -> Stopping Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.447 [1924.1924] INFO SampleApp: Stopping playback Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.474 [1924.1924] DEBUG AudioRenderer: [0xab2831c8]: Transition to stopped state has been acknowledged Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.474 [1924.1924] TRACE AudioRenderer: [0xab2831c8]: State changed: Stopping -> Stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.475 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Audio renderer state changed: Stopping -> Stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.475 [1924.1924] TRACE MediaEngine: [0xab282fa8]: State changed: Playing -> Stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.475 [1924.1924] INFO AudioStreamManager: [0xab283090]: Clearing all streams Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.475 [1924.1924] INFO AudioStreamManager: [0xab283090]: [Stream 5]: Disposing of audio stream Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.475 [1924.1924] INFO ContentFetcher: [0xab2b8d90]: Canceling download Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.481 [1924.1924] DEBUG Ringbuffer: [0xab488c20]: Freeing Audio Ringbuffer Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] DEBUG AudioStreamInfoFetcher: [0xab492988]: Freeing Audio Stream Info Fetcher Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] DEBUG MetadataFetcher: [0xab2879a8]: Freeing Metadata Fetcher Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] DEBUG PlaybackUrlFetcher: [0xab2bec10]: Freeing Playback URL Fetcher Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Stop Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] INFO SampleApp: Playback state changed: Stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] INFO StreamingEventReporter: [0xab283b00]: Reporting streaming ended event Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.486 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: End position: 186152ms Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.488 [1924.1924] TRACE StreamingEventReporter: [0xab283b00]: Duration: 2340ms Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.488 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Sending streaming reports Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] INFO HttpDownloader: [0xab283b58]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/reportStreamingEndJson Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] TRACE ProtocolHandler: [0xab2836e8]: Not sending state update because the renderer is not active Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] DEBUG UserInactivityManager: [0xab283d40]: Renderer is active but not playing, will deactivate in 3600s Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Current stream changed state: Running -> Nonexistent Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] INFO SampleApp: [Stream 5]: Audio stream has been disposed of Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: Reset Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.489 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: Reset Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG RendererActivationController: [0xab283900]: Media Engine has been stopped Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Invalidating track properties and device audio format Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] TRACE RendererActivationController: [0xab283900]: State changed: Active -> Inactive (Connected) Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG RendererActivationCommandSequencer: [0xab2839a8]: Confirming command: Deactivate Renderer Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetCurrentTrack Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting current track: NONE Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetCurrentTrack Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG MediaEngine: [0xab282fa8]: Executing command: SetNextTrack Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] INFO MediaEngine: [0xab282fa8]: Setting next track: NONE Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.490 [1924.1924] DEBUG MediaEngineCommandSequencer: [0xab283320]: Confirming command: SetNextTrack Dec 28 19:06:22 ifi-neo-stream3 play[1886]: 20251228 19:06:22.656 [1924.1924] DEBUG StreamingEventReporter: [0xab283b00]: Streaming report submitted successfully Dec 28 19:06:23 ifi-neo-stream3 node[505]: Download data end Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: Airplay started streaming, receiving metadatas Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: Airplay started streaming, receiving metadatas Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stPlaybackTimer Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::updateTrackBlock Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrackBlock Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::serviceStop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: ControllerMpd::stop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: verbose: ControllerMpd::sendMpdCommand stop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: successsuccess Dec 28 19:06:39 ifi-neo-stream3 shairport-sync[4251]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 19:06:39 ifi-neo-stream3 shairport-sync[4251]: Dload Upload Total Spent Left Speed Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: sendMpdCommand stop took 17 milliseconds Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests AirplayActive Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Dec 28 19:06:39 ifi-neo-stream3 shairport-sync[4251]: [158B blob data] Dec 28 19:06:39 ifi-neo-stream3 shairport-sync[4251]: {"time":1766948799892,"response":"airplayActive Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 28 19:06:39 ifi-neo-stream3 shairport-sync[4251]: Dload Upload Total Spent Left Speed Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: ---------------------------- Client requests Start Airplay PlaybackRoutine Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: Airplay playback start Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Sent Play Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CorePlayQueue::getTrack 0 Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioStop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::stop Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 28 19:06:39 ifi-neo-stream3 shairport-sync[4251]: [158B blob data] Dec 28 19:06:39 ifi-neo-stream3 volumio[1143]: info: ConvSwitch: Get message: success Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:40 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:41 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:41 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:42 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:42 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:06:42 ifi-neo-stream3 node[505]: metadata.album: /albumart Dec 28 19:06:42 ifi-neo-stream3 node[505]: airplay Dec 28 19:06:42 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:43 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:43 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:43 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:43 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:43 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:44 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::servicePushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:45 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:46 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:46 ifi-neo-stream3 node[505]: metadata.title changed Dec 28 19:06:46 ifi-neo-stream3 node[505]: metadata.album: http://127.0.0.1:3000/albumart?cacheid=331&web=Kassiani//extralarge&path=&metadata=false Dec 28 19:06:46 ifi-neo-stream3 node[505]: airplay Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:46 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:47 ifi-neo-stream3 node[505]: Closing connection with the client Dec 28 19:06:47 ifi-neo-stream3 node[505]: Closing connection with the client Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:47 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:47 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:48 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:48 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveCurrentVolume Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: CoreStateMachine::pushState Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::volumioPushState Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: MetaClient: Sent Meta airplay Dec 28 19:06:49 ifi-neo-stream3 node[505]: gxl:metadata_handler Dec 28 19:06:49 ifi-neo-stream3 volumio[1143]: info: MetaClient: Get message: success Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: TypeError: Cannot read property 'slice' of null Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at Object.onceWrapper (events.js:520:26) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at ClientRequest.emit (events.js:400:28) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at TLSSocket.socketOnData (_http_client.js:515:22) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at TLSSocket.emit (events.js:400:28) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at addChunk (internal/streams/readable.js:293:12) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at readableAddChunk (internal/streams/readable.js:267:9) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Dec 28 19:06:50 ifi-neo-stream3 volumio[1143]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 19:06:51 ifi-neo-stream3 sudo[4694]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-28 19:05 Dec 28 19:06:51 ifi-neo-stream3 sudo[4694]: 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="b6b5fc9c726190e478d1307bf4816c8d6dfb5af2" VOLUMIO_FE_VERSION="72eb2349b07a12438c15cacc860e8ee2920f9fe3" VOLUMIO_FE3_VERSION="036bae4158ab56d58bb5146ed07152c149e8c38c" VOLUMIO_BE_VERSION="3aec3392bb3143c0e0dfe38428c557fb646b7d62" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="ifi" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Oct 8 10:21:35 CST 2025" VOLUMIO_VERSION="0.01.2" VOLUMIO_HARDWARE="neo-stream3" VOLUMIO_DEVICENAME="NEO Stream3" VOLUMIO_HASH="e98645b625b553a5fa9d799f4d383f47"