Mar 28 22:04:06 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:06 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:16 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:16 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:16 volumio volumio[1411]: info: Listing playlists Mar 28 22:04:16 volumio volumio[1411]: info: Listing playlists Mar 28 22:04:21 volumio go-librespot[5543]: time="2026-03-28T22:04:21+01:00" level=trace msg="received accesspoint ping" Mar 28 22:04:21 volumio go-librespot[5543]: time="2026-03-28T22:04:21+01:00" level=trace msg="received accesspoint pong ack" Mar 28 22:04:21 volumio go-librespot[5543]: time="2026-03-28T22:04:21+01:00" level=trace msg="sent dealer ping" Mar 28 22:04:21 volumio go-librespot[5543]: time="2026-03-28T22:04:21+01:00" level=trace msg="received dealer pong" Mar 28 22:04:26 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:26 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:36 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:36 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:36 volumio volumio[1411]: info: Listing playlists Mar 28 22:04:36 volumio volumio[1411]: info: Listing playlists Mar 28 22:04:46 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:46 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:50 volumio volumio[1411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 9 Mar 28 22:04:50 volumio volumio[1411]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 9 Mar 28 22:04:50 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:50 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:50 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 28 22:04:50 volumio volumio[1411]: info: CoreCommandRouter::volumioGetQueue Mar 28 22:04:50 volumio volumio[1411]: info: CoreStateMachine::getQueue Mar 28 22:04:50 volumio volumio[1411]: info: CorePlayQueue::getQueue Mar 28 22:04:51 volumio go-librespot[5543]: time="2026-03-28T22:04:51+01:00" level=trace msg="sent dealer ping" Mar 28 22:04:51 volumio go-librespot[5543]: time="2026-03-28T22:04:51+01:00" level=trace msg="received dealer pong" Mar 28 22:04:56 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:04:56 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:04:56 volumio volumio[1411]: info: Listing playlists Mar 28 22:04:56 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:06 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:06 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:16 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:16 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:16 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:16 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:21 volumio go-librespot[5543]: time="2026-03-28T22:05:21+01:00" level=trace msg="sent dealer ping" Mar 28 22:05:21 volumio go-librespot[5543]: time="2026-03-28T22:05:21+01:00" level=trace msg="received dealer pong" Mar 28 22:05:26 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:26 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:36 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:36 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:36 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:36 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::volumioPause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::servicePause Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::servicePause Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::pause Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand pause Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand pause took 2 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: Mar 28 22:05:43 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:43 volumio volumio[1411]: info: Mar 28 22:05:43 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:43 volumio volumio[1411]: info: Mar 28 22:05:43 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:43 volumio volumio[1411]: info: Mar 28 22:05:43 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:43 volumio volumio[1411]: info: Mar 28 22:05:43 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand status took 4 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand status took 3 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand status took 2 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand status took 1 milliseconds Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand status took 3 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:43 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":298927,"duration":508,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:43 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState stateService pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":298927,"duration":508,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:43 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState stateService pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":298927,"duration":508,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:43 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState stateService pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":298927,"duration":508,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:43 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState stateService pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:43 volumio volumio[1411]: info: ------------------------------ 21ms Mar 28 22:05:43 volumio volumio[1411]: info: ------------------------------ 20ms Mar 28 22:05:43 volumio volumio[1411]: info: ------------------------------ 20ms Mar 28 22:05:43 volumio volumio[1411]: info: ------------------------------ 20ms Mar 28 22:05:43 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 16 milliseconds Mar 28 22:05:43 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:43 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":298927,"duration":508,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:43 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState stateService pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus pause Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:43 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:43 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:43 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:43 volumio volumio[1411]: info: ------------------------------ 33ms Mar 28 22:05:43 volumio volumio[1411]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 28 22:05:43 volumio volumio[1411]: info: peppy_screensaver: Genuine stop — paused Mar 28 22:05:43 volumio volumio[1411]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 28 22:05:43 volumio volumio[1411]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 28 22:05:43 volumio volumio[1411]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 28 22:05:43 volumio volumio[1411]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 28 22:05:43 volumio volumio[1411]: info: touch_display: Setting screensaver timeout to 90 seconds. Mar 28 22:05:45 volumio volumio[1411]: info: peppy_screensaver: Start PeppyMeter Mar 28 22:05:46 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:46 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:47 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:47 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:48 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 22:05:48 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::updateTrackBlock Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrackBlock Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::stPlaybackTimer Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::serviceStop Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::serviceStop Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::stop Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 22:05:51 volumio volumio[1411]: info: Disabling plugin peppy_screensaver Mar 28 22:05:51 volumio volumio[1411]: info: Preparing to generate the ALSA configuration file Mar 28 22:05:51 volumio volumio[1411]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Mar 28 22:05:51 volumio volumio[1411]: info: Mar 28 22:05:51 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand stop took 19 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:51 volumio volumio[1411]: info: Removing peppy_screensaver REST Endpoint Mar 28 22:05:51 volumio volumio[1411]: info: Mar 28 22:05:51 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:51 volumio volumio[1411]: info: Mar 28 22:05:51 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:51 volumio volumio[1411]: info: Mar 28 22:05:51 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:51 volumio volumio[1411]: info: Mar 28 22:05:51 volumio volumio[1411]: ---------------------------- MPD announces state update: player Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::getState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand status Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand status took 25 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand status took 7 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand status took 7 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand status took 3 milliseconds Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand status took 4 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseState Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: 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":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:51 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState stateService stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: No code Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: 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":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:51 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState stateService stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: No code Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio sudo[7459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio sudo[7459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: 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":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:51 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState stateService stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: No code Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: 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":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:51 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState stateService stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio sudo[7459]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:51 volumio volumio[1411]: info: No code Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio systemd[1]: volumio-app-plugins-music_service-mpd-mpd.conf.tmpl.mount: Deactivated successfully. Mar 28 22:05:51 volumio volumio[1411]: info: ------------------------------ 74ms Mar 28 22:05:51 volumio volumio[1411]: info: ------------------------------ 58ms Mar 28 22:05:51 volumio volumio[1411]: info: ------------------------------ 56ms Mar 28 22:05:51 volumio volumio[1411]: info: ------------------------------ 56ms Mar 28 22:05:51 volumio volumio[1411]: info: sendMpdCommand playlistinfo took 48 milliseconds Mar 28 22:05:51 volumio volumio[1411]: verbose: ControllerMpd::parseTrackInfo Mar 28 22:05:51 volumio volumio[1411]: info: ControllerMpd::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::servicePushState Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: 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":"Another Star","artist":"Stevie Wonder","album":"Songs In The Key Of Life","uri":"NAS/BIGNAS/DSD/Stevie Wonder/Stevie Wonder - Songs In The Key Of Life/17 - Stevie Wonder - Another Star.dsf","trackType":"dsf"} Mar 28 22:05:51 volumio volumio[1411]: verbose: CURRENT POSITION 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState stateService stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::syncState currentStatus stop Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: No code Mar 28 22:05:51 volumio volumio[1411]: info: CoreStateMachine::pushState Mar 28 22:05:51 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::volumioPushState Mar 28 22:05:51 volumio volumio[1411]: info: ------------------------------ 61ms Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Mar 28 22:05:51 volumio volumio[1411]: info: Creating Spotify config file Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: Spotify config file written Mar 28 22:05:51 volumio volumio[1411]: info: Asound.conf file written Mar 28 22:05:51 volumio sudo[7462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:05:51 volumio sudo[7462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:51 volumio sudo[7465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 28 22:05:51 volumio sudo[7465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:51 volumio sudo[7465]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:51 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:05:51 volumio systemd[1]: go-librespot-daemon.service: Killing process 5565 (go-librespot) with signal SIGKILL. Mar 28 22:05:51 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:05:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:51 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:51 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:51 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:51 volumio volumio[1411]: /usr/share/alsa/init/bcm2835:14: control element not found Mar 28 22:05:51 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:51 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 28 22:05:51 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 28 22:05:51 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Digital Playback Switch:0' : Remote I/O error Mar 28 22:05:51 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:FIR Filter Type:0' : Invalid argument Mar 28 22:05:51 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Mar 28 22:05:51 volumio volumio[1411]: info: Output device has changed, restarting MPD Mar 28 22:05:51 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Mar 28 22:05:51 volumio volumio[1411]: info: Output device has changed, restarting Shairport Sync Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:51 volumio sudo[7476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:51 volumio sudo[7476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:51 volumio sudo[7476]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:51 volumio sudo[7478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:51 volumio sudo[7478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:51 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:51 volumio volumio[1411]: info: Done. Mar 28 22:05:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:51 volumio volumio[1411]: info: Connection to go-librespot Websocket closed Mar 28 22:05:51 volumio volumio[1411]: info: Connection to go-librespot Websocket closed Mar 28 22:05:51 volumio volumio[1411]: info: Connection to go-librespot Websocket closed Mar 28 22:05:51 volumio volumio[1411]: info: Connection to go-librespot Websocket closed Mar 28 22:05:51 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio go-librespot[7472]: go-librespot daemon starting... Mar 28 22:05:51 volumio sudo[7462]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:51 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:51 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 28 22:05:51 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=debug msg="app state loaded" Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:05:51 volumio sudo[7498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:51 volumio sudo[7498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:51 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:51 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:51 volumio systemd[1]: mpd.service: Consumed 1min 5.959s CPU time. Mar 28 22:05:51 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:51 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:51 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:51 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:51 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:05:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:05:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:51 volumio systemd[1]: shairport-sync.service: Consumed 4.960s CPU time. Mar 28 22:05:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:51 volumio sudo[7498]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:51 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=info msg="zeroconf server listening on port 44833" Mar 28 22:05:51 volumio sudo[7502]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:51 volumio sudo[7502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:51 volumio sudo[7502]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:51 volumio go-librespot[7486]: time="2026-03-28T22:05:51+01:00" level=debug msg="obtained new client token: AAB+Eq75lQphJIOhW1Etv4hbWhsnrYJfb49CHSwOM5Sk/aFlPLhKbfAMZ6st1kNvGsaZQxDNMNTQ+XE4J8MkmxRSGnONefGB39Jd4SLmgnQzzyPOy0HeHllHSd3w6WuzBFQYBnbe8EZX6q6rY/dOcJc0vw5+kbVnHymujhPyogfSmN+ZRnewJ28ehJE9wdLfqMegA6SNU7LgAjnIkZzxKqCHig4Kt510I7/x9wGLsXut6w6C5renvGwGrw==" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="completed keyexchange" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="completed challenge" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=info msg="authenticated AP" username="fa*************li" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=info msg="authenticated Login5" username="fa*************li" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="initializing zeroconf session" username="fa*************li" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="dealer connection opened" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=trace msg="starting accesspoint recv loop" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=trace msg="starting dealer recv loop" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=trace msg="received accesspoint ping" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="received connection id: ZWM1NjdhZTItODc1...QTZFNDFFMjExNQ==" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=trace msg="received accesspoint pong ack" Mar 28 22:05:52 volumio go-librespot[7486]: time="2026-03-28T22:05:52+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 28 22:05:52 volumio volumio[1411]: info: Enabling plugin peppy_screensaver Mar 28 22:05:52 volumio volumio[1411]: info: Loading plugin "peppy_screensaver"... Mar 28 22:05:52 volumio volumio[1411]: info: Applying required configuration parameters for plugin peppy_screensaver Mar 28 22:05:52 volumio volumio[1411]: info: Preparing to generate the ALSA configuration file Mar 28 22:05:52 volumio volumio[1411]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 22:05:52 volumio volumio[1411]: info: Reading ALSA contributions from plugins. Mar 28 22:05:52 volumio volumio[1411]: info: Asound.conf file written Mar 28 22:05:52 volumio sudo[7537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 28 22:05:52 volumio sudo[7537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:52 volumio sudo[7537]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:52 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:52 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:52 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:52 volumio volumio[1411]: /usr/share/alsa/init/bcm2835:14: control element not found Mar 28 22:05:52 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:52 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 28 22:05:52 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 28 22:05:52 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Digital Playback Switch:0' : Remote I/O error Mar 28 22:05:52 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:FIR Filter Type:0' : Invalid argument Mar 28 22:05:52 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Mar 28 22:05:52 volumio volumio[1411]: info: Output device has changed, restarting MPD Mar 28 22:05:52 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Mar 28 22:05:52 volumio volumio[1411]: info: Output device has changed, restarting Shairport Sync Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:52 volumio sudo[7543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:52 volumio sudo[7543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:52 volumio sudo[7543]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:52 volumio sudo[7545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:52 volumio sudo[7545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:52 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:52 volumio volumio[1411]: info: PLUGIN START: peppy_screensaver Mar 28 22:05:52 volumio volumio[1411]: info: Loading i18n strings for locale it Mar 28 22:05:52 volumio volumio[1411]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 28 22:05:52 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:52 volumio volumio[1411]: info: /tmp/myfifo created Mar 28 22:05:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:52 volumio volumio[1411]: info: /tmp/myfifosa created Mar 28 22:05:52 volumio sudo[7565]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Mar 28 22:05:52 volumio sudo[7565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:52 volumio sudo[7565]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:52 volumio volumio[1411]: info: snd-dummy loaded Mar 28 22:05:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:52 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:53 volumio volumio[1411]: info: Adding peppy_screensaver REST Endpoint for plugin: user_interface/peppy_screensaver Mar 28 22:05:53 volumio volumio[1411]: info: peppy_screensaver: REST endpoint registered: peppy_screensaver Mar 28 22:05:53 volumio volumio[1411]: info: Updating peppy_screensaver_font REST Endpoint for plugin: user_interface/peppy_screensaver Mar 28 22:05:53 volumio volumio[1411]: info: peppy_screensaver: REST endpoint registered: peppy_screensaver_font Mar 28 22:05:53 volumio volumio[1411]: info: Updating peppy_screensaver_vinyl REST Endpoint for plugin: user_interface/peppy_screensaver Mar 28 22:05:53 volumio volumio[1411]: info: peppy_screensaver: REST endpoint registered: peppy_screensaver_vinyl Mar 28 22:05:53 volumio volumio[1411]: info: peppy_screensaver: Config version updated: c09ffbd8 Mar 28 22:05:53 volumio volumio[1411]: info: Done. Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:53 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:53 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:53 volumio volumio[1411]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Mar 28 22:05:53 volumio volumio[1411]: info: Creating Spotify config file Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: Spotify config file written Mar 28 22:05:53 volumio sudo[7578]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:53 volumio sudo[7578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:53 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:53 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:53 volumio sudo[7578]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio sudo[7609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:05:53 volumio sudo[7609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio sudo[7611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:53 volumio sudo[7611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio sudo[7615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:53 volumio sudo[7615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio volumio[1411]: info: peppy_screensaver: ALSA template: /data/plugins/user_interface/peppy_screensaver/Peppyalsa.postPeppyalsa.5.conf.tmpl (isX64=false) Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Mar 28 22:05:53 volumio volumio[1411]: info: Creating Spotify config file Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 28 22:05:53 volumio volumio[1411]: info: Preparing to generate the ALSA configuration file Mar 28 22:05:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:05:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:05:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:05:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:53 volumio volumio[1411]: info: Spotify config file written Mar 28 22:05:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:53 volumio sudo[7609]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:05:53 volumio go-librespot[7629]: go-librespot daemon starting... Mar 28 22:05:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:53 volumio systemd[1]: shairport-sync.service: Consumed 1.443s CPU time. Mar 28 22:05:53 volumio sudo[7628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Mar 28 22:05:53 volumio sudo[7628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 22:05:53 volumio sudo[7615]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio volumio[1411]: info: Reading ALSA contributions from plugins. Mar 28 22:05:53 volumio sudo[7611]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:53 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:53 volumio volumio[1411]: info: Asound.conf file unchanged, so no further update is needed Mar 28 22:05:53 volumio volumio[1411]: info: Output device has changed, restarting MPD Mar 28 22:05:53 volumio go-librespot[7630]: time="2026-03-28T22:05:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 28 22:05:53 volumio go-librespot[7630]: time="2026-03-28T22:05:53+01:00" level=debug msg="app state loaded" Mar 28 22:05:53 volumio sudo[7628]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio sudo[7634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:05:53 volumio sudo[7634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:05:53 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:05:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:53 volumio volumio[1411]: info: Output device has changed, restarting Shairport Sync Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:53 volumio sudo[7634]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio sudo[7642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:53 volumio sudo[7642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio sudo[7645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:53 volumio go-librespot[7644]: go-librespot daemon starting... Mar 28 22:05:53 volumio sudo[7645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio sudo[7642]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="app state loaded" Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:05:53 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:53 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:53 volumio sudo[7672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:53 volumio sudo[7672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio sudo[7672]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:53 volumio sudo[7690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:53 volumio sudo[7690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:05:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:05:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:53 volumio sudo[7676]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:53 volumio sudo[7676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:53 volumio sudo[7676]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:53 volumio sudo[7690]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=info msg="zeroconf server listening on port 33767" Mar 28 22:05:53 volumio volumio[1411]: info: CoreStateMachine::stop Mar 28 22:05:53 volumio volumio[1411]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 22:05:53 volumio volumio[1411]: info: Removing peppy_screensaver REST Endpoint Mar 28 22:05:53 volumio volumio[1411]: info: Disabling plugin peppy_screensaver Mar 28 22:05:53 volumio volumio[1411]: info: Preparing to generate the ALSA configuration file Mar 28 22:05:53 volumio sudo[7713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Mar 28 22:05:53 volumio sudo[7713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 28 22:05:53 volumio sudo[7713]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio systemd[1]: volumio-app-plugins-music_service-mpd-mpd.conf.tmpl.mount: Deactivated successfully. Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Mar 28 22:05:53 volumio volumio[1411]: info: Creating Spotify config file Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: Spotify config file written Mar 28 22:05:53 volumio sudo[7716]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:53 volumio sudo[7716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio volumio[1411]: info: Asound.conf file written Mar 28 22:05:53 volumio sudo[7719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="obtained new client token: AADncvjfYjgo3J8ZR/OnwniL5TjSHShUSVChDwr/PG5Ymdm1duy7K3Ku/1U5vkhApWjl8Vi0Rn0jlkGbEXp92W1G3a7iblahybMFRY3CORhjt7UymzQ4ophYoqTnfT8K+Ppc6WEXG+vnu6SIme7y+gDFrToSYwsDO9Fgy2LQkAwT1rHJSQUQBgGaHMY8uVNGblbE86eRlK+qHsWxGKoN+RKdR9hV9Etvjfa11wnY53F1ABd2X0xjM+wMvQ==" Mar 28 22:05:53 volumio sudo[7719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:53 volumio sudo[7722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 28 22:05:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:53 volumio sudo[7722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:53 volumio sudo[7722]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:53 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:53 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:53 volumio volumio[1411]: /usr/share/alsa/init/bcm2835:14: control element not found Mar 28 22:05:53 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:53 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 28 22:05:53 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 28 22:05:53 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Digital Playback Switch:0' : Remote I/O error Mar 28 22:05:53 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:FIR Filter Type:0' : Invalid argument Mar 28 22:05:53 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Mar 28 22:05:53 volumio volumio[1411]: info: Output device has changed, restarting MPD Mar 28 22:05:53 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Mar 28 22:05:53 volumio volumio[1411]: info: Output device has changed, restarting Shairport Sync Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 22:05:53 volumio sudo[7733]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:53 volumio sudo[7733]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:53 volumio sudo[7733]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:53 volumio sudo[7734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:53 volumio sudo[7734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:53 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:53 volumio volumio[1411]: info: Done. Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 28 22:05:53 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:53 volumio go-librespot[7648]: time="2026-03-28T22:05:53+01:00" level=debug msg="completed keyexchange" Mar 28 22:05:53 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:05:53 volumio systemd[1]: go-librespot-daemon.service: Killing process 7658 (go-librespot) with signal SIGKILL. Mar 28 22:05:53 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:54 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio sudo[7743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:54 volumio sudo[7743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:54 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:54 volumio sudo[7719]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:54 volumio go-librespot[7751]: go-librespot daemon starting... Mar 28 22:05:54 volumio sudo[7754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:54 volumio sudo[7754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:54 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=info msg="running go-librespot 0.4.0" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="app state loaded" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:05:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:05:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:54 volumio sudo[7754]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:54 volumio sudo[7763]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:54 volumio sudo[7763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:54 volumio sudo[7763]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=info msg="zeroconf server listening on port 43259" Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="obtained new client token: AADIUOmH57ln3mz1y19iqiuEcerUP6f5TPd4maVwiQk79UC6MD2R3kUPyTCgkxpkZxa/b6O84r2/8CkjfimyTWC2utOFvjaN7YUQ5NELdrTJePuw3Xhp3mz1qV9DBGYnvMbF6lmEBu9gOzO09sUo/6FhiTPaTFHZEpGTIj29kH+ISAIVuhegvEphthPJUAG1uoh6VfRWZrQHgs1Hvfzsip5V1lwVwiBmFSn8Hvz0Oi3HHB83XzGLG52ypQ==" Mar 28 22:05:54 volumio volumio[1411]: info: Enabling plugin peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: Loading plugin "peppy_screensaver"... Mar 28 22:05:54 volumio volumio[1411]: info: Applying required configuration parameters for plugin peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: Preparing to generate the ALSA configuration file Mar 28 22:05:54 volumio volumio[1411]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 22:05:54 volumio volumio[1411]: info: Reading ALSA contributions from plugins. Mar 28 22:05:54 volumio volumio[1411]: info: Asound.conf file written Mar 28 22:05:54 volumio sudo[7784]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 28 22:05:54 volumio sudo[7784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 28 22:05:54 volumio sudo[7784]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:54 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:54 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 28 22:05:54 volumio volumio[1411]: /usr/share/alsa/init/bcm2835:14: control element not found Mar 28 22:05:54 volumio volumio[1411]: No state is present for card b1 Mar 28 22:05:54 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 28 22:05:54 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 28 22:05:54 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:Digital Playback Switch:0' : Remote I/O error Mar 28 22:05:54 volumio volumio[1411]: /usr/sbin/alsactl: set_control:1475: Cannot write control '2:0:0:FIR Filter Type:0' : Invalid argument Mar 28 22:05:54 volumio volumio[1411]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Mar 28 22:05:54 volumio volumio[1411]: info: Output device has changed, restarting MPD Mar 28 22:05:54 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="completed keyexchange" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="completed challenge" Mar 28 22:05:54 volumio volumio[1411]: info: Output device has changed, restarting Shairport Sync Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:54 volumio volumio[1411]: info: PLUGIN START: peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: Loading i18n strings for locale it Mar 28 22:05:54 volumio sudo[7792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:54 volumio sudo[7792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:54 volumio volumio[1411]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 28 22:05:54 volumio sudo[7794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:54 volumio sudo[7794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:54 volumio sudo[7792]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio volumio[1411]: info: /tmp/myfifo created Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=info msg="authenticated AP" username="fa*************li" Mar 28 22:05:54 volumio volumio[1411]: info: /tmp/myfifosa created Mar 28 22:05:54 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:54 volumio sudo[7812]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Mar 28 22:05:54 volumio sudo[7812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:54 volumio sudo[7812]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio volumio[1411]: info: snd-dummy loaded Mar 28 22:05:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=info msg="authenticated Login5" username="fa*************li" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="initializing zeroconf session" username="fa*************li" Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:54 volumio volumio[1411]: info: Adding peppy_screensaver REST Endpoint for plugin: user_interface/peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: peppy_screensaver: REST endpoint registered: peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: Updating peppy_screensaver_font REST Endpoint for plugin: user_interface/peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: peppy_screensaver: REST endpoint registered: peppy_screensaver_font Mar 28 22:05:54 volumio volumio[1411]: info: Updating peppy_screensaver_vinyl REST Endpoint for plugin: user_interface/peppy_screensaver Mar 28 22:05:54 volumio volumio[1411]: info: peppy_screensaver: REST endpoint registered: peppy_screensaver_vinyl Mar 28 22:05:54 volumio volumio[1411]: info: Done. Mar 28 22:05:54 volumio volumio[1411]: info: Initializing connection to go-librespot Websocket Mar 28 22:05:54 volumio volumio[1411]: info: go-librespot daemon successfully initialized Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:54 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:54 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:54 volumio volumio[1411]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Mar 28 22:05:54 volumio volumio[1411]: info: Creating Spotify config file Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="new websocket client" Mar 28 22:05:54 volumio sudo[7823]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:54 volumio sudo[7823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="dealer connection opened" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=trace msg="starting accesspoint recv loop" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=trace msg="starting dealer recv loop" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=trace msg="received accesspoint ping" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:54 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:54 volumio go-librespot[7755]: time="2026-03-28T22:05:54+01:00" level=debug msg="received connection id: Yjg5ODUyMjMtNDRm...OUI5N0NFNTBBRQ==" Mar 28 22:05:54 volumio volumio[1411]: info: Connection to go-librespot Websocket established Mar 28 22:05:54 volumio sudo[7823]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:54 volumio volumio[1411]: info: Spotify config file written Mar 28 22:05:54 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:55 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:55 volumio sudo[7858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:05:55 volumio sudo[7858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio go-librespot[7755]: time="2026-03-28T22:05:55+01:00" level=trace msg="received accesspoint pong ack" Mar 28 22:05:55 volumio sudo[7863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:55 volumio sudo[7863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio sudo[7860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:55 volumio sudo[7860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Killing process 7759 (go-librespot) with signal SIGKILL. Mar 28 22:05:55 volumio volumio[1411]: info: peppy_screensaver: ALSA template: /data/plugins/user_interface/peppy_screensaver/Peppyalsa.postPeppyalsa.5.conf.tmpl (isX64=false) Mar 28 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:55 volumio volumio[1411]: info: Connection to go-librespot Websocket closed Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Mar 28 22:05:55 volumio volumio[1411]: info: Creating Spotify config file Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 28 22:05:55 volumio volumio[1411]: info: Preparing to generate the ALSA configuration file Mar 28 22:05:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:05:55 volumio sudo[7858]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio go-librespot[7874]: go-librespot daemon starting... Mar 28 22:05:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:55 volumio sudo[7876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio sudo[7876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio volumio[1411]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 22:05:55 volumio volumio[1411]: info: Reading ALSA contributions from plugins. Mar 28 22:05:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:55 volumio sudo[7876]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio volumio[1411]: info: Spotify config file written Mar 28 22:05:55 volumio sudo[7863]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio go-librespot[7877]: time="2026-03-28T22:05:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 28 22:05:55 volumio sudo[7860]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio go-librespot[7877]: time="2026-03-28T22:05:55+01:00" level=debug msg="app state loaded" Mar 28 22:05:55 volumio go-librespot[7877]: time="2026-03-28T22:05:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 22:05:55 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile Mar 28 22:05:55 volumio sudo[7886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 22:05:55 volumio sudo[7886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio volumio[1411]: info: Shairport-Sync Started Mar 28 22:05:55 volumio sudo[7889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:55 volumio sudo[7889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio sudo[7889]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 28 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Mar 28 22:05:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Mar 28 22:05:55 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio sudo[7886]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:55 volumio volumio[1411]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Mar 28 22:05:55 volumio volumio[1411]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Mar 28 22:05:55 volumio volumio[1411]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Mar 28 22:05:55 volumio volumio[1411]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Mar 28 22:05:55 volumio volumio[1411]: followed by "systemctl start go-librespot-daemon.service" again. Mar 28 22:05:55 volumio volumio[1411]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Mar 28 22:05:55 volumio volumio[1411]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Mar 28 22:05:55 volumio volumio[1411]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Mar 28 22:05:55 volumio volumio[1411]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Mar 28 22:05:55 volumio volumio[1411]: followed by "systemctl start go-librespot-daemon.service" again. Mar 28 22:05:55 volumio volumio[1411]: info: Asound.conf file unchanged, so no further update is needed Mar 28 22:05:55 volumio volumio[1411]: info: Output device has changed, restarting MPD Mar 28 22:05:55 volumio volumio[1411]: info: Output device has changed, restarting Shairport Sync Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:55 volumio sudo[7910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 22:05:55 volumio sudo[7910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio sudo[7913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:55 volumio sudo[7913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio sudo[7910]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio volumio[1411]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 22:05:55 volumio volumio[1411]: info: MPD Permissions set Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: Starting Shairport Sync Mar 28 22:05:55 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:55 volumio volumio[1411]: warn: peppy_screensaver: Failed to set MPD output: Error: Command failed: mpc enable 1 Mar 28 22:05:55 volumio volumio[1411]: MPD error: Connection reset by peer Mar 28 22:05:55 volumio sudo[7927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 22:05:55 volumio sudo[7927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 28 22:05:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:55 volumio systemd[1]: shairport-sync.service: Start request repeated too quickly. Mar 28 22:05:55 volumio systemd[1]: shairport-sync.service: Failed with result 'start-limit-hit'. Mar 28 22:05:55 volumio systemd[1]: Failed to start shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 28 22:05:55 volumio sudo[7927]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio volumio[1411]: info: Shairport-sync error: Error: Command failed: /usr/bin/sudo /bin/systemctl restart shairport-sync Mar 28 22:05:55 volumio volumio[1411]: Job for shairport-sync.service failed because start of the service was attempted too often. Mar 28 22:05:55 volumio volumio[1411]: See "systemctl status shairport-sync.service" and "journalctl -xeu shairport-sync.service" for details. Mar 28 22:05:55 volumio volumio[1411]: To force a start use "systemctl reset-failed shairport-sync.service" Mar 28 22:05:55 volumio volumio[1411]: followed by "systemctl start shairport-sync.service" again. Mar 28 22:05:55 volumio sudo[7929]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:55 volumio sudo[7929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:55 volumio sudo[7929]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 28 22:05:55 volumio sudo[7933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:55 volumio sudo[7933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 28 22:05:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:55 volumio sudo[7938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 22:05:55 volumio sudo[7938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 22:05:55 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 28 22:05:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 28 22:05:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 28 22:05:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 28 22:05:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 28 22:05:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio volumio[1411]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 22:05:55 volumio sudo[7942]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 28 22:05:55 volumio sudo[7942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 28 22:05:55 volumio sudo[7942]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:56 volumio volumio[1411]: info: go-librespot daemon successfully initialized Mar 28 22:05:56 volumio volumio[1411]: info: go-librespot daemon successfully initialized Mar 28 22:05:56 volumio volumio[1411]: info: CoreCommandRouter::volumioGetState Mar 28 22:05:56 volumio volumio[1411]: info: CorePlayQueue::getTrack 16 Mar 28 22:05:56 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:56 volumio volumio[1411]: info: Listing playlists Mar 28 22:05:57 volumio volumio[1411]: info: go-librespot daemon successfully initialized Mar 28 22:05:57 volumio mpd[7946]: 2026-03-28T22:05:57 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 22:05:57 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 28 22:05:57 volumio volumio[1411]: info: peppy_screensaver: MPD output 1 enabled Mar 28 22:05:57 volumio sudo[7933]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio volumio[1411]: info: peppy_screensaver: Startup - MPD output 1 enabled Mar 28 22:05:57 volumio sudo[7645]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7545]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7913]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7794]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7716]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7743]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7938]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7478]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio sudo[7734]: pam_unix(sudo:session): session closed for user root Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: MPD error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: The expression evaluated to a falsy value: Mar 28 22:05:57 volumio volumio[1411]: assert.ok(self.idling) Mar 28 22:05:57 volumio volumio[1411]: error: updateQueue error: null Mar 28 22:05:57 volumio volumio[1411]: info: peppy_screensaver: Startup - MPD output 1 enabled Mar 28 22:05:57 volumio volumio[1411]: info: Initializing connection to go-librespot Websocket Mar 28 22:05:57 volumio volumio[1411]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:05:57 volumio volumio[1411]: info: Getting Spotify volume Mar 28 22:05:57 volumio volumio[1411]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:05:57 volumio volumio[1411]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 22:05:57 volumio volumio[1411]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 28 22:05:57 volumio volumio[1411]: errno: -111, Mar 28 22:05:57 volumio volumio[1411]: code: 'ECONNREFUSED', Mar 28 22:05:57 volumio volumio[1411]: syscall: 'connect', Mar 28 22:05:57 volumio volumio[1411]: address: '127.0.0.1', Mar 28 22:05:57 volumio volumio[1411]: port: 9879, Mar 28 22:05:57 volumio volumio[1411]: response: undefined Mar 28 22:05:57 volumio volumio[1411]: } Mar 28 22:05:57 volumio volumio[1411]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 22:05:58 volumio sudo[7967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 22:04' Mar 28 22:05:58 volumio sudo[7967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"