-- Logs begin at Thu 2025-10-30 20:54:53 CST, end at Thu 2025-10-30 21:22:42 CST. -- Oct 30 21:21:03 volumio3160 volumio[912]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E5%88%80%E9%83%8E/%E5%B1%B1%E6%AD%8C%E5%AF%A5%E5%93%89/7ba4bc07-9656-4231-a47f-7334dae65b71.jpg' Oct 30 21:21:03 volumio3160 ntpd[3747]: 117.80.231.60 local addr 192.168.0.142 -> Oct 30 21:21:15 volumio3160 volumio[912]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 30 21:21:15 volumio3160 volumio[912]: info: Preparing to save Alsa Options, stopping services first Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:21:15 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPause Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::pause Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::stPlaybackTimer Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::servicePause Oct 30 21:21:15 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::servicePause Oct 30 21:21:15 volumio3160 volumio[912]: info: ControllerMpd::pause Oct 30 21:21:15 volumio3160 volumio[912]: verbose: ControllerMpd::sendMpdCommand pause Oct 30 21:21:15 volumio3160 volumio[912]: info: Saving Audio Output to: {"output_device":{"value":"0,0","label":"Analog Out"}} Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:21:15 volumio3160 volumio[912]: info: Found match in Cards Database: setting mixer for card Analog Out Oct 30 21:21:15 volumio3160 volumio[912]: info: Setting mixer Master for card Analog Out Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 30 21:21:15 volumio3160 volumio[912]: info: Updating Volume Controller Parameters: Device: 0,0 Name: Analog Out Mixer: Master Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 30 21:21:15 volumio3160 volumio[912]: info: Disabling external Volume Control Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 30 21:21:15 volumio3160 volumio[912]: info: Preparing to generate the ALSA configuration file Oct 30 21:21:15 volumio3160 volumio[912]: info: Oct 30 21:21:15 volumio3160 volumio[912]: ---------------------------- MPD announces state update: player Oct 30 21:21:15 volumio3160 volumio[912]: info: sendMpdCommand pause took 200 milliseconds Oct 30 21:21:15 volumio3160 volumio[912]: info: ControllerMpd::getState Oct 30 21:21:15 volumio3160 volumio[912]: verbose: ControllerMpd::sendMpdCommand status Oct 30 21:21:15 volumio3160 volumio[912]: info: sendMpdCommand status took 20 milliseconds Oct 30 21:21:15 volumio3160 volumio[912]: verbose: ControllerMpd::parseState Oct 30 21:21:15 volumio3160 volumio[912]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 30 21:21:15 volumio3160 volumio[912]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 30 21:21:15 volumio3160 volumio[912]: verbose: ControllerMpd::parseTrackInfo Oct 30 21:21:15 volumio3160 volumio[912]: info: ControllerMpd::pushState Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::servicePushState Oct 30 21:21:15 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:15 volumio3160 volumio[912]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":48242,"duration":285,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"03. 分手總要在雨天.dff","artist":null,"album":null,"uri":"USB/新加卷/03. 分手總要在雨天.dff","trackType":"dff"} Oct 30 21:21:15 volumio3160 volumio[912]: verbose: CURRENT POSITION 0 Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::syncState stateService pause Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::syncState currentStatus pause Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:21:15 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:21:15 volumio3160 volumio[912]: info: CoreStateMachine::stPlaybackTimer Oct 30 21:21:15 volumio3160 volumio[912]: info: ------------------------------ 39ms Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 30 21:21:16 volumio3160 volumio[912]: info: Asound.conf file unchanged, so no further update is needed Oct 30 21:21:16 volumio3160 volumio[912]: info: Output device has changed, restarting MPD Oct 30 21:21:16 volumio3160 sudo[6671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 30 21:21:16 volumio3160 sudo[6671]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:21:16 volumio3160 volumio[912]: info: Output device has changed, restarting Shairport Sync Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:21:16 volumio3160 sudo[6671]: pam_unix(sudo:session): session closed for user root Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:21:16 volumio3160 sudo[6674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 30 21:21:16 volumio3160 sudo[6674]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:21:16 volumio3160 systemd[1]: Stopping Music Player Daemon... Oct 30 21:21:16 volumio3160 volumio[912]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 30 21:21:16 volumio3160 volumio[912]: info: VolumeController:: Volume=100 Mute =false Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:21:16 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:21:16 volumio3160 volumio[912]: info: MPD Permissions set Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:21:16 volumio3160 systemd[1]: mpd.service: Succeeded. Oct 30 21:21:16 volumio3160 systemd[1]: Stopped Music Player Daemon. Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 30 21:21:16 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:21:16 volumio3160 systemd[1]: Starting Music Player Daemon... Oct 30 21:21:16 volumio3160 volumio[912]: info: Starting Shairport Sync Oct 30 21:21:16 volumio3160 sudo[6687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 21:21:16 volumio3160 sudo[6687]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:21:16 volumio3160 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 30 21:21:16 volumio3160 systemd[1]: shairport-sync.service: Succeeded. Oct 30 21:21:16 volumio3160 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 30 21:21:16 volumio3160 sudo[6683]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 30 21:21:16 volumio3160 sudo[6683]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:21:16 volumio3160 sudo[6683]: pam_unix(sudo:session): session closed for user root Oct 30 21:21:16 volumio3160 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 30 21:21:16 volumio3160 sudo[6687]: pam_unix(sudo:session): session closed for user root Oct 30 21:21:16 volumio3160 volumio[912]: info: Shairport-Sync Started Oct 30 21:21:17 volumio3160 mpd[6692]: Oct 30 21:21 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 30 21:21:17 volumio3160 systemd[1]: Started Music Player Daemon. Oct 30 21:21:17 volumio3160 sudo[6674]: pam_unix(sudo:session): session closed for user root Oct 30 21:21:17 volumio3160 volumio[912]: error: updateQueue error: null Oct 30 21:21:19 volumio3160 volumio[912]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 30 21:21:19 volumio3160 volumio[912]: info: CoreStateMachine::getcurrentVolume Oct 30 21:21:19 volumio3160 volumio[912]: info: CoreCommandRouter::volumioRetrievevolume Oct 30 21:21:20 volumio3160 volumio[912]: info: VolumeController:: Volume=100 Mute =false Oct 30 21:21:20 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:21:20 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:21:20 volumio3160 volumio[912]: info: CoreStateMachine::updateTrackBlock Oct 30 21:21:20 volumio3160 volumio[912]: info: CorePlayQueue::getTrackBlock Oct 30 21:21:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioRetrievevolume Oct 30 21:21:20 volumio3160 volumio[912]: info: VolumeController:: Volume=100 Mute =false Oct 30 21:21:20 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:21:20 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:21:30 volumio3160 volumio[912]: verbose: New Socket.io Connection to 192.168.0.142:3000 from 192.168.0.133 UA: Dalvik/2.1.0 (Linux; U; Android 15; V2359A Build/AP3A.240905.015.A1) Engine version: 3 Transport: polling Total Clients: 6 Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetQueue Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreStateMachine::getQueue Oct 30 21:21:30 volumio3160 volumio[912]: info: CorePlayQueue::getQueue Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:21:30 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:21:30 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetVisibleSources Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 21:21:30 volumio3160 volumio[912]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 30 21:21:31 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 30 21:22:03 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getDevices Oct 30 21:22:03 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getDevices Oct 30 21:22:05 volumio3160 volumio[912]: verbose: New Socket.io Connection to 192.168.0.142:3000 from 192.168.0.133 UA: Dalvik/2.1.0 (Linux; U; Android 15; V2359A Build/AP3A.240905.015.A1) Engine version: 3 Transport: polling Total Clients: 6 Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 30 21:22:05 volumio3160 volumio[912]: info: Discovery: Getting this device information Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:22:05 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetQueue Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreStateMachine::getQueue Oct 30 21:22:05 volumio3160 volumio[912]: info: CorePlayQueue::getQueue Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:22:05 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:22:05 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:22:05 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:22:05 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetVisibleSources Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:22:05 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreCommandRouter::volumioToggle Oct 30 21:22:06 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreStateMachine::play index undefined Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 21:22:06 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:06 volumio3160 volumio[912]: info: CoreStateMachine::startPlaybackTimer Oct 30 21:22:06 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:06 volumio3160 volumio[912]: info: ControllerMpd::resume Oct 30 21:22:06 volumio3160 volumio[912]: verbose: ControllerMpd::sendMpdCommand play Oct 30 21:22:06 volumio3160 volumio[912]: info: sendMpdCommand play took 1 milliseconds Oct 30 21:22:08 volumio3160 volumio[912]: info: VolumeController::SetAlsaVolume41 Oct 30 21:22:08 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:22:08 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:08 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 21:22:08 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:22:08 volumio3160 ntpd[3747]: 108.59.2.24 local addr 192.168.0.142 -> Oct 30 21:22:11 volumio3160 volumio[912]: info: CoreCommandRouter::volumioToggle Oct 30 21:22:11 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:11 volumio3160 volumio[912]: info: CoreStateMachine::play index undefined Oct 30 21:22:11 volumio3160 volumio[912]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 30 21:22:11 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:11 volumio3160 volumio[912]: info: CoreStateMachine::startPlaybackTimer Oct 30 21:22:11 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:11 volumio3160 volumio[912]: info: ControllerMpd::resume Oct 30 21:22:11 volumio3160 volumio[912]: verbose: ControllerMpd::sendMpdCommand play Oct 30 21:22:11 volumio3160 volumio[912]: info: sendMpdCommand play took 3 milliseconds Oct 30 21:22:20 volumio3160 volumio[912]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 30 21:22:20 volumio3160 volumio[912]: info: Preparing to save Alsa Options, stopping services first Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioGetState Oct 30 21:22:20 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPause Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreStateMachine::pause Oct 30 21:22:20 volumio3160 volumio[912]: info: Saving Audio Output to: {"output_device":{"value":"0,1","label":"SPDIF"}} Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:22:20 volumio3160 volumio[912]: info: Found match in Cards Database: setting mixer for card SPDIF Oct 30 21:22:20 volumio3160 volumio[912]: info: Setting mixer Master for card SPDIF Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 30 21:22:20 volumio3160 volumio[912]: info: Updating Volume Controller Parameters: Device: 0,1 Name: SPDIF Mixer: Master Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 30 21:22:20 volumio3160 volumio[912]: info: Disabling external Volume Control Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 30 21:22:20 volumio3160 volumio[912]: info: Preparing to generate the ALSA configuration file Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 30 21:22:20 volumio3160 volumio[912]: info: VolumeController:: Volume=40 Mute =false Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:22:20 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 21:22:20 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:22:20 volumio3160 volumio[912]: info: Asound.conf file written Oct 30 21:22:21 volumio3160 sudo[6892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 30 21:22:21 volumio3160 sudo[6892]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 sudo[6892]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:21 volumio3160 volumio[912]: No state is present for card PCH Oct 30 21:22:21 volumio3160 volumio[912]: Found hardware: "HDA-Intel" "Realtek ALC662 rev3" "HDA:10ec0662,10ec0000,00100300 HDA:80862883,80860101,00100000" "0x8086" "0x7270" Oct 30 21:22:21 volumio3160 volumio[912]: Hardware is initialized using a generic method Oct 30 21:22:21 volumio3160 volumio[912]: No state is present for card PCH Oct 30 21:22:21 volumio3160 volumio[912]: info: Output device has changed, restarting MPD Oct 30 21:22:21 volumio3160 sudo[6898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 30 21:22:21 volumio3160 sudo[6898]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 volumio[912]: info: Output device has changed, restarting Shairport Sync Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 sudo[6898]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:22:21 volumio3160 sudo[6901]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 30 21:22:21 volumio3160 sudo[6901]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 systemd[1]: Stopping Music Player Daemon... Oct 30 21:22:21 volumio3160 systemd[1]: mpd.service: Succeeded. Oct 30 21:22:21 volumio3160 volumio[912]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 30 21:22:21 volumio3160 systemd[1]: Stopped Music Player Daemon. Oct 30 21:22:21 volumio3160 volumio[912]: info: Output device has changed, restarting MPD Oct 30 21:22:21 volumio3160 systemd[1]: Starting Music Player Daemon... Oct 30 21:22:21 volumio3160 sudo[6908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 30 21:22:21 volumio3160 sudo[6908]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 sudo[6908]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:21 volumio3160 volumio[912]: info: Output device has changed, restarting Shairport Sync Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:22:21 volumio3160 sudo[6911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 30 21:22:21 volumio3160 sudo[6911]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 30 21:22:21 volumio3160 systemd[1]: mpd.service: Succeeded. Oct 30 21:22:21 volumio3160 systemd[1]: Stopped Music Player Daemon. Oct 30 21:22:21 volumio3160 volumio[912]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 30 21:22:21 volumio3160 volumio[912]: info: MPD Permissions set Oct 30 21:22:21 volumio3160 volumio[912]: info: MPD Permissions set Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 systemd[1]: Starting Music Player Daemon... Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 30 21:22:21 volumio3160 sudo[6916]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 30 21:22:21 volumio3160 sudo[6916]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 sudo[6916]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:21 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 30 21:22:21 volumio3160 volumio[912]: info: Starting Shairport Sync Oct 30 21:22:21 volumio3160 volumio[912]: info: Starting Shairport Sync Oct 30 21:22:21 volumio3160 sudo[6932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 21:22:21 volumio3160 sudo[6932]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 30 21:22:21 volumio3160 sudo[6935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 30 21:22:21 volumio3160 sudo[6935]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 30 21:22:21 volumio3160 systemd[1]: shairport-sync.service: Succeeded. Oct 30 21:22:21 volumio3160 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 30 21:22:21 volumio3160 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 30 21:22:21 volumio3160 sudo[6932]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:21 volumio3160 volumio[912]: info: Shairport-Sync Started Oct 30 21:22:21 volumio3160 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 30 21:22:21 volumio3160 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 30 21:22:21 volumio3160 systemd[1]: shairport-sync.service: Succeeded. Oct 30 21:22:21 volumio3160 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 30 21:22:21 volumio3160 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 30 21:22:21 volumio3160 sudo[6935]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:21 volumio3160 volumio[912]: info: Shairport-Sync Started Oct 30 21:22:22 volumio3160 mpd[6929]: Oct 30 21:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 30 21:22:22 volumio3160 systemd[1]: Started Music Player Daemon. Oct 30 21:22:22 volumio3160 sudo[6901]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:22 volumio3160 sudo[6911]: pam_unix(sudo:session): session closed for user root Oct 30 21:22:22 volumio3160 volumio[912]: error: MPD error: The expression evaluated to a falsy value: Oct 30 21:22:22 volumio3160 volumio[912]: assert.ok(self.idling) Oct 30 21:22:22 volumio3160 volumio[912]: error: The expression evaluated to a falsy value: Oct 30 21:22:22 volumio3160 volumio[912]: assert.ok(self.idling) Oct 30 21:22:22 volumio3160 volumio[912]: error: updateQueue error: null Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreStateMachine::getcurrentVolume Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreCommandRouter::volumioRetrievevolume Oct 30 21:22:24 volumio3160 volumio[912]: info: VolumeController:: Volume=41 Mute =false Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:22:24 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreStateMachine::updateTrackBlock Oct 30 21:22:24 volumio3160 volumio[912]: info: CorePlayQueue::getTrackBlock Oct 30 21:22:24 volumio3160 volumio[912]: info: CoreCommandRouter::volumioRetrievevolume Oct 30 21:22:25 volumio3160 volumio[912]: info: VolumeController:: Volume=41 Mute =false Oct 30 21:22:25 volumio3160 volumio[912]: info: CoreStateMachine::pushState Oct 30 21:22:25 volumio3160 volumio[912]: info: CorePlayQueue::getTrack 0 Oct 30 21:22:25 volumio3160 volumio[912]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 30 21:22:25 volumio3160 volumio[912]: info: CoreCommandRouter::volumioPushState Oct 30 21:22:42 volumio3160 volumio[912]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 30 21:22:42 volumio3160 volumio[912]: Error: connect ETIMEDOUT 173.252.248.244:443 Oct 30 21:22:42 volumio3160 volumio[912]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Oct 30 21:22:42 volumio3160 volumio[912]: errno: -110, Oct 30 21:22:42 volumio3160 volumio[912]: code: 'ETIMEDOUT', Oct 30 21:22:42 volumio3160 volumio[912]: syscall: 'connect', Oct 30 21:22:42 volumio3160 volumio[912]: address: '173.252.248.244', Oct 30 21:22:42 volumio3160 volumio[912]: port: 443 Oct 30 21:22:42 volumio3160 volumio[912]: } Oct 30 21:22:42 volumio3160 volumio[912]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 30 21:22:42 volumio3160 sudo[6991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-30 21:21 Oct 30 21:22:42 volumio3160 sudo[6991]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:41:06 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="097e6b8b481766e7a0f9527e4a34a29b"