-- Logs begin at Thu 2019-02-14 18:12:00 CST, end at Sun 2025-04-27 22:22:57 CST. -- Apr 27 22:21:01 v1 volumio[2591]: info: VolumeController::SetAlsaVolume91 Apr 27 22:21:01 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:01 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:01 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:01 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:01 v1 volumio[2591]: info: VolumeController::SetAlsaVolume100 Apr 27 22:21:01 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:01 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:01 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:01 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:21 v1 volumio[2591]: info: Apr 27 22:21:21 v1 volumio[2591]: ---------------------------- MPD announces state update: player Apr 27 22:21:21 v1 volumio[2591]: info: ControllerMpd::getState Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand status Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 27 22:21:21 v1 volumio[2591]: info: sendMpdCommand status took 13 milliseconds Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::parseState Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 22:21:21 v1 volumio[2591]: info: Apr 27 22:21:21 v1 volumio[2591]: ---------------------------- MPD announces state update: player Apr 27 22:21:21 v1 volumio[2591]: info: ControllerMpd::getState Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand status Apr 27 22:21:21 v1 volumio[2591]: info: sendMpdCommand clearerror took 15 milliseconds Apr 27 22:21:21 v1 volumio[2591]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 27 22:21:21 v1 volumio[2591]: info: sendMpdCommand status took 6 milliseconds Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::parseTrackInfo Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::parseState Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 22:21:21 v1 volumio[2591]: info: ControllerMpd::pushState Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::servicePushState Apr 27 22:21:21 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:21 v1 volumio[2591]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":47462,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"迟到","artist":"群星","album":"极致环绕 人声天碟 天品2号","uri":"NAS/BaiduYunDownload/01迟到.mp3","trackType":"mp3"} Apr 27 22:21:21 v1 volumio[2591]: verbose: CURRENT POSITION 0 Apr 27 22:21:21 v1 volumio[2591]: info: CoreStateMachine::syncState stateService pause Apr 27 22:21:21 v1 volumio[2591]: info: CoreStateMachine::syncState currentStatus play Apr 27 22:21:21 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:21 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:21 v1 volumio[2591]: info: ------------------------------ 55ms Apr 27 22:21:21 v1 volumio[2591]: info: sendMpdCommand playlistinfo took 24 milliseconds Apr 27 22:21:21 v1 volumio[2591]: verbose: ControllerMpd::parseTrackInfo Apr 27 22:21:21 v1 volumio[2591]: info: ControllerMpd::pushState Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::servicePushState Apr 27 22:21:21 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:21 v1 volumio[2591]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":47462,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"迟到","artist":"群星","album":"极致环绕 人声天碟 天品2号","uri":"NAS/BaiduYunDownload/01迟到.mp3","trackType":"mp3"} Apr 27 22:21:21 v1 volumio[2591]: verbose: CURRENT POSITION 0 Apr 27 22:21:21 v1 volumio[2591]: info: CoreStateMachine::syncState stateService pause Apr 27 22:21:21 v1 volumio[2591]: info: CoreStateMachine::syncState currentStatus play Apr 27 22:21:21 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:21 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:21 v1 volumio[2591]: info: ------------------------------ 54ms Apr 27 22:21:21 v1 volumio[2591]: info: Apr 27 22:21:21 v1 volumio[2591]: ---------------------------- USB Audio Device Detached Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Apr 27 22:21:21 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:21:22 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Apr 27 22:21:22 v1 volumio[2591]: info: No valid Plugin REST Endpoint Apr 27 22:21:22 v1 kernel: usb 1-1.2: USB disconnect, device number 5 Apr 27 22:21:36 v1 kernel: usb 1-1.3: new full-speed USB device number 6 using dwc_otg Apr 27 22:21:36 v1 kernel: usb 1-1.3: New USB device found, idVendor=0c76, idProduct=201f, bcdDevice= 1.00 Apr 27 22:21:36 v1 kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 27 22:21:36 v1 kernel: usb 1-1.3: Product: USB TO SPDIF OUT Apr 27 22:21:36 v1 kernel: usb 1-1.3: Manufacturer: Solid State System Co.,Ltd. Apr 27 22:21:36 v1 kernel: usb 1-1.3: SerialNumber: 000000000000 Apr 27 22:21:36 v1 kernel: usb 1-1.3: Warning! Unlikely big volume range (=496), cval->res is probably wrong. Apr 27 22:21:36 v1 kernel: usb 1-1.3: [51] FU [Mic Playback Volume] ch = 1, val = 0/7936/16 Apr 27 22:21:36 v1 kernel: usb 1-1.3: Warning! Unlikely big volume range (=1008), cval->res is probably wrong. Apr 27 22:21:36 v1 kernel: usb 1-1.3: [49] FU [Speaker Playback Volume] ch = 2, val = -16129/-1/16 Apr 27 22:21:36 v1 kernel: usb 1-1.3: Warning! Unlikely big volume range (=496), cval->res is probably wrong. Apr 27 22:21:36 v1 kernel: usb 1-1.3: [50] FU [Mic Capture Volume] ch = 1, val = 0/7936/16 Apr 27 22:21:36 v1 kernel: input: Solid State System Co.,Ltd. USB TO SPDIF OUT as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.3/0003:0C76:201F.0003/input/input2 Apr 27 22:21:36 v1 kernel: hid-generic 0003:0C76:201F.0003: input,hidraw0: USB HID v1.00 Device [Solid State System Co.,Ltd. USB TO SPDIF OUT] on usb-3f980000.usb-1.3/input3 Apr 27 22:21:36 v1 volumio[2591]: info: Apr 27 22:21:36 v1 volumio[2591]: ---------------------------- USB Audio Device Attached Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::Close All Modals sent Apr 27 22:21:36 v1 volumio[2591]: info: Preparing to save Alsa Options, stopping services first Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:21:36 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::volumioPause Apr 27 22:21:36 v1 volumio[2591]: info: CoreStateMachine::pause Apr 27 22:21:36 v1 volumio[2591]: info: CoreStateMachine::stPlaybackTimer Apr 27 22:21:36 v1 volumio[2591]: info: CoreStateMachine::servicePause Apr 27 22:21:36 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::servicePause Apr 27 22:21:36 v1 volumio[2591]: info: ControllerMpd::pause Apr 27 22:21:36 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand pause Apr 27 22:21:36 v1 volumio[2591]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"USB TO SPDIF OUT","alsacard":"OUT"},"i2s":false} Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:21:36 v1 systemd-udevd[14601]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:21:36 v1 volumio[2591]: info: Setting mixer Speaker for card USB TO SPDIF OUT Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 27 22:21:36 v1 volumio[2591]: info: Updating Volume Controller Parameters: Device: 5 Name: USB TO SPDIF OUT Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 27 22:21:36 v1 volumio[2591]: info: Disabling external Volume Control Apr 27 22:21:36 v1 volumio[2591]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 27 22:21:36 v1 volumio[2591]: info: Preparing to generate the ALSA configuration file Apr 27 22:21:37 v1 volumio[2591]: info: Apr 27 22:21:37 v1 volumio[2591]: ---------------------------- MPD announces state update: player Apr 27 22:21:37 v1 volumio[2591]: info: sendMpdCommand pause took 493 milliseconds Apr 27 22:21:37 v1 volumio[2591]: info: ControllerMpd::getState Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand status Apr 27 22:21:37 v1 volumio[2591]: info: Apr 27 22:21:37 v1 volumio[2591]: ---------------------------- MPD announces state update: player Apr 27 22:21:37 v1 volumio[2591]: info: ControllerMpd::getState Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand status Apr 27 22:21:37 v1 volumio[2591]: info: sendMpdCommand status took 45 milliseconds Apr 27 22:21:37 v1 volumio[2591]: info: sendMpdCommand status took 42 milliseconds Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::parseState Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::parseState Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 27 22:21:37 v1 volumio[2591]: info: No valid Plugin REST Endpoint Apr 27 22:21:37 v1 volumio[2591]: info: sendMpdCommand playlistinfo took 23 milliseconds Apr 27 22:21:37 v1 volumio[2591]: info: sendMpdCommand playlistinfo took 23 milliseconds Apr 27 22:21:37 v1 volumio[2591]: verbose: ControllerMpd::parseTrackInfo Apr 27 22:21:37 v1 volumio[2591]: info: ControllerMpd::pushState Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::servicePushState Apr 27 22:21:37 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:37 v1 volumio[2591]: verbose: STATE SERVICE {"status":"play","position":0,"seek":48468,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"迟到","artist":"群星","album":"极致环绕 人声天碟 天品2号","uri":"NAS/BaiduYunDownload/01迟到.mp3","trackType":"mp3"} Apr 27 22:21:37 v1 volumio[2591]: verbose: CURRENT POSITION 0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::syncState stateService play Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::syncState currentStatus pause Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:37 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:37 v1 volumio[2591]: info: ControllerMpd::pushState Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::servicePushState Apr 27 22:21:37 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:37 v1 volumio[2591]: verbose: STATE SERVICE {"status":"play","position":0,"seek":48468,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"迟到","artist":"群星","album":"极致环绕 人声天碟 天品2号","uri":"NAS/BaiduYunDownload/01迟到.mp3","trackType":"mp3"} Apr 27 22:21:37 v1 volumio[2591]: verbose: CURRENT POSITION 0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::syncState stateService play Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::syncState currentStatus play Apr 27 22:21:37 v1 volumio[2591]: info: Received an update from plugin. extracting info from payload Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:37 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:37 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:37 v1 volumio[2591]: info: ------------------------------ 136ms Apr 27 22:21:37 v1 volumio[2591]: info: ------------------------------ 132ms Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 27 22:21:37 v1 volumio[2591]: info: VolumeController:: Volume=41 Mute =false Apr 27 22:21:37 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:37 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:37 v1 volumio[2591]: info: Asound.conf file unchanged, so no further update is needed Apr 27 22:21:37 v1 volumio[2591]: info: Output device has changed, restarting MPD Apr 27 22:21:37 v1 volumio[2591]: info: Output device has changed, restarting Shairport Sync Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:21:37 v1 sudo[14627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 27 22:21:37 v1 sudo[14627]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:21:37 v1 sudo[14627]: pam_unix(sudo:session): session closed for user root Apr 27 22:21:37 v1 sudo[14629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 27 22:21:37 v1 sudo[14629]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:21:37 v1 systemd[1]: Stopping Music Player Daemon... Apr 27 22:21:37 v1 volumio[2591]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Apr 27 22:21:37 v1 volumio[2591]: info: MPD Permissions set Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 systemd[1]: mpd.service: Succeeded. Apr 27 22:21:37 v1 systemd[1]: Stopped Music Player Daemon. Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:21:37 v1 volumio[2591]: info: Starting Shairport Sync Apr 27 22:21:37 v1 systemd[1]: Starting Music Player Daemon... Apr 27 22:21:37 v1 sudo[14641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 27 22:21:37 v1 sudo[14641]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:21:37 v1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 27 22:21:37 v1 systemd[1]: shairport-sync.service: Succeeded. Apr 27 22:21:37 v1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 27 22:21:37 v1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 27 22:21:37 v1 sudo[14641]: pam_unix(sudo:session): session closed for user root Apr 27 22:21:37 v1 volumio[2591]: info: Shairport-Sync Started Apr 27 22:21:37 v1 sudo[14639]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 27 22:21:37 v1 sudo[14639]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:21:37 v1 sudo[14639]: pam_unix(sudo:session): session closed for user root Apr 27 22:21:40 v1 mpd[14648]: Apr 27 22:21 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 27 22:21:40 v1 systemd[1]: Started Music Player Daemon. Apr 27 22:21:40 v1 sudo[14629]: pam_unix(sudo:session): session closed for user root Apr 27 22:21:40 v1 volumio[2591]: error: updateQueue error: null Apr 27 22:21:40 v1 volumio[2591]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 27 22:21:40 v1 volumio[2591]: info: CoreStateMachine::getcurrentVolume Apr 27 22:21:40 v1 volumio[2591]: info: CoreCommandRouter::volumioRetrievevolume Apr 27 22:21:41 v1 volumio[2591]: info: VolumeController:: Volume=41 Mute =false Apr 27 22:21:41 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:41 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:41 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:41 v1 volumio[2591]: info: CoreStateMachine::updateTrackBlock Apr 27 22:21:41 v1 volumio[2591]: info: CorePlayQueue::getTrackBlock Apr 27 22:21:41 v1 volumio[2591]: info: CoreCommandRouter::volumioRetrievevolume Apr 27 22:21:41 v1 volumio[2591]: info: VolumeController:: Volume=41 Mute =false Apr 27 22:21:41 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:41 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:41 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:43 v1 volumio[2591]: info: VolumeController::SetAlsaVolume65 Apr 27 22:21:43 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:21:43 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:43 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:21:43 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:21:46 v1 volumio[2591]: info: CoreCommandRouter::volumioPause Apr 27 22:21:46 v1 volumio[2591]: info: CoreStateMachine::pause Apr 27 22:21:46 v1 volumio[2591]: info: CoreStateMachine::stPlaybackTimer Apr 27 22:21:46 v1 volumio[2591]: info: CoreStateMachine::servicePause Apr 27 22:21:46 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:21:46 v1 volumio[2591]: info: CoreCommandRouter::servicePause Apr 27 22:21:46 v1 volumio[2591]: info: ControllerMpd::pause Apr 27 22:21:46 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand pause Apr 27 22:21:46 v1 volumio[2591]: info: sendMpdCommand pause took 2 milliseconds Apr 27 22:21:46 v1 volumio[2591]: info: CoreCommandRouter::volumioPause Apr 27 22:21:46 v1 volumio[2591]: info: CoreStateMachine::pause Apr 27 22:21:50 v1 volumio[2591]: info: CoreCommandRouter::volumioPause Apr 27 22:21:50 v1 volumio[2591]: info: CoreStateMachine::pause Apr 27 22:21:52 v1 volumio[2591]: info: CoreCommandRouter::volumioPause Apr 27 22:21:52 v1 volumio[2591]: info: CoreStateMachine::pause Apr 27 22:21:57 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 27 22:21:57 v1 volumio[2591]: info: CURURI: albums:// Apr 27 22:21:57 v1 volumio[2591]: info: listAlbums - loading Albums from cache Apr 27 22:21:57 v1 volumio[2591]: info: Preload queue cleared Apr 27 22:22:03 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:03 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:03 v1 volumio[2591]: info: CoreCommandRouter::volumioPlay Apr 27 22:22:03 v1 volumio[2591]: info: CoreStateMachine::play index undefined Apr 27 22:22:03 v1 volumio[2591]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 22:22:03 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:03 v1 volumio[2591]: info: CoreStateMachine::startPlaybackTimer Apr 27 22:22:03 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:03 v1 volumio[2591]: info: ControllerMpd::resume Apr 27 22:22:03 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand play Apr 27 22:22:03 v1 volumio[2591]: info: sendMpdCommand play took 1 milliseconds Apr 27 22:22:04 v1 volumio[2591]: info: CoreCommandRouter::volumioPlay Apr 27 22:22:04 v1 volumio[2591]: info: CoreStateMachine::play index undefined Apr 27 22:22:04 v1 volumio[2591]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 22:22:04 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:04 v1 volumio[2591]: info: CoreStateMachine::startPlaybackTimer Apr 27 22:22:04 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:04 v1 volumio[2591]: info: ControllerMpd::resume Apr 27 22:22:04 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand play Apr 27 22:22:04 v1 volumio[2591]: info: sendMpdCommand play took 2 milliseconds Apr 27 22:22:08 v1 volumio[2591]: verbose: New Socket.io Connection to 192.168.2.12 from 192.168.2.29 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Edg/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:08 v1 volumio[2591]: info: Received Get System Info Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 27 22:22:08 v1 volumio[2591]: info: Discovery: Getting this device information Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetVisibleSources Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetQueue Apr 27 22:22:08 v1 volumio[2591]: info: CoreStateMachine::getQueue Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getQueue Apr 27 22:22:08 v1 volumio[2591]: info: Listing playlists Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 27 22:22:08 v1 volumio[2591]: info: Received Get System Info Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 27 22:22:08 v1 volumio[2591]: info: Discovery: Getting this device information Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 27 22:22:08 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:08 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:09 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 27 22:22:10 v1 volumio[2591]: verbose: New Socket.io Connection to 192.168.2.12 from 192.168.2.29 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Edg/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:10 v1 volumio[2591]: info: Received Get System Info Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 27 22:22:10 v1 volumio[2591]: info: Discovery: Getting this device information Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetVisibleSources Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetQueue Apr 27 22:22:10 v1 volumio[2591]: info: CoreStateMachine::getQueue Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getQueue Apr 27 22:22:10 v1 volumio[2591]: info: Listing playlists Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 27 22:22:10 v1 volumio[2591]: info: Received Get System Info Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 27 22:22:10 v1 volumio[2591]: info: Discovery: Getting this device information Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 27 22:22:10 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:10 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:11 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 27 22:22:14 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 27 22:22:17 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 27 22:22:18 v1 volumio[2591]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 27 22:22:18 v1 volumio[2591]: info: Preparing to save Alsa Options, stopping services first Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:18 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::volumioPause Apr 27 22:22:18 v1 volumio[2591]: info: CoreStateMachine::pause Apr 27 22:22:18 v1 volumio[2591]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"USB TO SPDIF OUT"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:22:18 v1 volumio[2591]: info: Setting mixer Speaker for card USB TO SPDIF OUT Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 27 22:22:18 v1 volumio[2591]: info: Updating Volume Controller Parameters: Device: 5 Name: USB TO SPDIF OUT Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 27 22:22:18 v1 volumio[2591]: info: Disabling external Volume Control Apr 27 22:22:18 v1 volumio[2591]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 27 22:22:18 v1 volumio[2591]: info: Preparing to generate the ALSA configuration file Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 27 22:22:19 v1 volumio[2591]: info: Asound.conf file unchanged, so no further update is needed Apr 27 22:22:19 v1 volumio[2591]: info: Output device has changed, restarting MPD Apr 27 22:22:19 v1 volumio[2591]: info: Output device has changed, restarting Shairport Sync Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:19 v1 sudo[14778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 27 22:22:19 v1 sudo[14778]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:19 v1 sudo[14778]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:19 v1 sudo[14780]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 27 22:22:19 v1 sudo[14780]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:19 v1 systemd[1]: Stopping Music Player Daemon... Apr 27 22:22:19 v1 volumio[2591]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 27 22:22:19 v1 systemd[1]: mpd.service: Succeeded. Apr 27 22:22:19 v1 systemd[1]: Stopped Music Player Daemon. Apr 27 22:22:19 v1 volumio[2591]: info: MPD Permissions set Apr 27 22:22:19 v1 volumio[2591]: info: VolumeController:: Volume=65 Mute =false Apr 27 22:22:19 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:22:19 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:19 v1 systemd[1]: Starting Music Player Daemon... Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:19 v1 volumio[2591]: info: Starting Shairport Sync Apr 27 22:22:19 v1 sudo[14792]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 27 22:22:19 v1 sudo[14792]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:19 v1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 27 22:22:19 v1 systemd[1]: shairport-sync.service: Succeeded. Apr 27 22:22:19 v1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 27 22:22:19 v1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 27 22:22:19 v1 sudo[14792]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:19 v1 volumio[2591]: info: Shairport-Sync Started Apr 27 22:22:19 v1 sudo[14786]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 27 22:22:19 v1 sudo[14786]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:19 v1 sudo[14786]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:20 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 27 22:22:22 v1 mpd[14796]: Apr 27 22:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 27 22:22:22 v1 systemd[1]: Started Music Player Daemon. Apr 27 22:22:22 v1 sudo[14780]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:22 v1 volumio[2591]: error: updateQueue error: null Apr 27 22:22:22 v1 volumio[2591]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 27 22:22:22 v1 volumio[2591]: info: CoreStateMachine::getcurrentVolume Apr 27 22:22:22 v1 volumio[2591]: info: CoreCommandRouter::volumioRetrievevolume Apr 27 22:22:23 v1 volumio[2591]: info: VolumeController:: Volume=65 Mute =false Apr 27 22:22:23 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:22:23 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:22:23 v1 volumio[2591]: info: CoreStateMachine::updateTrackBlock Apr 27 22:22:23 v1 volumio[2591]: info: CorePlayQueue::getTrackBlock Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::volumioRetrievevolume Apr 27 22:22:23 v1 volumio[2591]: info: VolumeController:: Volume=65 Mute =false Apr 27 22:22:23 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:22:23 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:22:23 v1 volumio[2591]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 sudo[14820]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 sudo[14820]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:23 v1 sudo[14820]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:23 v1 sudo[14822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 27 22:22:23 v1 sudo[14822]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:23 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:23 v1 volumio[2591]: info: MPD Permissions set Apr 27 22:22:24 v1 systemd[1]: Stopping Music Player Daemon... Apr 27 22:22:24 v1 systemd[1]: mpd.service: Succeeded. Apr 27 22:22:24 v1 systemd[1]: Stopped Music Player Daemon. Apr 27 22:22:24 v1 systemd[1]: Starting Music Player Daemon... Apr 27 22:22:24 v1 sudo[14829]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 27 22:22:24 v1 sudo[14829]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:24 v1 sudo[14829]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:26 v1 mpd[14831]: Apr 27 22:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 27 22:22:26 v1 systemd[1]: Started Music Player Daemon. Apr 27 22:22:26 v1 sudo[14822]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:26 v1 volumio[2591]: error: updateQueue error: null Apr 27 22:22:36 v1 volumio[2591]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:36 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:36 v1 volumio[2591]: info: Restoring Previous Volume level: 100 false false Apr 27 22:22:36 v1 volumio[2591]: info: Output device has changed, restarting MPD Apr 27 22:22:36 v1 volumio[2591]: info: Output device has changed, restarting Shairport Sync Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:36 v1 sudo[14853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 27 22:22:36 v1 sudo[14853]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:36 v1 sudo[14853]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:36 v1 sudo[14855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 27 22:22:36 v1 sudo[14855]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:36 v1 systemd[1]: Stopping Music Player Daemon... Apr 27 22:22:36 v1 volumio[2591]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 27 22:22:36 v1 volumio[2591]: info: Volume configurations have been set Apr 27 22:22:36 v1 systemd[1]: mpd.service: Succeeded. Apr 27 22:22:36 v1 systemd[1]: Stopped Music Player Daemon. Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 27 22:22:36 v1 volumio[2591]: info: Updating Volume Controller Parameters: Device: 5 Name: USB TO SPDIF OUT Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 27 22:22:36 v1 systemd[1]: Starting Music Player Daemon... Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 27 22:22:36 v1 volumio[2591]: info: Disabling external Volume Control Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 27 22:22:36 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:22:36 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:22:36 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:22:37 v1 volumio[2591]: info: MPD Permissions set Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 27 22:22:37 v1 sudo[14863]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 27 22:22:37 v1 sudo[14863]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:37 v1 sudo[14863]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:37 v1 volumio[2591]: info: Starting Shairport Sync Apr 27 22:22:37 v1 sudo[14876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 27 22:22:37 v1 sudo[14876]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:37 v1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 27 22:22:37 v1 systemd[1]: shairport-sync.service: Succeeded. Apr 27 22:22:37 v1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 27 22:22:37 v1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 27 22:22:37 v1 sudo[14876]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:37 v1 volumio[2591]: info: Shairport-Sync Started Apr 27 22:22:39 v1 mpd[14870]: Apr 27 22:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 27 22:22:39 v1 systemd[1]: Started Music Player Daemon. Apr 27 22:22:39 v1 sudo[14855]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:39 v1 volumio[2591]: error: updateQueue error: null Apr 27 22:22:41 v1 volumio[2591]: info: VolumeController::SetAlsaVolume100 Apr 27 22:22:41 v1 volumio[2591]: info: CoreStateMachine::pushState Apr 27 22:22:41 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:41 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 27 22:22:41 v1 volumio[2591]: info: CoreCommandRouter::volumioPushState Apr 27 22:22:44 v1 volumio[2591]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Apr 27 22:22:44 v1 sudo[14937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 27 22:22:44 v1 sudo[14937]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:44 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:44 v1 sudo[14937]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:44 v1 sudo[14939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 27 22:22:44 v1 sudo[14939]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:45 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 27 22:22:45 v1 volumio[2591]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 27 22:22:45 v1 volumio[2591]: info: MPD Permissions set Apr 27 22:22:45 v1 systemd[1]: Stopping Music Player Daemon... Apr 27 22:22:45 v1 systemd[1]: mpd.service: Succeeded. Apr 27 22:22:45 v1 systemd[1]: Stopped Music Player Daemon. Apr 27 22:22:45 v1 systemd[1]: Starting Music Player Daemon... Apr 27 22:22:45 v1 sudo[14946]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 27 22:22:45 v1 sudo[14946]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 27 22:22:45 v1 sudo[14946]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:47 v1 mpd[14948]: Apr 27 22:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 27 22:22:47 v1 systemd[1]: Started Music Player Daemon. Apr 27 22:22:47 v1 sudo[14939]: pam_unix(sudo:session): session closed for user root Apr 27 22:22:47 v1 volumio[2591]: error: updateQueue error: null Apr 27 22:22:48 v1 volumio[2591]: info: CoreCommandRouter::volumioPlay Apr 27 22:22:48 v1 volumio[2591]: info: CoreStateMachine::play index undefined Apr 27 22:22:48 v1 volumio[2591]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 27 22:22:48 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:48 v1 volumio[2591]: info: CoreStateMachine::startPlaybackTimer Apr 27 22:22:48 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:48 v1 volumio[2591]: info: ControllerMpd::resume Apr 27 22:22:48 v1 volumio[2591]: verbose: ControllerMpd::sendMpdCommand play Apr 27 22:22:48 v1 volumio[2591]: info: sendMpdCommand play took 2 milliseconds Apr 27 22:22:55 v1 volumio[2591]: info: CoreCommandRouter::volumioGetState Apr 27 22:22:55 v1 volumio[2591]: info: CorePlayQueue::getTrack 0 Apr 27 22:22:56 v1 volumio[2591]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 27 22:22:56 v1 volumio[2591]: Error: connect ETIMEDOUT 69.171.228.74:443 Apr 27 22:22:56 v1 volumio[2591]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Apr 27 22:22:56 v1 volumio[2591]: errno: -110, Apr 27 22:22:56 v1 volumio[2591]: code: 'ETIMEDOUT', Apr 27 22:22:56 v1 volumio[2591]: syscall: 'connect', Apr 27 22:22:56 v1 volumio[2591]: address: '69.171.228.74', Apr 27 22:22:56 v1 volumio[2591]: port: 443 Apr 27 22:22:56 v1 volumio[2591]: } Apr 27 22:22:56 v1 volumio[2591]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 27 22:22:57 v1 sudo[14978]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-27 22:21 Apr 27 22:22:57 v1 sudo[14978]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"