-- Logs begin at Wed 2025-12-24 19:35:06 CET, end at Sat 2025-12-27 18:03:18 CET. -- Dec 27 18:02:04 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:04 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:04 volumio volumio[1167]: info: Prefetching next song Dec 27 18:02:04 volumio volumio[1167]: info: DOING PREFETCH IN MPD Dec 27 18:02:04 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a" Dec 27 18:02:04 volumio volumio[1167]: info: sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a" took 1 milliseconds Dec 27 18:02:04 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand consume 1 Dec 27 18:02:04 volumio volumio[1167]: info: Dec 27 18:02:04 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:04 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:04 volumio volumio[1167]: info: sendMpdCommand consume 1 took 1 milliseconds Dec 27 18:02:04 volumio volumio[1167]: info: Dec 27 18:02:04 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:04 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:04 volumio volumio[1167]: info: Dec 27 18:02:04 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:04 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:04 volumio volumio[1167]: info: ------------------------------ 2ms Dec 27 18:02:04 volumio volumio[1167]: info: ------------------------------ 2ms Dec 27 18:02:04 volumio volumio[1167]: info: ------------------------------ 3ms Dec 27 18:02:08 volumio volumio[1167]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioGetState Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:08 volumio volumio[1167]: info: Restoring Previous Volume level: 44 false true Dec 27 18:02:08 volumio volumio[1167]: info: VolumeController::SetAlsaVolume100 Dec 27 18:02:08 volumio volumio[1167]: info: Enable softmixer device for audio device number 5 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioStop Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::stop Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::stPlaybackTimer Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::serviceStop Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::serviceStop Dec 27 18:02:08 volumio volumio[1167]: info: ControllerMpd::stop Dec 27 18:02:08 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 18:02:08 volumio volumio[1167]: info: Enable softmixer device for audio device undefined Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 27 18:02:08 volumio volumio[1167]: info: Updating Volume Controller Parameters: Device: 5 Name: USB PnP Sound Device Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 27 18:02:08 volumio volumio[1167]: info: Disabling external Volume Control Dec 27 18:02:08 volumio volumio[1167]: info: Output device has changed, restarting MPD Dec 27 18:02:08 volumio sudo[13301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 18:02:08 volumio sudo[13301]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio sudo[13301]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio volumio[1167]: info: Output device has changed, restarting Shairport Sync Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:08 volumio sudo[13304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 18:02:08 volumio sudo[13304]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio systemd[1]: Stopping Music Player Daemon... Dec 27 18:02:08 volumio volumio[1167]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 18:02:08 volumio volumio[1167]: info: Volume configurations have been set Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 27 18:02:08 volumio volumio[1167]: info: Updating Volume Controller Parameters: Device: 5 Name: USB PnP Sound Device Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 27 18:02:08 volumio volumio[1167]: info: Disabling external Volume Control Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:08 volumio volumio[1167]: error: MPD error: Error: write EPIPE Dec 27 18:02:08 volumio volumio[1167]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Dec 27 18:02:08 volumio volumio[1167]: info: MPD Permissions set Dec 27 18:02:08 volumio systemd[1]: mpd.service: Succeeded. Dec 27 18:02:08 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:08 volumio volumio[1167]: info: Software Volume ALSA configuration written Dec 27 18:02:08 volumio volumio[1167]: info: Preparing to generate the ALSA configuration file Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio systemd[1]: Starting Music Player Daemon... Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 27 18:02:08 volumio volumio[1167]: info: Reading ALSA contributions from plugins. Dec 27 18:02:08 volumio sudo[13320]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 18:02:08 volumio sudo[13320]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio sudo[13320]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 27 18:02:08 volumio volumio[1167]: info: VolumeController:: Volume=100 Mute =false Dec 27 18:02:08 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:08 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:08 volumio volumio[1167]: info: Starting Shairport Sync Dec 27 18:02:08 volumio sudo[13332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 18:02:08 volumio sudo[13332]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio volumio[1167]: info: Asound.conf file written Dec 27 18:02:08 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 18:02:08 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 18:02:08 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 18:02:08 volumio sudo[13336]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 27 18:02:08 volumio sudo[13336]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 18:02:08 volumio sudo[13336]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio sudo[13332]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio volumio[1167]: info: Output device has changed, restarting MPD Dec 27 18:02:08 volumio sudo[13343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 18:02:08 volumio sudo[13343]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio sudo[13343]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio volumio[1167]: info: Output device has changed, restarting Shairport Sync Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:08 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:08 volumio sudo[13346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 18:02:08 volumio sudo[13346]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 27 18:02:08 volumio systemd[1]: mpd.service: Succeeded. Dec 27 18:02:08 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 18:02:08 volumio volumio[1167]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 18:02:08 volumio systemd[1]: Starting Music Player Daemon... Dec 27 18:02:08 volumio sudo[13351]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 18:02:08 volumio sudo[13351]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:08 volumio sudo[13351]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio mpd[13356]: Dec 27 18:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 27 18:02:08 volumio systemd[1]: Started Music Player Daemon. Dec 27 18:02:08 volumio sudo[13304]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:08 volumio sudo[13346]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:09 volumio volumio[1167]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Dec 27 18:02:09 volumio volumio[1167]: Found hardware: "USB-Audio" "USB Mixer" "USB0d8c:013c" "" "" Dec 27 18:02:09 volumio volumio[1167]: Hardware is initialized using a generic method Dec 27 18:02:09 volumio volumio[1167]: info: Output device has changed, restarting MPD Dec 27 18:02:09 volumio sudo[13362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 18:02:09 volumio sudo[13362]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:09 volumio sudo[13362]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:09 volumio volumio[1167]: info: Output device has changed, restarting Shairport Sync Dec 27 18:02:09 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:09 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:09 volumio sudo[13365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 18:02:09 volumio sudo[13365]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:09 volumio systemd[1]: Stopping Music Player Daemon... Dec 27 18:02:09 volumio systemd[1]: mpd.service: Succeeded. Dec 27 18:02:09 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 18:02:09 volumio volumio[1167]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 27 18:02:10 volumio volumio[1167]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 27 18:02:10 volumio systemd[1]: Starting Music Player Daemon... Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 27 18:02:10 volumio volumio[1167]: info: Disabling external Volume Control Dec 27 18:02:10 volumio volumio[1167]: error: Upnp client error: Error: This socket has been ended by the other party Dec 27 18:02:10 volumio volumio[1167]: info: MPD Permissions set Dec 27 18:02:10 volumio volumio[1167]: info: MPD Permissions set Dec 27 18:02:10 volumio volumio[1167]: info: Shairport-Sync Started Dec 27 18:02:10 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:10 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:10 volumio sudo[13370]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 18:02:10 volumio sudo[13370]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio sudo[13370]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 18:02:10 volumio volumio[1167]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 27 18:02:10 volumio volumio[1167]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 27 18:02:10 volumio volumio[1167]: info: Starting Shairport Sync Dec 27 18:02:10 volumio volumio[1167]: info: Starting Shairport Sync Dec 27 18:02:10 volumio sudo[13391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 18:02:10 volumio sudo[13391]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 18:02:10 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 18:02:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 18:02:10 volumio sudo[13394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 18:02:10 volumio sudo[13394]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 18:02:10 volumio sudo[13391]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:10 volumio volumio[1167]: info: Shairport-Sync Started Dec 27 18:02:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 18:02:10 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 18:02:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 18:02:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 18:02:10 volumio sudo[13394]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:10 volumio volumio[1167]: info: Shairport-Sync Started Dec 27 18:02:10 volumio mpd[13381]: Dec 27 18:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 27 18:02:10 volumio systemd[1]: Started Music Player Daemon. Dec 27 18:02:10 volumio sudo[13365]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:10 volumio volumio[1167]: error: MPD error: The expression evaluated to a falsy value: Dec 27 18:02:10 volumio volumio[1167]: assert.ok(self.idling) Dec 27 18:02:10 volumio volumio[1167]: error: The expression evaluated to a falsy value: Dec 27 18:02:10 volumio volumio[1167]: assert.ok(self.idling) Dec 27 18:02:10 volumio volumio[1167]: error: updateQueue error: null Dec 27 18:02:10 volumio volumio[1167]: error: updateQueue error: null Dec 27 18:02:10 volumio volumio[1167]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 27 18:02:11 volumio volumio[1167]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 27 18:02:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Dec 27 18:02:11 volumio sudo[13407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 18:02:11 volumio sudo[13407]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:11 volumio systemd[1]: Stopping Music Player Daemon... Dec 27 18:02:11 volumio systemd[1]: mpd.service: Succeeded. Dec 27 18:02:11 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 18:02:11 volumio systemd[1]: Starting Music Player Daemon... Dec 27 18:02:11 volumio sudo[13409]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 18:02:11 volumio sudo[13409]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:11 volumio sudo[13409]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:11 volumio mpd[13411]: Dec 27 18:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 27 18:02:11 volumio systemd[1]: Started Music Player Daemon. Dec 27 18:02:11 volumio sudo[13407]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:11 volumio volumio[1167]: error: updateQueue error: null Dec 27 18:02:11 volumio volumio[1167]: error: Upnp client error: Error: This socket has been ended by the other party Dec 27 18:02:12 volumio volumio[1167]: info: VolumeController::SetAlsaVolume44 Dec 27 18:02:12 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:12 volumio volumio[1167]: info: CorePlayQueue::getTrack 0 Dec 27 18:02:12 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:12 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:13 volumio sudo[13431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 18:02:13 volumio sudo[13431]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:13 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 18:02:13 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 18:02:13 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 18:02:13 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 18:02:13 volumio sudo[13434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 18:02:13 volumio sudo[13434]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:13 volumio systemd[1]: Started MPD Monitor Service. Dec 27 18:02:13 volumio sudo[13431]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:13 volumio mpd_monitor.sh[13435]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 18:02:13 volumio volumio[1167]: info: Successfully started MPD Monitor Dec 27 18:02:13 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 18:02:13 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 18:02:13 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 18:02:13 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 18:02:13 volumio systemd[1]: Started MPD Monitor Service. Dec 27 18:02:13 volumio sudo[13434]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:13 volumio mpd_monitor.sh[13439]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 18:02:13 volumio volumio[1167]: info: Successfully started MPD Monitor Dec 27 18:02:13 volumio sudo[13444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 18:02:13 volumio sudo[13444]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:13 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 18:02:13 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 18:02:13 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 18:02:13 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 18:02:13 volumio systemd[1]: Started MPD Monitor Service. Dec 27 18:02:13 volumio mpd_monitor.sh[13446]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 18:02:13 volumio sudo[13444]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:13 volumio volumio[1167]: info: Successfully started MPD Monitor Dec 27 18:02:14 volumio sudo[13453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 18:02:14 volumio sudo[13453]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 18:02:14 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 18:02:14 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 18:02:14 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 18:02:14 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 18:02:14 volumio systemd[1]: Started MPD Monitor Service. Dec 27 18:02:14 volumio sudo[13453]: pam_unix(sudo:session): session closed for user root Dec 27 18:02:14 volumio mpd_monitor.sh[13455]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 18:02:14 volumio volumio[1167]: info: Successfully started MPD Monitor Dec 27 18:02:22 volumio volumio[1167]: info: CoreCommandRouter::volumioPlay Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::play index 1 Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::stop Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::play index undefined Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:02:22 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:02:22 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::clearAddPlayTracks USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand stop took 1 milliseconds Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand clear Dec 27 18:02:22 volumio volumio[1167]: info: Dec 27 18:02:22 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:22 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand clear took 0 milliseconds Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a" Dec 27 18:02:22 volumio volumio[1167]: error: updateQueue error: null Dec 27 18:02:22 volumio volumio[1167]: info: ------------------------------ 1ms Dec 27 18:02:22 volumio volumio[1167]: info: Dec 27 18:02:22 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:22 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a" took 0 milliseconds Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand play Dec 27 18:02:22 volumio volumio[1167]: info: ------------------------------ 1ms Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand play took 1 milliseconds Dec 27 18:02:22 volumio volumio[1167]: info: Dec 27 18:02:22 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:22 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:22 volumio volumio[1167]: info: Dec 27 18:02:22 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand status took 16 milliseconds Dec 27 18:02:22 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand status took 0 milliseconds Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 27 18:02:22 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:22 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:22 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:22 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:22 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:22 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:22 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 27 18:02:22 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:22 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:22 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:22 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:22 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:22 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:22 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:22 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:22 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:22 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:22 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:22 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:22 volumio volumio[1167]: info: ------------------------------ 22ms Dec 27 18:02:22 volumio volumio[1167]: info: ------------------------------ 7ms Dec 27 18:02:25 volumio volumio[1167]: info: CoreCommandRouter::volumioSeek Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::seek Dec 27 18:02:25 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:25 volumio volumio[1167]: info: TRACKBLOCK {"uri":"mnt/USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","service":"mpd","name":"I can't be with you","artist":"The Cranberries","album":"No need to argue","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=86&web=The%20Cranberries/No%20need%20to%20argue/extralarge&path=%2FUSB%2FMUSIK_1%2FThe%20Cranberris%2FNo%20need%20to%20argue&metadata=false","duration":190,"samplerate":44.1,"bitdepth":"32 bit","trackType":"m4a","channels":2} Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:02:25 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:25 volumio volumio[1167]: info: ControllerMpd::seek Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:25 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:25 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:25 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:25 volumio volumio[1167]: error: null Dec 27 18:02:25 volumio volumio[1167]: info: Dec 27 18:02:25 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:25 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:25 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:25 volumio volumio[1167]: info: sendMpdCommand status took 3 milliseconds Dec 27 18:02:25 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:25 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:25 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:02:25 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:25 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:25 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:25 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:25 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":167000,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:25 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:25 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:25 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:25 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:25 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:25 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:25 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:25 volumio volumio[1167]: info: ------------------------------ 7ms Dec 27 18:02:26 volumio volumio[1167]: info: CoreCommandRouter::volumioSeek Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::seek Dec 27 18:02:26 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:26 volumio volumio[1167]: info: TRACKBLOCK {"uri":"mnt/USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","service":"mpd","name":"I can't be with you","artist":"The Cranberries","album":"No need to argue","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=86&web=The%20Cranberries/No%20need%20to%20argue/extralarge&path=%2FUSB%2FMUSIK_1%2FThe%20Cranberris%2FNo%20need%20to%20argue&metadata=false","duration":190,"samplerate":44.1,"bitdepth":"32 bit","trackType":"m4a","channels":2} Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:02:26 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:26 volumio volumio[1167]: info: ControllerMpd::seek Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:26 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:26 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:26 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:26 volumio volumio[1167]: error: null Dec 27 18:02:26 volumio volumio[1167]: info: Dec 27 18:02:26 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:26 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:26 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:26 volumio volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 27 18:02:26 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:26 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:26 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:02:26 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:26 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:26 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:26 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:26 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":182000,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:26 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:26 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:26 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:26 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:26 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:26 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:26 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:26 volumio volumio[1167]: info: ------------------------------ 6ms Dec 27 18:02:27 volumio volumio[1167]: info: CoreCommandRouter::volumioSeek Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::seek Dec 27 18:02:27 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:27 volumio volumio[1167]: info: TRACKBLOCK {"uri":"mnt/USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","service":"mpd","name":"I can't be with you","artist":"The Cranberries","album":"No need to argue","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=86&web=The%20Cranberries/No%20need%20to%20argue/extralarge&path=%2FUSB%2FMUSIK_1%2FThe%20Cranberris%2FNo%20need%20to%20argue&metadata=false","duration":190,"samplerate":44.1,"bitdepth":"32 bit","trackType":"m4a","channels":2} Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:02:27 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:27 volumio volumio[1167]: info: ControllerMpd::seek Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:27 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:27 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:27 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:27 volumio volumio[1167]: error: null Dec 27 18:02:27 volumio volumio[1167]: info: Dec 27 18:02:27 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:27 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:27 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:27 volumio volumio[1167]: info: sendMpdCommand status took 2 milliseconds Dec 27 18:02:27 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:27 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:27 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:02:27 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:27 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:27 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:27 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:27 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":181000,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:27 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:27 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:27 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:27 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:27 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:27 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:27 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:27 volumio volumio[1167]: info: ------------------------------ 6ms Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::volumioSeek Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::seek Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: TRACKBLOCK {"uri":"mnt/USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","service":"mpd","name":"I can't be with you","artist":"The Cranberries","album":"No need to argue","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=86&web=The%20Cranberries/No%20need%20to%20argue/extralarge&path=%2FUSB%2FMUSIK_1%2FThe%20Cranberris%2FNo%20need%20to%20argue&metadata=false","duration":190,"samplerate":44.1,"bitdepth":"32 bit","trackType":"m4a","channels":2} Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: ControllerMpd::seek Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:28 volumio volumio[1167]: error: null Dec 27 18:02:28 volumio volumio[1167]: info: Dec 27 18:02:28 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:28 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:28 volumio volumio[1167]: info: sendMpdCommand status took 3 milliseconds Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:28 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:28 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":187000,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:28 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:28 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:28 volumio volumio[1167]: info: ------------------------------ 7ms Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:28 volumio volumio[1167]: info: Prefetching next song Dec 27 18:02:28 volumio volumio[1167]: info: DOING PREFETCH IN MPD Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/03 Titel 3.m4a" Dec 27 18:02:28 volumio volumio[1167]: info: sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/03 Titel 3.m4a" took 0 milliseconds Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand consume 1 Dec 27 18:02:28 volumio volumio[1167]: info: Dec 27 18:02:28 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:28 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:28 volumio volumio[1167]: info: Dec 27 18:02:28 volumio volumio[1167]: ---------------------------- MPD announces state update: options Dec 27 18:02:28 volumio volumio[1167]: info: sendMpdCommand consume 1 took 1 milliseconds Dec 27 18:02:28 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:28 volumio volumio[1167]: info: ------------------------------ 0ms Dec 27 18:02:28 volumio volumio[1167]: info: sendMpdCommand status took 0 milliseconds Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:28 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:02:28 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:28 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":187857,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"I can't be with you","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/02 Titel 2.m4a","trackType":"m4a"} Dec 27 18:02:28 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:28 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:28 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:28 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:28 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:28 volumio volumio[1167]: info: ------------------------------ 3ms Dec 27 18:02:30 volumio volumio[1167]: info: Dec 27 18:02:30 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:02:30 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:02:30 volumio volumio[1167]: info: Dec 27 18:02:30 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:02:30 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:02:30 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:02:30 volumio volumio[1167]: info: ------------------------------ 1ms Dec 27 18:02:30 volumio volumio[1167]: info: sendMpdCommand status took 0 milliseconds Dec 27 18:02:30 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:02:30 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:02:30 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:02:30 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:02:30 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:02:30 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:02:30 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:30 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":190,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Twenty one","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/03 Titel 3.m4a","trackType":"m4a"} Dec 27 18:02:30 volumio volumio[1167]: verbose: CURRENT POSITION 1 Dec 27 18:02:30 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:02:30 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:02:30 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:02:30 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:30 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:30 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:30 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:30 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:30 volumio volumio[1167]: info: CorePlayQueue::getTrack 1 Dec 27 18:02:30 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:30 volumio volumio[1167]: info: ------------------------------ 4ms Dec 27 18:02:30 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:02:30 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:31 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:31 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:31 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:31 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:37 volumio volumio[1167]: info: VolumeController::SetAlsaVolume46 Dec 27 18:02:37 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:37 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:37 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:37 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:37 volumio volumio[1167]: info: VolumeController::SetAlsaVolume64 Dec 27 18:02:37 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:37 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:37 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:37 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:38 volumio volumio[1167]: info: VolumeController::SetAlsaVolume100 Dec 27 18:02:38 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:38 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:38 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:38 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:39 volumio volumio[1167]: info: VolumeController::SetAlsaVolume95 Dec 27 18:02:39 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:39 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:39 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:39 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:40 volumio volumio[1167]: info: VolumeController::SetAlsaVolume92 Dec 27 18:02:40 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:40 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:40 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:40 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:40 volumio volumio[1167]: info: VolumeController::SetAlsaVolume89 Dec 27 18:02:40 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:40 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:40 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:40 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:40 volumio volumio[1167]: info: VolumeController::SetAlsaVolume81 Dec 27 18:02:40 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:40 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:40 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:40 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:42 volumio volumio[1167]: info: VolumeController::SetAlsaVolume100 Dec 27 18:02:42 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:42 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:42 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:42 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:46 volumio volumio[1167]: info: VolumeController::SetAlsaVolume77 Dec 27 18:02:46 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:46 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:46 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:46 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:47 volumio volumio[1167]: info: VolumeController::SetAlsaVolume73 Dec 27 18:02:47 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:47 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:47 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:47 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:48 volumio volumio[1167]: info: VolumeController::SetAlsaVolume53 Dec 27 18:02:48 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:48 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:48 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:48 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:02:59 volumio volumio[1167]: info: VolumeController::SetAlsaVolume51 Dec 27 18:02:59 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:02:59 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:02:59 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:02:59 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:00 volumio volumio[1167]: info: VolumeController::SetAlsaVolume47 Dec 27 18:03:00 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:00 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:03:00 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:03:00 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:00 volumio volumio[1167]: info: VolumeController::SetAlsaVolume58 Dec 27 18:03:00 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:00 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:03:00 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:03:00 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPlay Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::play index 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::stop Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::stPlaybackTimer Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::updateTrackBlock Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrackBlock Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::serviceStop Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 2 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::serviceStop Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::stop Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 18:03:06 volumio volumio[1167]: info: Dec 27 18:03:06 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand stop took 7 milliseconds Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::play index undefined Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::startPlaybackTimer Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::clearAddPlayTracks USB/MUSIK_1/The Cranberris/No need to argue/04 Titel 4.m4a Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand status took 1 milliseconds Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand stop took 1 milliseconds Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand clear Dec 27 18:03:06 volumio volumio[1167]: info: Dec 27 18:03:06 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:03:06 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand clear took 1 milliseconds Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/04 Titel 4.m4a" Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: 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":"Twenty one","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/03 Titel 3.m4a","trackType":"m4a"} Dec 27 18:03:06 volumio volumio[1167]: verbose: CURRENT POSITION 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::syncState stateService stop Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: No code Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: ------------------------------ 6ms Dec 27 18:03:06 volumio volumio[1167]: error: updateQueue error: null Dec 27 18:03:06 volumio volumio[1167]: info: Dec 27 18:03:06 volumio volumio[1167]: ---------------------------- MPD announces system playlist update Dec 27 18:03:06 volumio volumio[1167]: info: Ignoring MPD Status Update Dec 27 18:03:06 volumio volumio[1167]: info: ------------------------------ 6ms Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand add "USB/MUSIK_1/The Cranberris/No need to argue/04 Titel 4.m4a" took 6 milliseconds Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand play Dec 27 18:03:06 volumio volumio[1167]: info: ------------------------------ 4ms Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand play took 4 milliseconds Dec 27 18:03:06 volumio volumio[1167]: info: Dec 27 18:03:06 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:03:06 volumio volumio[1167]: info: Dec 27 18:03:06 volumio volumio[1167]: ---------------------------- MPD announces state update: player Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand status took 15 milliseconds Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::getState Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand status Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand status took 0 milliseconds Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::parseState Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":308,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Zombie","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/04 Titel 4.m4a","trackType":"m4a"} Dec 27 18:03:06 volumio volumio[1167]: verbose: CURRENT POSITION 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus stop Dec 27 18:03:06 volumio volumio[1167]: info: ------------------------------ 17ms Dec 27 18:03:06 volumio volumio[1167]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 27 18:03:06 volumio volumio[1167]: verbose: ControllerMpd::parseTrackInfo Dec 27 18:03:06 volumio volumio[1167]: info: ControllerMpd::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::servicePushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":308,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Zombie","artist":"The Cranberries","album":"No need to argue","uri":"USB/MUSIK_1/The Cranberris/No need to argue/04 Titel 4.m4a","trackType":"m4a"} Dec 27 18:03:06 volumio volumio[1167]: verbose: CURRENT POSITION 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::syncState stateService play Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::syncState currentStatus play Dec 27 18:03:06 volumio volumio[1167]: info: Received an update from plugin. extracting info from payload Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: CoreStateMachine::pushState Dec 27 18:03:06 volumio volumio[1167]: info: CorePlayQueue::getTrack 3 Dec 27 18:03:06 volumio volumio[1167]: info: CoreCommandRouter::volumioPushState Dec 27 18:03:06 volumio volumio[1167]: info: ------------------------------ 5ms Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 18:03:13 volumio volumio[1167]: info: Retrieving Cloud Streaming UI Dec 27 18:03:13 volumio volumio[1167]: info: Getting Tidal Cloud Configuration Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 18:03:13 volumio volumio[1167]: info: Getting Qobuz Cloud Configuration Dec 27 18:03:13 volumio volumio[1167]: info: Asking plugin for UI Config Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 18:03:13 volumio volumio[1167]: info: Getting Spotify Cloud Configuration Dec 27 18:03:13 volumio volumio[1167]: info: Asking plugin for UI Config Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 18:03:13 volumio volumio[1167]: info: Saving Spotify Acccount Dec 27 18:03:13 volumio volumio[1167]: info: Got Tidal Cloud Configuration Dec 27 18:03:13 volumio volumio[1167]: info: Got it Dec 27 18:03:13 volumio volumio[1167]: info: Got it Dec 27 18:03:13 volumio volumio[1167]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 18:03:13 volumio volumio[1167]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 27 18:03:13 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 27 18:03:17 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 27 18:03:17 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Dec 27 18:03:17 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Dec 27 18:03:17 volumio volumio[1167]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 18:03:17 volumio volumio[1167]: Error: dns service error: unknown Dec 27 18:03:17 volumio volumio[1167]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Dec 27 18:03:17 volumio volumio[1167]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Dec 27 18:03:17 volumio volumio[1167]: errorCode: -65537 Dec 27 18:03:17 volumio volumio[1167]: } Dec 27 18:03:17 volumio volumio[1167]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 18:03:18 volumio sudo[13751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-27 18:02 Dec 27 18:03:18 volumio sudo[13751]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"