-- Logs begin at Fri 2025-04-25 17:01:57 CEST, end at Sun 2025-04-27 17:56:21 CEST. -- Apr 27 17:55:06 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:06 integro volumio[3177]: info: Listing playlists Apr 27 17:55:06 integro volumio[3177]: info: Listing playlists Apr 27 17:55:16 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:26 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:26 integro volumio[3177]: info: Listing playlists Apr 27 17:55:26 integro volumio[3177]: info: Listing playlists Apr 27 17:55:29 integro volumio[3177]: info: Preload queue cleared Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::ClearQueue Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::stPlaybackTimer Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::updateTrackBlock Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrackBlock Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::serviceStop Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::serviceStop Apr 27 17:55:29 integro volumio[3177]: info: [1745769329406] ControllerWebradio::stop Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand stop Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::clearPlayQueue Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::saveQueue Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushQueue Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::addQueueItems Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::addQueueItems Apr 27 17:55:29 integro volumio[3177]: info: Preload queue cleared Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:5bu9A6uphPWg39RC3ZKeku Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:5bu9A6uphPWg39RC3ZKeku in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:5bu9A6uphPWg39RC3ZKeku Apr 27 17:55:29 integro kernel: asoc-aml-card auge_sound: tdm playback stop Apr 27 17:55:29 integro kernel: spdif_a is set to disable Apr 27 17:55:29 integro kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 27 17:55:29 integro kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Apr 27 17:55:29 integro kernel: tdm playback mute: 1, lane_cnt = 8 Apr 27 17:55:29 integro kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: info: Apr 27 17:55:29 integro volumio[3177]: ---------------------------- MPD announces state update: player Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand stop took 41 milliseconds Apr 27 17:55:29 integro volumio[3177]: info: ControllerMpd::getState Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Apr 27 17:55:29 integro volumio[3177]: info: Apr 27 17:55:29 integro volumio[3177]: ---------------------------- MPD announces state update: player Apr 27 17:55:29 integro volumio[3177]: info: ControllerMpd::getState Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Apr 27 17:55:29 integro volumio[3177]: info: Apr 27 17:55:29 integro volumio[3177]: ---------------------------- MPD announces state update: player Apr 27 17:55:29 integro volumio[3177]: info: ControllerMpd::getState Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand status Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand status took 5 milliseconds Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand status took 4 milliseconds Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand status took 2 milliseconds Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::parseState Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::parseState Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::parseState Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand playlistinfo took 15 milliseconds Apr 27 17:55:29 integro volumio[3177]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::parseTrackInfo Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::parseTrackInfo Apr 27 17:55:29 integro volumio[3177]: verbose: ControllerMpd::parseTrackInfo Apr 27 17:55:29 integro volumio[3177]: info: ControllerMpd::pushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"fip-hifi.aac?id=radiofrance","artist":"fip-hifi.aac","album":null,"uri":"https://icecast.radiofrance.fr/fip-hifi.aac?id=radiofrance","trackType":""} Apr 27 17:55:29 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::syncState stateService stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: No code Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: ControllerMpd::pushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"fip-hifi.aac?id=radiofrance","artist":"fip-hifi.aac","album":null,"uri":"https://icecast.radiofrance.fr/fip-hifi.aac?id=radiofrance","trackType":""} Apr 27 17:55:29 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::syncState stateService stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: No code Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: ControllerMpd::pushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"fip-hifi.aac?id=radiofrance","artist":"fip-hifi.aac","album":null,"uri":"https://icecast.radiofrance.fr/fip-hifi.aac?id=radiofrance","trackType":""} Apr 27 17:55:29 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::syncState stateService stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: No code Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:29 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:29 integro volumio[3177]: info: ------------------------------ 125ms Apr 27 17:55:29 integro volumio[3177]: info: ------------------------------ 121ms Apr 27 17:55:29 integro volumio[3177]: info: ------------------------------ 122ms Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:29 integro volumio[3177]: info: MCU Signalled Playback Inactive Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","service":"spop","name":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPushQueue Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::saveQueue Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::updateTrackBlock Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrackBlock Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioPlay Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::play index 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::addQueueItems Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::addQueueItems Apr 27 17:55:29 integro volumio[3177]: info: Preload queue cleared Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:5SJFZnECoKeTLy7PPVLLbF Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:5SJFZnECoKeTLy7PPVLLbF in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:5SJFZnECoKeTLy7PPVLLbF Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:172J2JqVRzR74ILc2eBvta Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:172J2JqVRzR74ILc2eBvta in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:172J2JqVRzR74ILc2eBvta Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:14V6VqJXHZ08pM6Fu3vUsO Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:14V6VqJXHZ08pM6Fu3vUsO in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:14V6VqJXHZ08pM6Fu3vUsO Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:504wsV4Br1jy9xUvWzpAog Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:504wsV4Br1jy9xUvWzpAog in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:504wsV4Br1jy9xUvWzpAog Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:2mXVCqoNE6otHBcmRz4IHv Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:2mXVCqoNE6otHBcmRz4IHv in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:2mXVCqoNE6otHBcmRz4IHv Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:325xUomC1NKDerrKIn0zfD Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:325xUomC1NKDerrKIn0zfD in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:325xUomC1NKDerrKIn0zfD Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:4w3aG0qWqCQKhvsQYzX3nY Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:4w3aG0qWqCQKhvsQYzX3nY in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:4w3aG0qWqCQKhvsQYzX3nY Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:14lyZKpPu1ECQpfXhgrip6 Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:14lyZKpPu1ECQpfXhgrip6 in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:14lyZKpPu1ECQpfXhgrip6 Apr 27 17:55:29 integro volumio[3177]: info: Adding Item to queue: spotify:track:0L5cUf2OgB2GeVzxwGJv3q Apr 27 17:55:29 integro volumio[3177]: info: Exploding uri spotify:track:0L5cUf2OgB2GeVzxwGJv3q in service spop Apr 27 17:55:29 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:track:0L5cUf2OgB2GeVzxwGJv3q Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::stop Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::play index undefined Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreStateMachine::startPlaybackTimer Apr 27 17:55:29 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::volumioGetVisibleSources Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 27 17:55:29 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 27 17:55:29 integro volumio[3177]: info: [1745769329802] ControllerSpotify::clearAddPlayTrack Apr 27 17:55:29 integro volumio[3177]: info: Sending Spotify command with payload to local API: /player/play Apr 27 17:55:29 integro go-librespot[15039]: time="2025-04-27T17:55:29+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 27 17:55:29 integro go-librespot[15039]: time="2025-04-27T17:55:29+02:00" level=debug msg="loading track spotify:track:5bu9A6uphPWg39RC3ZKeku (paused: false, position: 1ms)" Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2mXVCqoNE6otHBcmRz4IHv","service":"spop","name":"Goldberg Variations, BWV 988: Variation 2 a 1 Clav.","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":49,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4w3aG0qWqCQKhvsQYzX3nY","service":"spop","name":"Goldberg Variations, BWV 988: Variation 7 a 1 ovvero 2 Clav.","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":76,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:504wsV4Br1jy9xUvWzpAog","service":"spop","name":"Keyboard Concerto No. 5 in F Minor, BWV 1056: II. Largo","artist":"Johann Sebastian Bach","album":"Glenn Gould plays Bach: Piano Concertos Nos. 1 - 5 BWV 1052-1056 & No. 7 BWV 1058","type":"song","duration":176,"albumart":"https://i.scdn.co/image/ab67616d0000b2737b941680859557c796b4eca9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:325xUomC1NKDerrKIn0zfD","service":"spop","name":"Goldberg Variations, BWV 988: Variation 5 a 1 ovvero 2 Clav.","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":37,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0L5cUf2OgB2GeVzxwGJv3q","service":"spop","name":"Goldberg Variations, BWV 988: Variation 6 a 1 Clav. Canone alla Seconda","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":40,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5SJFZnECoKeTLy7PPVLLbF","service":"spop","name":"Goldberg Variations, BWV 988: Variation 3 a 1 Clav. Canone all'Unisono","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":90,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=trace msg="emitting websocket event: will_play" Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:14V6VqJXHZ08pM6Fu3vUsO","service":"spop","name":"Goldberg Variations, BWV 988: Variation 1 a 1 Clav.","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":70,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:14lyZKpPu1ECQpfXhgrip6","service":"spop","name":"Goldberg Variations, BWV 988: Variation 4 a 1 Clav.","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":50,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:172J2JqVRzR74ILc2eBvta","service":"spop","name":"Goldberg Variations, BWV 988: Aria da capo","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Apr 27 17:55:30 integro volumio[3177]: info: CoreCommandRouter::volumioPushQueue Apr 27 17:55:30 integro volumio[3177]: info: CorePlayQueue::saveQueue Apr 27 17:55:30 integro volumio[3177]: info: CoreStateMachine::updateTrackBlock Apr 27 17:55:30 integro volumio[3177]: info: CorePlayQueue::getTrackBlock Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5bu9A6uphPWg39RC3ZKeku" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="requested aes key for file d05a3f8179609a52c5ce68bf43468a24ebb13ffc, gid: 5bu9A6uphPWg39RC3ZKeku" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1324" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1106" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="fetched first chunk of 13, total size is 6604352 bytes" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" Apr 27 17:55:30 integro go-librespot[15039]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 Apr 27 17:55:30 integro go-librespot[15039]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 Apr 27 17:55:30 integro kernel: aml_tdm_open Apr 27 17:55:30 integro kernel: Not init audio effects Apr 27 17:55:30 integro kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 27 17:55:30 integro kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 27 17:55:30 integro kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d101218, id(1), clksel(1) Apr 27 17:55:30 integro kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 27 17:55:30 integro kernel: dump_pcm_setting(ffffffc03d101218) Apr 27 17:55:30 integro kernel: pcm_mode(1) Apr 27 17:55:30 integro kernel: sysclk(11289600) Apr 27 17:55:30 integro kernel: sysclk_bclk_ratio(4) Apr 27 17:55:30 integro kernel: bclk(2822400) Apr 27 17:55:30 integro kernel: bclk_lrclk_ratio(64) Apr 27 17:55:30 integro kernel: lrclk(44100) Apr 27 17:55:30 integro kernel: tx_mask(0x3) Apr 27 17:55:30 integro kernel: rx_mask(0x3) Apr 27 17:55:30 integro kernel: slots(2) Apr 27 17:55:30 integro kernel: slot_width(32) Apr 27 17:55:30 integro kernel: lane_mask_in(0x2) Apr 27 17:55:30 integro kernel: lane_mask_out(0x1) Apr 27 17:55:30 integro kernel: lane_oe_mask_in(0x0) Apr 27 17:55:30 integro kernel: lane_oe_mask_out(0x0) Apr 27 17:55:30 integro kernel: lane_lb_mask_in(0x0) Apr 27 17:55:30 integro kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 27 17:55:30 integro kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 27 17:55:30 integro kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 27 17:55:30 integro kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 27 17:55:30 integro kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 27 17:55:30 integro kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 27 17:55:30 integro kernel: aml_tdm_prepare(), reset fddr Apr 27 17:55:30 integro kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 27 17:55:30 integro kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 27 17:55:30 integro kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 27 17:55:30 integro kernel: tdm playback mute: 0, lane_cnt = 8 Apr 27 17:55:30 integro kernel: aml_tdm_prepare(), reset fddr Apr 27 17:55:30 integro kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 27 17:55:30 integro kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 27 17:55:30 integro kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 27 17:55:30 integro kernel: tdm playback mute: 0, lane_cnt = 8 Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=info msg="loaded track \"Goldberg Variations, BWV 988: Aria\" (uri: spotify:track:5bu9A6uphPWg39RC3ZKeku, paused: false, position: 1ms, duration: 184853ms)" Apr 27 17:55:30 integro kernel: asoc-aml-card auge_sound: tdm playback enable Apr 27 17:55:30 integro kernel: spdif_a is set to enable Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=trace msg="emitting websocket event: metadata" Apr 27 17:55:30 integro volumio[3177]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","name":"Goldberg Variations, BWV 988: Aria","artist_names":["Johann Sebastian Bach","Glenn Gould"],"album_name":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","position":1,"duration":184853,"release_date":"year:1981","track_number":1,"disc_number":1}} Apr 27 17:55:30 integro go-librespot[15039]: time="2025-04-27T17:55:30+02:00" level=debug msg="fetched chunk 2/12, size: 524288" Apr 27 17:55:31 integro go-librespot[15039]: time="2025-04-27T17:55:31+02:00" level=debug msg="fetched chunk 3/12, size: 524288" Apr 27 17:55:31 integro go-librespot[15039]: time="2025-04-27T17:55:31+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:31 integro go-librespot[15039]: time="2025-04-27T17:55:31+02:00" level=trace msg="emitting websocket event: playing" Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus play Apr 27 17:55:31 integro volumio[3177]: info: Received an update from plugin. extracting info from payload Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:31 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:31 integro volumio[3177]: info: MCU Signalled Playback Active Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus play Apr 27 17:55:31 integro volumio[3177]: info: Received an update from plugin. extracting info from payload Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:31 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:31 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus play Apr 27 17:55:31 integro volumio[3177]: info: Received an update from plugin. extracting info from payload Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:31 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:31 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:31 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:31 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:31 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:31 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:31 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:31 integro go-librespot[15039]: time="2025-04-27T17:55:31+02:00" level=debug msg="fetched chunk 1/12, size: 524288" Apr 27 17:55:34 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:34 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:36 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:36 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:36 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:36 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:36 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:36 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:36 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:36 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:43 integro go-librespot[15039]: time="2025-04-27T17:55:43+02:00" level=debug msg="fetched chunk 4/12, size: 524288" Apr 27 17:55:45 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:45 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:45 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:45 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: spop , goto Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:46 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:46 integro volumio[3177]: info: Listing playlists Apr 27 17:55:46 integro volumio[3177]: info: Listing playlists Apr 27 17:55:46 integro volumio[3177]: info: Executing endpoint getSimilarAlbums Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 27 17:55:46 integro volumio[3177]: info: Executing endpoint getSimilarAlbums Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 27 17:55:46 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:46 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:46 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:46 integro volumio[3177]: info: Executing endpoint metavolumio Apr 27 17:55:46 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 27 17:55:48 integro volumio[3177]: info: Preload queue cleared Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::ClearQueue Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::stop Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::stPlaybackTimer Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::updateTrackBlock Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrackBlock Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:48 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::serviceStop Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::serviceStop Apr 27 17:55:48 integro volumio[3177]: info: Spotify Stop Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: SPOTIFY STOP Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: {"status":"play","position":0,"title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d0000b273caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","codec":"ogg","seek":1,"duration":184,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":false,"repeatSingle":false,"consume":false,"volume":44,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Apr 27 17:55:48 integro volumio[3177]: info: Sending Spotify command to local API: /player/pause Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::clearPlayQueue Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::saveQueue Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioPushQueue Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::addQueueItems Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::addQueueItems Apr 27 17:55:48 integro volumio[3177]: info: Preload queue cleared Apr 27 17:55:48 integro volumio[3177]: info: Adding Item to queue: spotify:album:1aCpHSQE5ghxibsQ5gkBe0 Apr 27 17:55:48 integro volumio[3177]: info: Exploding uri spotify:album:1aCpHSQE5ghxibsQ5gkBe0 in service spop Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: EXPLODING URI:spotify:album:1aCpHSQE5ghxibsQ5gkBe0 Apr 27 17:55:48 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="pause track at 17592ms" Apr 27 17:55:48 integro kernel: asoc-aml-card auge_sound: tdm playback stop Apr 27 17:55:48 integro kernel: spdif_a is set to disable Apr 27 17:55:48 integro kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 27 17:55:48 integro kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Apr 27 17:55:48 integro kernel: tdm playback mute: 1, lane_cnt = 8 Apr 27 17:55:48 integro kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 27 17:55:48 integro volumio[3177]: info: MCU Signalled Playback Inactive Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=trace msg="emitting websocket event: paused" Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: {"status":"pause","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":17001,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":17001,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:48 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::syncState stateService pause Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:48 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: {"status":"pause","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":17001,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":17001,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:48 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::syncState stateService pause Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:48 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:48 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:48 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioPushQueue Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::saveQueue Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::updateTrackBlock Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrackBlock Apr 27 17:55:48 integro volumio[3177]: info: CoreCommandRouter::volumioPlay Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::play index 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::stop Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::play index undefined Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: CoreStateMachine::startPlaybackTimer Apr 27 17:55:48 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:48 integro volumio[3177]: info: [1745769348643] ControllerSpotify::clearAddPlayTrack Apr 27 17:55:48 integro volumio[3177]: info: Sending Spotify command with payload to local API: /player/play Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="loading track spotify:track:5bu9A6uphPWg39RC3ZKeku (paused: false, position: 1ms)" Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=trace msg="emitting websocket event: will_play" Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:48 integro volumio[3177]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5bu9A6uphPWg39RC3ZKeku" Apr 27 17:55:48 integro go-librespot[15039]: time="2025-04-27T17:55:48+02:00" level=debug msg="requested aes key for file d05a3f8179609a52c5ce68bf43468a24ebb13ffc, gid: 5bu9A6uphPWg39RC3ZKeku" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=debug msg="fetched first chunk of 13, total size is 6604352 bytes" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" Apr 27 17:55:49 integro go-librespot[15039]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 Apr 27 17:55:49 integro kernel: aml_tdm_open Apr 27 17:55:49 integro kernel: Not init audio effects Apr 27 17:55:49 integro kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 27 17:55:49 integro kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 27 17:55:49 integro kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 27 17:55:49 integro kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 27 17:55:49 integro kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d101218, id(1), clksel(1) Apr 27 17:55:49 integro kernel: aml_dai_set_tdm_fmt(), fmt not change Apr 27 17:55:49 integro kernel: dump_pcm_setting(ffffffc03d101218) Apr 27 17:55:49 integro kernel: pcm_mode(1) Apr 27 17:55:49 integro kernel: sysclk(11289600) Apr 27 17:55:49 integro kernel: sysclk_bclk_ratio(4) Apr 27 17:55:49 integro kernel: bclk(2822400) Apr 27 17:55:49 integro kernel: bclk_lrclk_ratio(64) Apr 27 17:55:49 integro kernel: lrclk(44100) Apr 27 17:55:49 integro kernel: tx_mask(0x3) Apr 27 17:55:49 integro kernel: rx_mask(0x3) Apr 27 17:55:49 integro kernel: slots(2) Apr 27 17:55:49 integro kernel: slot_width(32) Apr 27 17:55:49 integro kernel: lane_mask_in(0x2) Apr 27 17:55:49 integro kernel: lane_mask_out(0x1) Apr 27 17:55:49 integro kernel: lane_oe_mask_in(0x0) Apr 27 17:55:49 integro kernel: lane_oe_mask_out(0x0) Apr 27 17:55:49 integro kernel: lane_lb_mask_in(0x0) Apr 27 17:55:49 integro kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Apr 27 17:55:49 integro kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Apr 27 17:55:49 integro kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Apr 27 17:55:49 integro kernel: aml_dai_set_clkdiv, div 4, clksel(1) Apr 27 17:55:49 integro kernel: aml_dai_set_bclk_ratio, select I2S mode Apr 27 17:55:49 integro kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Apr 27 17:55:49 integro kernel: aml_tdm_prepare(), reset fddr Apr 27 17:55:49 integro kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 27 17:55:49 integro kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 27 17:55:49 integro kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 27 17:55:49 integro kernel: tdm playback mute: 0, lane_cnt = 8 Apr 27 17:55:49 integro kernel: aml_tdm_prepare(), reset fddr Apr 27 17:55:49 integro kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Apr 27 17:55:49 integro kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 27 17:55:49 integro kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Apr 27 17:55:49 integro kernel: tdm playback mute: 0, lane_cnt = 8 Apr 27 17:55:49 integro go-librespot[15039]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=info msg="loaded track \"Goldberg Variations, BWV 988: Aria\" (uri: spotify:track:5bu9A6uphPWg39RC3ZKeku, paused: false, position: 1ms, duration: 184853ms)" Apr 27 17:55:49 integro kernel: asoc-aml-card auge_sound: tdm playback enable Apr 27 17:55:49 integro kernel: spdif_a is set to enable Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=debug msg="fetched chunk 3/12, size: 524288" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=trace msg="emitting websocket event: metadata" Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","name":"Goldberg Variations, BWV 988: Aria","artist_names":["Johann Sebastian Bach","Glenn Gould"],"album_name":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","position":1,"duration":184853,"release_date":"year:1981","track_number":1,"disc_number":1}} Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=debug msg="fetched chunk 1/12, size: 524288" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=debug msg="fetched chunk 2/12, size: 524288" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 27 17:55:49 integro go-librespot[15039]: time="2025-04-27T17:55:49+02:00" level=trace msg="emitting websocket event: playing" Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus stop Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","play_origin":"go-librespot"}} Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus play Apr 27 17:55:49 integro volumio[3177]: info: Received an update from plugin. extracting info from payload Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:49 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:49 integro volumio[3177]: info: MCU Signalled Playback Active Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus play Apr 27 17:55:49 integro volumio[3177]: info: Received an update from plugin. extracting info from payload Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:49 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: PUSH STATE SPOTIFY Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::servicePushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Goldberg Variations, BWV 988: Aria","artist":"Johann Sebastian Bach, Glenn Gould","album":"Bach: The Goldberg Variations, BWV 988 (1981 Gould Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e02caf1a802a9c25e577d53d516","uri":"spotify:track:5bu9A6uphPWg39RC3ZKeku","trackType":"spotify","seek":1,"duration":184,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 27 17:55:49 integro volumio[3177]: verbose: CURRENT POSITION 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState stateService play Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::syncState currentStatus play Apr 27 17:55:49 integro volumio[3177]: info: Received an update from plugin. extracting info from payload Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:49 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:49 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:49 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:49 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:49 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:49 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:49 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:52 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 44 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 45 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:52 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 44 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 45 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:52 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 44 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 46 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 27 17:55:52 integro volumio[3177]: info: Setting Spotify Volume from Volumio: 46 Apr 27 17:55:52 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:52 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 46 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 47 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:52 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:52 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:52 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:52 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:52 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 46 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 47 Apr 27 17:55:52 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 46 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 48 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 27 17:55:53 integro volumio[3177]: info: Setting Spotify Volume from Volumio: 48 Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 48 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 49 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 49 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 48 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 49 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 48 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 50 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 27 17:55:53 integro volumio[3177]: info: Setting Spotify Volume from Volumio: 50 Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 50 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 51 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:53 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:53 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:53 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:53 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:53 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 50 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 51 Apr 27 17:55:53 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:54 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 50 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 52 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 27 17:55:54 integro volumio[3177]: info: Setting Spotify Volume from Volumio: 52 Apr 27 17:55:54 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:54 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 52 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 53 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:54 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 52 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 53 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:54 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 52 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 54 Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 27 17:55:54 integro volumio[3177]: info: Setting Spotify Volume from Volumio: 54 Apr 27 17:55:54 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:54 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:54 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:54 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:54 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:54 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Apr 27 17:55:55 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Apr 27 17:55:55 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:55 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:55 integro volumio[3177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 17:55:55 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:55 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:55 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:55 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:55 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:55 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:55 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:55 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 54 Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 55 Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:55 integro volumio[3177]: info: CoreStateMachine::pushState Apr 27 17:55:55 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:55 integro volumio[3177]: info: CoreCommandRouter::volumioPushState Apr 27 17:55:55 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:55 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:55:55 integro volumio[3177]: info: MRS: Pushing multiroomSync output update for this device Apr 27 17:55:55 integro volumio[3177]: info: MRS: Pushing multiroomSync output Apr 27 17:55:55 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:55 integro volumio[3177]: info: Signalling Playback active due to playback status change Apr 27 17:55:55 integro volumio[3177]: info: Updating RAAT Signal Path Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: SPOTIFY VOLUME 54 Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: VOLUMIO VOLUME 55 Apr 27 17:55:55 integro volumio[3177]: SPOTIFY: DELTA VOLUME ENOUGH: false Apr 27 17:55:56 integro volumio[3177]: SPOTIFY: SETTING SPOTIFY VOLUME 54 Apr 27 17:55:56 integro volumio[3177]: info: Sending Spotify command with payload to local API: /player/volume Apr 27 17:55:56 integro go-librespot[15039]: time="2025-04-27T17:55:56+02:00" level=debug msg="update volume to 35388/65535" Apr 27 17:55:56 integro go-librespot[15039]: time="2025-04-27T17:55:56+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 27 17:55:56 integro go-librespot[15039]: time="2025-04-27T17:55:56+02:00" level=trace msg="emitting websocket event: volume" Apr 27 17:55:56 integro volumio[3177]: SPOTIFY: received: {"type":"volume","data":{"value":54,"max":100}} Apr 27 17:55:56 integro volumio[3177]: SPOTIFY: RECEIVED SPOTIFY VOLUME 54 Apr 27 17:55:56 integro volumio[3177]: SPOTIFY: received: {"type":"volume","data":{"value":54,"max":100}} Apr 27 17:55:56 integro volumio[3177]: SPOTIFY: RECEIVED SPOTIFY VOLUME 54 Apr 27 17:55:56 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:55:56 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:56:01 integro go-librespot[15039]: time="2025-04-27T17:56:01+02:00" level=debug msg="fetched chunk 4/12, size: 524288" Apr 27 17:56:06 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:56:06 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:56:06 integro volumio[3177]: info: Listing playlists Apr 27 17:56:06 integro volumio[3177]: info: Listing playlists Apr 27 17:56:16 integro volumio[3177]: info: CoreCommandRouter::volumioGetState Apr 27 17:56:16 integro volumio[3177]: info: CorePlayQueue::getTrack 0 Apr 27 17:56:16 integro go-librespot[15039]: time="2025-04-27T17:56:16+02:00" level=debug msg="fetched chunk 5/12, size: 524288" Apr 27 17:56:20 integro volumio[3177]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 27 17:56:20 integro volumio[3177]: Error: connect ETIMEDOUT 151.101.134.79:443 Apr 27 17:56:20 integro volumio[3177]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Apr 27 17:56:20 integro volumio[3177]: errno: -110, Apr 27 17:56:20 integro volumio[3177]: code: 'ETIMEDOUT', Apr 27 17:56:20 integro volumio[3177]: syscall: 'connect', Apr 27 17:56:20 integro volumio[3177]: address: '151.101.134.79', Apr 27 17:56:20 integro volumio[3177]: port: 443 Apr 27 17:56:20 integro volumio[3177]: } Apr 27 17:56:20 integro volumio[3177]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 27 17:56:21 integro sudo[5332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-27 17:55 Apr 27 17:56:21 integro sudo[5332]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="integro" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 08:21:01 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Integro" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Integro" VOLUMIO_HASH="e4bf773a7a29410391c374b4329f7a82"