Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 07 15:35:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 07 15:35:05 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:05 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:05 volumio volumio[1205]: info: Listing playlists Feb 07 15:35:05 volumio volumio[1205]: info: Listing playlists Feb 07 15:35:15 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:15 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:16 volumio go-librespot[1602]: time="2026-02-07T15:35:16+01:00" level=trace msg="received accesspoint ping" Feb 07 15:35:16 volumio go-librespot[1602]: time="2026-02-07T15:35:16+01:00" level=trace msg="received accesspoint pong ack" Feb 07 15:35:17 volumio go-librespot[1602]: time="2026-02-07T15:35:17+01:00" level=trace msg="sent dealer ping" Feb 07 15:35:17 volumio go-librespot[1602]: time="2026-02-07T15:35:17+01:00" level=trace msg="received dealer pong" Feb 07 15:35:25 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:25 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:25 volumio volumio[1205]: info: Listing playlists Feb 07 15:35:25 volumio volumio[1205]: info: Listing playlists Feb 07 15:35:35 volumio volumio[1205]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:35 volumio volumio[1205]: info: Restoring Previous Volume level: 100 false true Feb 07 15:35:35 volumio volumio[1205]: info: VolumeController::SetAlsaVolume100 Feb 07 15:35:35 volumio volumio[1205]: info: Enable softmixer device for audio device number 5 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioStop Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::stop Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::updateTrackBlock Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrackBlock Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::stPlaybackTimer Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::serviceStop Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::serviceStop Feb 07 15:35:35 volumio volumio[1205]: info: ControllerMpd::stop Feb 07 15:35:35 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand stop Feb 07 15:35:35 volumio volumio[1205]: info: Enable softmixer device for audio device undefined Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 07 15:35:35 volumio volumio[1205]: info: Updating Volume Controller Parameters: Device: 5 Name: Musical Fidelity V-DAC 24/96 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 07 15:35:35 volumio volumio[1205]: info: Disabling external Volume Control Feb 07 15:35:35 volumio volumio[1205]: info: Output device has changed, restarting MPD Feb 07 15:35:35 volumio volumio[1205]: info: Output device has changed, restarting Shairport Sync Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:35 volumio sudo[4911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 15:35:35 volumio sudo[4911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:35 volumio sudo[4913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 15:35:35 volumio sudo[4913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:35 volumio volumio[1205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 15:35:35 volumio sudo[4911]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:35 volumio volumio[1205]: info: Volume configurations have been set Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 07 15:35:35 volumio volumio[1205]: info: Updating Volume Controller Parameters: Device: 5 Name: Musical Fidelity V-DAC 24/96 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 07 15:35:35 volumio volumio[1205]: info: Disabling external Volume Control Feb 07 15:35:35 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:35 volumio volumio[1205]: error: MPD error: Error: write EPIPE Feb 07 15:35:35 volumio volumio[1205]: error: write EPIPE {"code":"EPIPE","errno":-32,"syscall":"write"} Feb 07 15:35:35 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:35 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:35 volumio volumio[1205]: info: MPD Permissions set Feb 07 15:35:35 volumio volumio[1205]: info: Software Volume ALSA configuration written Feb 07 15:35:35 volumio volumio[1205]: info: Preparing to generate the ALSA configuration file Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Feb 07 15:35:35 volumio volumio[1205]: info: Reading ALSA contributions from plugins. Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 07 15:35:35 volumio volumio[1205]: info: Starting Shairport Sync Feb 07 15:35:35 volumio volumio[1205]: info: Asound.conf file written Feb 07 15:35:35 volumio sudo[4949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 15:35:35 volumio sudo[4949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:35 volumio sudo[4952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Feb 07 15:35:35 volumio sudo[4952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 15:35:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 15:35:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 15:35:35 volumio systemd[1]: shairport-sync.service: Consumed 6.483s CPU time. Feb 07 15:35:35 volumio sudo[4952]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:35 volumio volumio[1205]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 07 15:35:35 volumio volumio[1205]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 07 15:35:35 volumio volumio[1205]: info: Output device has changed, restarting MPD Feb 07 15:35:35 volumio volumio[1205]: info: Output device has changed, restarting Shairport Sync Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:35 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 15:35:35 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 15:35:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 15:35:35 volumio systemd[1]: mpd.service: Consumed 3.724s CPU time. Feb 07 15:35:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 15:35:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 15:35:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 15:35:35 volumio sudo[4949]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:35 volumio sudo[4960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 15:35:35 volumio sudo[4960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:35 volumio sudo[4960]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 15:35:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 15:35:35 volumio sudo[4962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 15:35:35 volumio sudo[4962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:35 volumio volumio[1205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 15:35:35 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 15:35:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 15:35:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 15:35:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 15:35:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 15:35:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 15:35:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 15:35:35 volumio sudo[4989]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 15:35:35 volumio sudo[4989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 15:35:35 volumio sudo[4989]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:36 volumio kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 2 ep 1 Feb 07 15:35:36 volumio kernel: xhci_hcd 0000:01:00.0: @0000000428d16b10 00000000 00000000 0e000000 02028001 Feb 07 15:35:36 volumio volumio[1205]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Feb 07 15:35:37 volumio volumio[1205]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Feb 07 15:35:37 volumio volumio[1205]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Feb 07 15:35:37 volumio volumio[1205]: Found hardware: "USB-Audio" "USB Mixer" "USB4d46:0002" "" "" Feb 07 15:35:37 volumio volumio[1205]: Hardware is initialized using a generic method Feb 07 15:35:37 volumio volumio[1205]: info: Output device has changed, restarting MPD Feb 07 15:35:37 volumio volumio[1205]: info: Output device has changed, restarting Shairport Sync Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:37 volumio sudo[5011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 15:35:37 volumio sudo[5011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:37 volumio sudo[5013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 15:35:37 volumio sudo[5013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:37 volumio sudo[5011]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:37 volumio volumio[1205]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 07 15:35:37 volumio volumio[1205]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 07 15:35:37 volumio volumio[1205]: info: Disabling external Volume Control Feb 07 15:35:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 15:35:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 15:35:37 volumio systemd[1]: mpd.service: Consumed 1.344s CPU time. Feb 07 15:35:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 15:35:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 15:35:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 15:35:37 volumio volumio[1205]: info: VolumeController::SetAlsaVolume0 Feb 07 15:35:37 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:37 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:37 volumio volumio[1205]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Feb 07 15:35:37 volumio volumio[1205]: info: MPD Permissions set Feb 07 15:35:37 volumio volumio[1205]: info: MPD Permissions set Feb 07 15:35:37 volumio volumio[1205]: info: Shairport-Sync Started Feb 07 15:35:37 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:37 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 15:35:37 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:37 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 86 Feb 07 15:35:37 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:37 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 07 15:35:37 volumio volumio[1205]: info: Setting Spotify Volume from Volumio: 100 Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:37 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:37 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:37 volumio volumio[1205]: info: Starting Shairport Sync Feb 07 15:35:37 volumio volumio[1205]: info: Starting Shairport Sync Feb 07 15:35:37 volumio sudo[5045]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 15:35:37 volumio sudo[5045]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:37 volumio sudo[5047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 15:35:37 volumio sudo[5047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 15:35:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 15:35:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 15:35:37 volumio systemd[1]: shairport-sync.service: Consumed 1.543s CPU time. Feb 07 15:35:37 volumio sudo[5032]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 15:35:37 volumio sudo[5032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 15:35:37 volumio sudo[5032]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 15:35:37 volumio sudo[5045]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:37 volumio sudo[5047]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:37 volumio volumio[1205]: info: Shairport-Sync Started Feb 07 15:35:37 volumio volumio[1205]: info: Shairport-Sync Started Feb 07 15:35:38 volumio mpd[5054]: 2026-02-07T15:35:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 15:35:38 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 07 15:35:38 volumio sudo[5070]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 15:35:38 volumio sudo[5070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 15:35:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 15:35:38 volumio sudo[4962]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:38 volumio sudo[4913]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:38 volumio sudo[5013]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:38 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 15:35:38 volumio volumio[1205]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Feb 07 15:35:38 volumio volumio[1205]: info: Sending Spotify command with payload to local API: /player/volume Feb 07 15:35:38 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 15:35:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 15:35:38 volumio systemd[1]: mpd.service: Consumed 1.432s CPU time. Feb 07 15:35:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 15:35:38 volumio volumio[1205]: error: MPD error: The expression evaluated to a falsy value: Feb 07 15:35:38 volumio volumio[1205]: assert.ok(self.idling) Feb 07 15:35:38 volumio volumio[1205]: error: The expression evaluated to a falsy value: Feb 07 15:35:38 volumio volumio[1205]: assert.ok(self.idling) Feb 07 15:35:38 volumio volumio[1205]: error: MPD error: Error: write EPIPE Feb 07 15:35:38 volumio volumio[1205]: error: write EPIPE {"code":"EPIPE","errno":-32,"syscall":"write"} Feb 07 15:35:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 15:35:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 15:35:38 volumio volumio[1205]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Feb 07 15:35:38 volumio volumio[1205]: error: MPD error: Error: connect ECONNRESET /run/mpd/socket Feb 07 15:35:38 volumio volumio[1205]: error: MPD error: Error: connect ECONNRESET /run/mpd/socket Feb 07 15:35:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 15:35:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 15:35:38 volumio sudo[5076]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 15:35:38 volumio sudo[5076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 15:35:38 volumio sudo[5076]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:39 volumio volumio[1205]: info: VolumeController::SetAlsaVolume100 Feb 07 15:35:39 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:39 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:39 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:39 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:39 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:39 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:39 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:39 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:40 volumio mpd[5078]: 2026-02-07T15:35:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 15:35:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 15:35:40 volumio sudo[5070]: pam_unix(sudo:session): session closed for user root Feb 07 15:35:40 volumio volumio[1205]: error: updateQueue error: null Feb 07 15:35:40 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 15:35:43 volumio volumio[1205]: error: MPD error: The expression evaluated to a falsy value: Feb 07 15:35:43 volumio volumio[1205]: assert.ok(self.idling) Feb 07 15:35:43 volumio volumio[1205]: error: The expression evaluated to a falsy value: Feb 07 15:35:43 volumio volumio[1205]: assert.ok(self.idling) Feb 07 15:35:43 volumio volumio[1205]: error: updateQueue error: null Feb 07 15:35:45 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:45 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:45 volumio volumio[1205]: info: Listing playlists Feb 07 15:35:45 volumio volumio[1205]: info: Listing playlists Feb 07 15:35:47 volumio go-librespot[1602]: time="2026-02-07T15:35:47+01:00" level=trace msg="sent dealer ping" Feb 07 15:35:47 volumio go-librespot[1602]: time="2026-02-07T15:35:47+01:00" level=trace msg="received dealer pong" Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPlay Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::play index undefined Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::startPlaybackTimer Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::clearAddPlayTracks NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand stop Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand stop took 0 milliseconds Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand clear Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces system playlist update Feb 07 15:35:48 volumio volumio[1205]: info: Ignoring MPD Status Update Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand clear took 1 milliseconds Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand add "NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a" Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces system playlist update Feb 07 15:35:48 volumio volumio[1205]: info: Ignoring MPD Status Update Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces system playlist update Feb 07 15:35:48 volumio volumio[1205]: info: Ignoring MPD Status Update Feb 07 15:35:48 volumio volumio[1205]: error: updateQueue error: null Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces system playlist update Feb 07 15:35:48 volumio volumio[1205]: info: Ignoring MPD Status Update Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 4ms Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand add "NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a" took 3 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 3ms Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 2ms Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand play Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces system playlist update Feb 07 15:35:48 volumio volumio[1205]: info: Ignoring MPD Status Update Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces system playlist update Feb 07 15:35:48 volumio volumio[1205]: info: Ignoring MPD Status Update Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 7ms Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand play took 7 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 6ms Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 5ms Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand status took 36 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand status took 38 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand status took 37 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand status took 3 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand status took 2 milliseconds Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:35:48 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState stateService play Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus stop Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 43ms Feb 07 15:35:48 volumio volumio[1205]: info: Feb 07 15:35:48 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand status took 2 milliseconds Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: STATE SERVICE {"status":"play","position":0,"seek":366,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:35:48 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState stateService play Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus play Feb 07 15:35:48 volumio volumio[1205]: info: Received an update from plugin. extracting info from payload Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: STATE SERVICE {"status":"play","position":0,"seek":458,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:35:48 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState stateService play Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus play Feb 07 15:35:48 volumio volumio[1205]: info: Received an update from plugin. extracting info from payload Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:35:48 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState stateService play Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus play Feb 07 15:35:48 volumio volumio[1205]: info: Received an update from plugin. extracting info from payload Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:35:48 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState stateService play Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus play Feb 07 15:35:48 volumio volumio[1205]: info: Received an update from plugin. extracting info from payload Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 114ms Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 115ms Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 80ms Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 80ms Feb 07 15:35:48 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 71 milliseconds Feb 07 15:35:48 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:35:48 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:35:48 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState stateService play Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus play Feb 07 15:35:48 volumio volumio[1205]: info: Received an update from plugin. extracting info from payload Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:48 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:48 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:48 volumio volumio[1205]: info: ------------------------------ 89ms Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 15:35:48 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: false Feb 07 15:35:50 volumio volumio[1205]: info: VolumeController::SetAlsaVolume53 Feb 07 15:35:50 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:50 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:50 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:50 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:50 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Feb 07 15:35:50 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 100 Feb 07 15:35:50 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 53 Feb 07 15:35:50 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 07 15:35:50 volumio volumio[1205]: info: Setting Spotify Volume from Volumio: 53 Feb 07 15:35:51 volumio volumio[1205]: info: VolumeController::SetAlsaVolume32 Feb 07 15:35:51 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:51 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:51 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:51 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:51 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Feb 07 15:35:51 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 53 Feb 07 15:35:51 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 32 Feb 07 15:35:51 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 07 15:35:51 volumio volumio[1205]: info: Setting Spotify Volume from Volumio: 32 Feb 07 15:35:52 volumio volumio[1205]: info: VolumeController::SetAlsaVolume62 Feb 07 15:35:52 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:52 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:52 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:52 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:52 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 62 Feb 07 15:35:52 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 32 Feb 07 15:35:52 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 62 Feb 07 15:35:52 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 07 15:35:52 volumio volumio[1205]: info: Setting Spotify Volume from Volumio: 62 Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: SETTING SPOTIFY VOLUME 62 Feb 07 15:35:54 volumio volumio[1205]: info: Sending Spotify command with payload to local API: /player/volume Feb 07 15:35:54 volumio go-librespot[1602]: time="2026-02-07T15:35:54+01:00" level=debug msg="update volume requested to 40631/65535" Feb 07 15:35:54 volumio go-librespot[1602]: time="2026-02-07T15:35:54+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 07 15:35:54 volumio volumio[1205]: info: VolumeController::SetAlsaVolume82 Feb 07 15:35:54 volumio go-librespot[1602]: time="2026-02-07T15:35:54+01:00" level=trace msg="emitting websocket event: volume" Feb 07 15:35:54 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:35:54 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:54 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:35:54 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: received: {"type":"volume","data":{"value":62,"max":100}} Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: RECEIVED SPOTIFY VOLUME 62 Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 82 Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 62 Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 82 Feb 07 15:35:54 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 07 15:35:54 volumio volumio[1205]: info: Setting Spotify Volume from Volumio: 82 Feb 07 15:35:55 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:35:55 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:35:56 volumio volumio[1205]: SPOTIFY: SETTING SPOTIFY VOLUME 82 Feb 07 15:35:56 volumio volumio[1205]: info: Sending Spotify command with payload to local API: /player/volume Feb 07 15:35:56 volumio go-librespot[1602]: time="2026-02-07T15:35:56+01:00" level=debug msg="update volume requested to 53738/65535" Feb 07 15:35:56 volumio go-librespot[1602]: time="2026-02-07T15:35:56+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 07 15:35:56 volumio go-librespot[1602]: time="2026-02-07T15:35:56+01:00" level=trace msg="emitting websocket event: volume" Feb 07 15:35:56 volumio volumio[1205]: SPOTIFY: received: {"type":"volume","data":{"value":82,"max":100}} Feb 07 15:35:56 volumio volumio[1205]: SPOTIFY: RECEIVED SPOTIFY VOLUME 82 Feb 07 15:36:00 volumio volumio[1205]: info: VolumeController::SetAlsaVolume76 Feb 07 15:36:00 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:36:00 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:00 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:36:00 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:36:00 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Feb 07 15:36:00 volumio volumio[1205]: SPOTIFY: SPOTIFY VOLUME 82 Feb 07 15:36:00 volumio volumio[1205]: SPOTIFY: VOLUMIO VOLUME 76 Feb 07 15:36:00 volumio volumio[1205]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 07 15:36:00 volumio volumio[1205]: info: Setting Spotify Volume from Volumio: 76 Feb 07 15:36:01 volumio volumio[1205]: SPOTIFY: SETTING SPOTIFY VOLUME 76 Feb 07 15:36:01 volumio volumio[1205]: info: Sending Spotify command with payload to local API: /player/volume Feb 07 15:36:01 volumio go-librespot[1602]: time="2026-02-07T15:36:01+01:00" level=debug msg="update volume requested to 49806/65535" Feb 07 15:36:02 volumio go-librespot[1602]: time="2026-02-07T15:36:02+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 07 15:36:02 volumio go-librespot[1602]: time="2026-02-07T15:36:02+01:00" level=trace msg="emitting websocket event: volume" Feb 07 15:36:02 volumio volumio[1205]: SPOTIFY: received: {"type":"volume","data":{"value":76,"max":100}} Feb 07 15:36:02 volumio volumio[1205]: SPOTIFY: RECEIVED SPOTIFY VOLUME 76 Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::volumioPause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::stPlaybackTimer Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::servicePause Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::servicePause Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::pause Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand pause Feb 07 15:36:03 volumio volumio[1205]: info: Feb 07 15:36:03 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand pause took 1 milliseconds Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:36:03 volumio volumio[1205]: info: Feb 07 15:36:03 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:36:03 volumio volumio[1205]: info: Feb 07 15:36:03 volumio volumio[1205]: ---------------------------- MPD announces state update: player Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::getState Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand status Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand status took 2 milliseconds Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand status took 2 milliseconds Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand status took 1 milliseconds Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::parseState Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 15:36:03 volumio volumio[1205]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:36:03 volumio volumio[1205]: verbose: ControllerMpd::parseTrackInfo Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15474,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:36:03 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::syncState stateService pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::stPlaybackTimer Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15474,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:36:03 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::syncState stateService pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::stPlaybackTimer Feb 07 15:36:03 volumio volumio[1205]: info: ControllerMpd::pushState Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::servicePushState Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":15474,"duration":245,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"928 Kbps","isStreaming":false,"title":"Treat Her Like A Lady","artist":"Celine Dion","album":"Let's Talk About Love","uri":"NAS/NAS/Celine Dion/Let's Talk About Love/03 Treat Her Like A Lady.m4a","trackType":"m4a"} Feb 07 15:36:03 volumio volumio[1205]: verbose: CURRENT POSITION 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::syncState stateService pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::syncState currentStatus pause Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::pushState Feb 07 15:36:03 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:03 volumio volumio[1205]: info: CoreCommandRouter::volumioPushState Feb 07 15:36:03 volumio volumio[1205]: info: CoreStateMachine::stPlaybackTimer Feb 07 15:36:03 volumio volumio[1205]: info: ------------------------------ 29ms Feb 07 15:36:03 volumio volumio[1205]: info: ------------------------------ 29ms Feb 07 15:36:03 volumio volumio[1205]: info: ------------------------------ 29ms Feb 07 15:36:03 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Feb 07 15:36:03 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Feb 07 15:36:03 volumio volumio[1205]: SPOTIFY: RECEIVED VOLUMIO VOLUME 76 Feb 07 15:36:05 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:36:05 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:05 volumio volumio[1205]: info: Listing playlists Feb 07 15:36:05 volumio volumio[1205]: info: Listing playlists Feb 07 15:36:15 volumio volumio[1205]: info: CoreCommandRouter::volumioGetState Feb 07 15:36:15 volumio volumio[1205]: info: CorePlayQueue::getTrack 2 Feb 07 15:36:17 volumio volumio[1205]: info: CoreCommandRouter::volumioGetVisibleSources Feb 07 15:36:17 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 15:36:17 volumio go-librespot[1602]: time="2026-02-07T15:36:17+01:00" level=trace msg="sent dealer ping" Feb 07 15:36:17 volumio go-librespot[1602]: time="2026-02-07T15:36:17+01:00" level=trace msg="received dealer pong" Feb 07 15:36:20 volumio volumio[1205]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 07 15:36:20 volumio volumio[1205]: info: CURURI: artists:// Feb 07 15:36:22 volumio volumio[1205]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 15:36:22 volumio volumio[1205]: TypeError: Cannot read properties of null (reading 'slice') Feb 07 15:36:22 volumio volumio[1205]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 07 15:36:22 volumio volumio[1205]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 07 15:36:22 volumio volumio[1205]: at Object.onceWrapper (node:events:629:26) Feb 07 15:36:22 volumio volumio[1205]: at ClientRequest.emit (node:events:514:28) Feb 07 15:36:22 volumio volumio[1205]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 07 15:36:22 volumio volumio[1205]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 07 15:36:22 volumio volumio[1205]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 07 15:36:22 volumio volumio[1205]: at TLSSocket.emit (node:events:514:28) Feb 07 15:36:22 volumio volumio[1205]: at addChunk (node:internal/streams/readable:343:12) Feb 07 15:36:22 volumio volumio[1205]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 07 15:36:22 volumio volumio[1205]: at Readable.push (node:internal/streams/readable:253:10) Feb 07 15:36:22 volumio volumio[1205]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Feb 07 15:36:22 volumio volumio[1205]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 15:36:22 volumio sudo[5163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 15:35' Feb 07 15:36:22 volumio sudo[5163]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"