-- Logs begin at Thu 2025-06-05 23:22:06 CST, end at Thu 2025-06-05 23:35:24 CST. -- Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::volumioPause Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::pause Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::stPlaybackTimer Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::servicePause Jun 05 23:34:01 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::servicePause Jun 05 23:34:01 volumio volumio[879]: info: ControllerMpd::pause Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand pause Jun 05 23:34:01 volumio volumio[879]: info: Jun 05 23:34:01 volumio volumio[879]: ---------------------------- MPD announces state update: player Jun 05 23:34:01 volumio volumio[879]: info: sendMpdCommand pause took 2 milliseconds Jun 05 23:34:01 volumio volumio[879]: info: ControllerMpd::getState Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:34:01 volumio volumio[879]: info: Jun 05 23:34:01 volumio volumio[879]: ---------------------------- MPD announces state update: player Jun 05 23:34:01 volumio volumio[879]: info: ControllerMpd::getState Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:34:01 volumio volumio[879]: info: sendMpdCommand status took 3 milliseconds Jun 05 23:34:01 volumio volumio[879]: info: sendMpdCommand status took 2 milliseconds Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 05 23:34:01 volumio volumio[879]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 23:34:01 volumio volumio[879]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::parseTrackInfo Jun 05 23:34:01 volumio volumio[879]: verbose: ControllerMpd::parseTrackInfo Jun 05 23:34:01 volumio volumio[879]: info: ControllerMpd::pushState Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::servicePushState Jun 05 23:34:01 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:01 volumio volumio[879]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5167,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"海来阿木 - 三生三幸.wav","artist":null,"album":null,"uri":"NAS/music/海来阿木《海来阿木》/海来阿木 - 三生三幸.wav","trackType":"wav"} Jun 05 23:34:01 volumio volumio[879]: verbose: CURRENT POSITION 0 Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::syncState stateService pause Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus pause Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:01 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::stPlaybackTimer Jun 05 23:34:01 volumio volumio[879]: info: ControllerMpd::pushState Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::servicePushState Jun 05 23:34:01 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:01 volumio volumio[879]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5167,"duration":276,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"海来阿木 - 三生三幸.wav","artist":null,"album":null,"uri":"NAS/music/海来阿木《海来阿木》/海来阿木 - 三生三幸.wav","trackType":"wav"} Jun 05 23:34:01 volumio volumio[879]: verbose: CURRENT POSITION 0 Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::syncState stateService pause Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus pause Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:01 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:01 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:01 volumio volumio[879]: info: CoreStateMachine::stPlaybackTimer Jun 05 23:34:01 volumio volumio[879]: info: ------------------------------ 33ms Jun 05 23:34:01 volumio volumio[879]: info: ------------------------------ 32ms Jun 05 23:34:04 volumio volumio[879]: info: VolumeController::SetAlsaVolume35 Jun 05 23:34:04 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:04 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:04 volumio volumio[879]: info: VolumeController::SetAlsaVolume45 Jun 05 23:34:04 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:04 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:04 volumio volumio[879]: info: VolumeController::SetAlsaVolume40 Jun 05 23:34:04 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:04 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:04 volumio volumio[879]: info: VolumeController::SetAlsaVolume35 Jun 05 23:34:04 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:04 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:34:04 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetVisibleSources Jun 05 23:34:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 23:34:10 volumio volumio[879]: info: CoreCommandRouter::volumioGetQueue Jun 05 23:34:10 volumio volumio[879]: info: CoreStateMachine::getQueue Jun 05 23:34:10 volumio volumio[879]: info: CorePlayQueue::getQueue Jun 05 23:34:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 05 23:34:20 volumio volumio[879]: info: Received Get System Info Jun 05 23:34:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 05 23:34:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 05 23:34:20 volumio volumio[879]: info: Discovery: Getting this device information Jun 05 23:34:20 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Jun 05 23:34:20 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:20 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 05 23:34:29 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 05 23:34:50 volumio volumio[879]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jun 05 23:34:50 volumio volumio[879]: info: Preparing to save Alsa Options, stopping services first Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::volumioGetState Jun 05 23:34:50 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::volumioPause Jun 05 23:34:50 volumio volumio[879]: info: CoreStateMachine::pause Jun 05 23:34:50 volumio volumio[879]: info: Saving Audio Output to: {"output_device":{"value":"0,3","label":"HDMI"}} Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 23:34:50 volumio volumio[879]: info: Found match in Cards Database: setting mixer for card HDMI Jun 05 23:34:50 volumio volumio[879]: info: Setting mixer IEC958 for card HDMI Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 05 23:34:50 volumio volumio[879]: info: Updating Volume Controller Parameters: Device: 0,3 Name: HDMI Mixer: IEC958 Max Vol: 90 Vol Curve; logarithmic Vol Steps: 1 Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 05 23:34:50 volumio volumio[879]: info: Disabling external Volume Control Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:34:50 volumio volumio[879]: info: Preparing to generate the ALSA configuration file Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 05 23:34:50 volumio volumio[879]: Unable to parse: Jun 05 23:34:50 volumio volumio[879]: Simple mixer control 'IEC958',0 Jun 05 23:34:50 volumio volumio[879]: Capabilities: pswitch pswitch-joined Jun 05 23:34:50 volumio volumio[879]: Playback channels: Mono Jun 05 23:34:50 volumio volumio[879]: Mono: Playback [on] Jun 05 23:34:50 volumio volumio[879]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Jun 05 23:34:50 volumio volumio[879]: info: Asound.conf file written Jun 05 23:34:50 volumio sudo[3926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 05 23:34:50 volumio sudo[3926]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:50 volumio sudo[3926]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:50 volumio volumio[879]: info: Output device has changed, restarting MPD Jun 05 23:34:50 volumio sudo[3932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 05 23:34:50 volumio sudo[3932]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:50 volumio volumio[879]: info: Output device has changed, restarting Shairport Sync Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:34:50 volumio sudo[3932]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:50 volumio sudo[3935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 05 23:34:50 volumio sudo[3935]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:50 volumio systemd[1]: Stopping Music Player Daemon... Jun 05 23:34:50 volumio volumio[879]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 05 23:34:50 volumio volumio[879]: info: Output device has changed, restarting MPD Jun 05 23:34:50 volumio systemd[1]: mpd.service: Succeeded. Jun 05 23:34:50 volumio systemd[1]: Stopped Music Player Daemon. Jun 05 23:34:50 volumio systemd[1]: Starting Music Player Daemon... Jun 05 23:34:50 volumio sudo[3942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 05 23:34:50 volumio sudo[3942]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:50 volumio volumio[879]: info: Output device has changed, restarting Shairport Sync Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:50 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:34:51 volumio sudo[3942]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:51 volumio sudo[3945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 05 23:34:51 volumio sudo[3945]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:51 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 05 23:34:51 volumio systemd[1]: mpd.service: Succeeded. Jun 05 23:34:51 volumio systemd[1]: Stopped Music Player Daemon. Jun 05 23:34:51 volumio volumio[879]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 05 23:34:51 volumio volumio[879]: info: MPD Permissions set Jun 05 23:34:51 volumio volumio[879]: info: MPD Permissions set Jun 05 23:34:51 volumio volumio[879]: Unable to parse: Jun 05 23:34:51 volumio volumio[879]: Simple mixer control 'IEC958',0 Jun 05 23:34:51 volumio volumio[879]: Capabilities: pswitch pswitch-joined Jun 05 23:34:51 volumio volumio[879]: Playback channels: Mono Jun 05 23:34:51 volumio volumio[879]: Mono: Playback [on] Jun 05 23:34:51 volumio volumio[879]: info: VolumeController:: Volume=undefined Mute =false Jun 05 23:34:51 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:51 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:51 volumio systemd[1]: Starting Music Player Daemon... Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio sudo[3950]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 05 23:34:51 volumio sudo[3950]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:51 volumio sudo[3950]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 05 23:34:51 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 23:34:51 volumio volumio[879]: info: Starting Shairport Sync Jun 05 23:34:51 volumio volumio[879]: info: Starting Shairport Sync Jun 05 23:34:51 volumio sudo[3966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 05 23:34:51 volumio sudo[3966]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:51 volumio sudo[3968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 05 23:34:51 volumio sudo[3968]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:34:51 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 05 23:34:51 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 05 23:34:51 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 05 23:34:51 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 05 23:34:51 volumio sudo[3968]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:51 volumio sudo[3966]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:51 volumio volumio[879]: info: Shairport-Sync Started Jun 05 23:34:51 volumio volumio[879]: info: Shairport-Sync Started Jun 05 23:34:52 volumio mpd[3959]: Jun 05 23:34 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 05 23:34:52 volumio systemd[1]: Started Music Player Daemon. Jun 05 23:34:52 volumio sudo[3945]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:52 volumio sudo[3935]: pam_unix(sudo:session): session closed for user root Jun 05 23:34:52 volumio volumio[879]: error: MPD error: The expression evaluated to a falsy value: Jun 05 23:34:52 volumio volumio[879]: assert.ok(self.idling) Jun 05 23:34:52 volumio volumio[879]: error: The expression evaluated to a falsy value: Jun 05 23:34:52 volumio volumio[879]: assert.ok(self.idling) Jun 05 23:34:52 volumio volumio[879]: error: updateQueue error: null Jun 05 23:34:54 volumio volumio[879]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jun 05 23:34:54 volumio volumio[879]: info: CoreStateMachine::getcurrentVolume Jun 05 23:34:54 volumio volumio[879]: info: CoreCommandRouter::volumioRetrievevolume Jun 05 23:34:54 volumio volumio[879]: Unable to parse: Jun 05 23:34:54 volumio volumio[879]: Simple mixer control 'IEC958',0 Jun 05 23:34:54 volumio volumio[879]: Capabilities: pswitch pswitch-joined Jun 05 23:34:54 volumio volumio[879]: Playback channels: Mono Jun 05 23:34:54 volumio volumio[879]: Mono: Playback [on] Jun 05 23:34:54 volumio volumio[879]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Jun 05 23:34:54 volumio volumio[879]: Unable to parse: Jun 05 23:34:54 volumio volumio[879]: Simple mixer control 'IEC958',0 Jun 05 23:34:54 volumio volumio[879]: Capabilities: pswitch pswitch-joined Jun 05 23:34:54 volumio volumio[879]: Playback channels: Mono Jun 05 23:34:54 volumio volumio[879]: Mono: Playback [on] Jun 05 23:34:54 volumio volumio[879]: info: VolumeController:: Volume=undefined Mute =false Jun 05 23:34:54 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:54 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:54 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:54 volumio volumio[879]: info: CoreStateMachine::updateTrackBlock Jun 05 23:34:54 volumio volumio[879]: info: CorePlayQueue::getTrackBlock Jun 05 23:34:54 volumio volumio[879]: info: CoreCommandRouter::volumioRetrievevolume Jun 05 23:34:54 volumio volumio[879]: Unable to parse: Jun 05 23:34:54 volumio volumio[879]: Simple mixer control 'IEC958',0 Jun 05 23:34:54 volumio volumio[879]: Capabilities: pswitch pswitch-joined Jun 05 23:34:54 volumio volumio[879]: Playback channels: Mono Jun 05 23:34:54 volumio volumio[879]: Mono: Playback [on] Jun 05 23:34:54 volumio volumio[879]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output Jun 05 23:34:54 volumio volumio[879]: Unable to parse: Jun 05 23:34:54 volumio volumio[879]: Simple mixer control 'IEC958',0 Jun 05 23:34:54 volumio volumio[879]: Capabilities: pswitch pswitch-joined Jun 05 23:34:54 volumio volumio[879]: Playback channels: Mono Jun 05 23:34:54 volumio volumio[879]: Mono: Playback [on] Jun 05 23:34:54 volumio volumio[879]: info: VolumeController:: Volume=undefined Mute =false Jun 05 23:34:54 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:34:54 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:34:54 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:34:59 volumio ntpd[1073]: 211.68.71.26 local addr 192.168.2.212 -> Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 05 23:35:04 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:07 volumio volumio[879]: info: Retrieving Cloud Streaming UI Jun 05 23:35:07 volumio volumio[879]: info: Getting Tidal Cloud Configuration Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:07 volumio volumio[879]: info: Getting Qobuz Cloud Configuration Jun 05 23:35:07 volumio volumio[879]: info: Asking plugin for UI Config Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:07 volumio volumio[879]: info: Getting Spotify Cloud Configuration Jun 05 23:35:07 volumio volumio[879]: info: Asking plugin for UI Config Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:07 volumio volumio[879]: info: Saving Spotify Acccount Jun 05 23:35:07 volumio volumio[879]: info: Got Tidal Cloud Configuration Jun 05 23:35:07 volumio volumio[879]: info: Got it Jun 05 23:35:07 volumio volumio[879]: info: Got it Jun 05 23:35:07 volumio volumio[879]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 05 23:35:07 volumio volumio[879]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::volumioGetBrowseSources Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::volumioGetBrowseSources Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::volumioGetBrowseSources Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 23:35:07 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand update Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:10 volumio volumio[879]: info: Jun 05 23:35:10 volumio volumio[879]: ---------------------------- MPD announces state update: update Jun 05 23:35:10 volumio volumio[879]: info: sendMpdCommand update took 5 milliseconds Jun 05 23:35:10 volumio volumio[879]: info: ControllerMpd::getState Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:10 volumio volumio[879]: info: sendMpdCommand status took 4 milliseconds Jun 05 23:35:10 volumio volumio[879]: info: sendMpdCommand status took 2 milliseconds Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:10 volumio volumio[879]: info: Command Router : Notfying DB Updatetrue Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::Close All Modals sent Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:10 volumio volumio[879]: info: ControllerMpd::pushState Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:10 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:10 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:10 volumio volumio[879]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 05 23:35:10 volumio volumio[879]: verbose: CURRENT POSITION 0 Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::syncState stateService stop Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus pause Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:10 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:10 volumio volumio[879]: info: ------------------------------ 315ms Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:10 volumio volumio[879]: info: Jun 05 23:35:10 volumio volumio[879]: ---------------------------- MPD announces state update: update Jun 05 23:35:10 volumio volumio[879]: info: ControllerMpd::getState Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:10 volumio volumio[879]: info: sendMpdCommand status took 6 milliseconds Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:10 volumio volumio[879]: info: Command Router : Notfying DB Updatetrue Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::Close All Modals sent Jun 05 23:35:10 volumio volumio[879]: info: sendMpdCommand status took 163 milliseconds Jun 05 23:35:10 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:10 volumio volumio[879]: info: ControllerMpd::pushState Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::servicePushState Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:10 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:10 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:10 volumio volumio[879]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 05 23:35:10 volumio volumio[879]: verbose: CURRENT POSITION 0 Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::syncState stateService stop Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus pause Jun 05 23:35:10 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:10 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:10 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:10 volumio volumio[879]: info: ------------------------------ 182ms Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:11 volumio volumio[879]: info: Jun 05 23:35:11 volumio volumio[879]: ---------------------------- MPD announces state update: update Jun 05 23:35:11 volumio volumio[879]: info: ControllerMpd::getState Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:11 volumio volumio[879]: info: Jun 05 23:35:11 volumio volumio[879]: ---------------------------- MPD announces state update: update Jun 05 23:35:11 volumio volumio[879]: info: ControllerMpd::getState Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::sendMpdCommand status Jun 05 23:35:11 volumio volumio[879]: info: sendMpdCommand status took 7 milliseconds Jun 05 23:35:11 volumio volumio[879]: info: sendMpdCommand status took 5 milliseconds Jun 05 23:35:11 volumio volumio[879]: info: sendMpdCommand status took 5 milliseconds Jun 05 23:35:11 volumio volumio[879]: info: sendMpdCommand status took 3 milliseconds Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:11 volumio volumio[879]: info: Command Router : Notfying DB Updatefalse Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::Close All Modals sent Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:11 volumio volumio[879]: info: Command Router : Notfying DB Updatefalse Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::Close All Modals sent Jun 05 23:35:11 volumio volumio[879]: verbose: ControllerMpd::parseState Jun 05 23:35:11 volumio volumio[879]: info: ControllerMpd::pushState Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::servicePushState Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:11 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:11 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:11 volumio volumio[879]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 05 23:35:11 volumio volumio[879]: verbose: CURRENT POSITION 0 Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::syncState stateService stop Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus pause Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:11 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:11 volumio volumio[879]: info: ControllerMpd::pushState Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::servicePushState Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:11 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:11 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:11 volumio volumio[879]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 05 23:35:11 volumio volumio[879]: verbose: CURRENT POSITION 0 Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::syncState stateService stop Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::syncState currentStatus pause Jun 05 23:35:11 volumio volumio[879]: info: CoreStateMachine::pushState Jun 05 23:35:11 volumio volumio[879]: info: CorePlayQueue::getTrack 0 Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::volumioPushState Jun 05 23:35:11 volumio volumio[879]: info: ------------------------------ 197ms Jun 05 23:35:11 volumio volumio[879]: info: ------------------------------ 195ms Jun 05 23:35:11 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 23:35:15 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 23:35:19 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 05 23:35:22 volumio volumio[879]: info: Disabling MyMusic plugin upnp Jun 05 23:35:22 volumio sudo[4091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jun 05 23:35:22 volumio sudo[4091]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 23:35:22 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Jun 05 23:35:22 volumio volumio[879]: error: Upnp client error: Error: This socket has been ended by the other party Jun 05 23:35:23 volumio volumio[879]: info: Enabling MyMusic plugin upnp Jun 05 23:35:23 volumio volumio[879]: info: Enabling plugin upnp Jun 05 23:35:23 volumio volumio[879]: info: Loading plugin "upnp"... Jun 05 23:35:23 volumio volumio[879]: info: [1749137723859] Starting Upmpd Daemon Jun 05 23:35:23 volumio volumio[879]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 05 23:35:23 volumio volumio[879]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 23:35:23 volumio volumio[879]: Error: listen EADDRINUSE: address already in use :::6599 Jun 05 23:35:23 volumio volumio[879]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jun 05 23:35:23 volumio volumio[879]: at listenInCluster (net.js:1379:12) Jun 05 23:35:23 volumio volumio[879]: at Server.listen (net.js:1465:7) Jun 05 23:35:23 volumio volumio[879]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jun 05 23:35:23 volumio volumio[879]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jun 05 23:35:23 volumio volumio[879]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jun 05 23:35:23 volumio volumio[879]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 05 23:35:23 volumio volumio[879]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jun 05 23:35:23 volumio volumio[879]: code: 'EADDRINUSE', Jun 05 23:35:23 volumio volumio[879]: errno: -98, Jun 05 23:35:23 volumio volumio[879]: syscall: 'listen', Jun 05 23:35:23 volumio volumio[879]: address: '::', Jun 05 23:35:23 volumio volumio[879]: port: 6599 Jun 05 23:35:23 volumio volumio[879]: } Jun 05 23:35:23 volumio volumio[879]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 23:35:24 volumio sudo[4106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-05 23:34 Jun 05 23:35:24 volumio sudo[4106]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"