-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Sun 2024-05-12 14:13:34 CST. -- May 12 14:12:04 volumio volumio[809]: verbose: New Socket.io Connection to 192.168.0.108 from 192.168.0.102 UA: okhttp/4.9.2 Total Clients: 4 May 12 14:12:04 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:04 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 12 14:12:04 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 12 14:12:04 volumio volumio[809]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Beyond/%E4%B9%90%E4%B8%8E%E6%80%92/1117e744-25be-4dd9-b01f-08205283f8f3.jpg' May 12 14:12:04 volumio volumio[809]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Beyond/%E4%B9%90%E4%B8%8E%E6%80%92/1117e744-25be-4dd9-b01f-08205283f8f3.jpg' May 12 14:12:05 volumio volumio[809]: verbose: New Socket.io Connection to 192.168.0.108 from 192.168.0.102 UA: okhttp/4.9.2 Total Clients: 5 May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetVisibleSources May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 12 14:12:05 volumio volumio[809]: info: Received Get System Info May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 14:12:05 volumio volumio[809]: info: Discovery: Getting this device information May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:05 volumio volumio[809]: info: Listing playlists May 12 14:12:05 volumio volumio[809]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Beyond/%E4%B9%90%E4%B8%8E%E6%80%92/1117e744-25be-4dd9-b01f-08205283f8f3.jpg' May 12 14:12:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 12 14:12:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 14:12:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 14:12:07 volumio volumio[809]: info: Discovery: Getting this device information May 12 14:12:07 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::getUIConfigOnPlugin May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 14:12:10 volumio volumio[809]: info: Getting Alsa Cards List without I2S DAC May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 12 14:12:10 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 12 14:12:18 volumio volumio[809]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:18 volumio volumio[809]: info: Restoring Previous Volume level: 100 false true May 12 14:12:18 volumio volumio[809]: info: VolumeController::SetAlsaVolume100 May 12 14:12:18 volumio volumio[809]: info: Enable softmixer device for audio device number 2 May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::volumioStop May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::stop May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock May 12 14:12:18 volumio volumio[809]: info: CorePlayQueue::getTrackBlock May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:18 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::serviceStop May 12 14:12:18 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:18 volumio volumio[809]: info: ControllerMpd::stop May 12 14:12:18 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand stop May 12 14:12:18 volumio volumio[809]: info: Enable softmixer device for audio device undefined May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 12 14:12:18 volumio volumio[809]: info: Updating Volume Controller Parameters: Device: 2 Name: R-PI DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 12 14:12:18 volumio volumio[809]: info: Disabling external Volume Control May 12 14:12:18 volumio volumio[809]: info: Output device has changed, restarting MPD May 12 14:12:18 volumio volumio[809]: info: Output device has changed, restarting Shairport Sync May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:18 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 14:12:18 volumio volumio[809]: info: Volume configurations have been set May 12 14:12:18 volumio sudo[1673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 14:12:18 volumio sudo[1675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 14:12:18 volumio sudo[1675]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:18 volumio sudo[1673]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:18 volumio sudo[1673]: pam_unix(sudo:session): session closed for user root May 12 14:12:18 volumio systemd[1]: Stopping Music Player Daemon... May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 12 14:12:18 volumio volumio[809]: info: Updating Volume Controller Parameters: Device: 2 Name: R-PI DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 12 14:12:18 volumio volumio[809]: info: Disabling external Volume Control May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::getUIConfigOnPlugin May 12 14:12:18 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:18 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:18 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:19 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:19 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:19 volumio volumio[809]: error: MPD error: Error: write EPIPE May 12 14:12:19 volumio volumio[809]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} May 12 14:12:19 volumio volumio[809]: error: Upnp client error: Error: This socket has been ended by the other party May 12 14:12:19 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:19 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:19 volumio volumio[809]: info: MPD Permissions set May 12 14:12:19 volumio volumio[809]: info: Software Volume ALSA configuration written May 12 14:12:19 volumio volumio[809]: info: Preparing to generate the ALSA configuration file May 12 14:12:19 volumio volumio[809]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 12 14:12:19 volumio volumio[809]: info: Reading ALSA contributions from plugins. May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 14:12:19 volumio volumio[809]: info: Getting Alsa Cards List without I2S DAC May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 12 14:12:19 volumio volumio[809]: info: Starting Shairport Sync May 12 14:12:19 volumio volumio[809]: info: Asound.conf file written May 12 14:12:19 volumio sudo[1702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 14:12:19 volumio sudo[1702]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:19 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 14:12:19 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 14:12:19 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 14:12:19 volumio sudo[1705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 12 14:12:19 volumio sudo[1705]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:19 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 14:12:19 volumio volumio[809]: info: Output device has changed, restarting MPD May 12 14:12:19 volumio sudo[1705]: pam_unix(sudo:session): session closed for user root May 12 14:12:19 volumio systemd[1]: mpd.service: Succeeded. May 12 14:12:19 volumio systemd[1]: Stopped Music Player Daemon. May 12 14:12:19 volumio volumio[809]: info: Output device has changed, restarting Shairport Sync May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:19 volumio sudo[1711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 14:12:19 volumio sudo[1702]: pam_unix(sudo:session): session closed for user root May 12 14:12:19 volumio sudo[1711]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:19 volumio systemd[1]: Starting Music Player Daemon... May 12 14:12:19 volumio sudo[1711]: pam_unix(sudo:session): session closed for user root May 12 14:12:19 volumio sudo[1716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 14:12:19 volumio sudo[1716]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:19 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 12 14:12:19 volumio systemd[1]: mpd.service: Succeeded. May 12 14:12:19 volumio systemd[1]: Stopped Music Player Daemon. May 12 14:12:19 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 14:12:19 volumio systemd[1]: Starting Music Player Daemon... May 12 14:12:20 volumio mpd[1722]: May 12 14:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 12 14:12:20 volumio systemd[1]: Started Music Player Daemon. May 12 14:12:20 volumio sudo[1675]: pam_unix(sudo:session): session closed for user root May 12 14:12:20 volumio sudo[1716]: pam_unix(sudo:session): session closed for user root May 12 14:12:20 volumio volumio[809]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo May 12 14:12:20 volumio volumio[809]: info: Output device has changed, restarting MPD May 12 14:12:20 volumio volumio[809]: info: Output device has changed, restarting Shairport Sync May 12 14:12:20 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:20 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:20 volumio sudo[1731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 14:12:20 volumio sudo[1731]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:20 volumio sudo[1731]: pam_unix(sudo:session): session closed for user root May 12 14:12:20 volumio sudo[1733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 14:12:20 volumio sudo[1733]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:20 volumio systemd[1]: Stopping Music Player Daemon... May 12 14:12:20 volumio volumio[809]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 14:12:20 volumio systemd[1]: mpd.service: Succeeded. May 12 14:12:20 volumio systemd[1]: Stopped Music Player Daemon. May 12 14:12:20 volumio volumio[809]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 12 14:12:20 volumio volumio[809]: info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 12 14:12:20 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 12 14:12:20 volumio volumio[809]: info: Disabling external Volume Control May 12 14:12:20 volumio systemd[1]: Starting Music Player Daemon... May 12 14:12:21 volumio volumio[809]: info: MPD Permissions set May 12 14:12:21 volumio volumio[809]: info: MPD Permissions set May 12 14:12:21 volumio volumio[809]: info: Shairport-Sync Started May 12 14:12:21 volumio volumio[809]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 May 12 14:12:21 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 14:12:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:21 volumio volumio[809]: info: Starting Shairport Sync May 12 14:12:21 volumio volumio[809]: info: Starting Shairport Sync May 12 14:12:21 volumio sudo[1758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 14:12:21 volumio sudo[1758]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:21 volumio sudo[1760]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 14:12:21 volumio sudo[1760]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 14:12:21 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 14:12:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 14:12:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 14:12:21 volumio sudo[1758]: pam_unix(sudo:session): session closed for user root May 12 14:12:21 volumio volumio[809]: info: Shairport-Sync Started May 12 14:12:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 14:12:21 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 12 14:12:21 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 14:12:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 14:12:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 14:12:21 volumio sudo[1760]: pam_unix(sudo:session): session closed for user root May 12 14:12:21 volumio volumio[809]: info: Shairport-Sync Started May 12 14:12:21 volumio mpd[1740]: May 12 14:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 12 14:12:21 volumio systemd[1]: Started Music Player Daemon. May 12 14:12:21 volumio sudo[1733]: pam_unix(sudo:session): session closed for user root May 12 14:12:21 volumio volumio[809]: error: MPD error: The expression evaluated to a falsy value: May 12 14:12:21 volumio volumio[809]: assert.ok(self.idling) May 12 14:12:21 volumio volumio[809]: error: The expression evaluated to a falsy value: May 12 14:12:21 volumio volumio[809]: assert.ok(self.idling) May 12 14:12:21 volumio volumio[809]: error: updateQueue error: null May 12 14:12:21 volumio volumio[809]: error: updateQueue error: null May 12 14:12:22 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd May 12 14:12:22 volumio sudo[1773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 14:12:22 volumio sudo[1773]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 14:12:22 volumio systemd[1]: Stopping Music Player Daemon... May 12 14:12:22 volumio systemd[1]: mpd.service: Succeeded. May 12 14:12:22 volumio systemd[1]: Stopped Music Player Daemon. May 12 14:12:22 volumio volumio[809]: error: Upnp client error: Error: This socket has been ended by the other party May 12 14:12:22 volumio systemd[1]: Starting Music Player Daemon... May 12 14:12:23 volumio mpd[1775]: May 12 14:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 12 14:12:23 volumio systemd[1]: Started Music Player Daemon. May 12 14:12:23 volumio sudo[1773]: pam_unix(sudo:session): session closed for user root May 12 14:12:23 volumio volumio[809]: error: updateQueue error: null May 12 14:12:23 volumio volumio[809]: info: VolumeController::SetAlsaVolume100 May 12 14:12:23 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:23 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:23 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:23 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:23 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 14:12:24 volumio volumio[809]: info: Clearing queue after UPNP request May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::ClearQueue May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::stop May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::clearPlayQueue May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::saveQueue May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: error: updateQueue error: null May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 2ms May 12 14:12:25 volumio volumio[809]: info: Starting UPNP Playback May 12 14:12:25 volumio volumio[809]: info: Preparing playback through UPNP May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioGetState May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::getTrack 0 May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 2ms May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 2ms May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 2ms May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 3ms May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 2ms May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 1ms May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:12:25 volumio volumio[809]: info: ControllerMpd::getState May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:12:25 volumio volumio[809]: info: sendMpdCommand status took 13 milliseconds May 12 14:12:25 volumio volumio[809]: info: ControllerMpd::getState May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:12:25 volumio volumio[809]: info: sendMpdCommand status took 1 milliseconds May 12 14:12:25 volumio volumio[809]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:12:25 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:12:25 volumio volumio[809]: verbose: In UPNP mode May 12 14:12:25 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"情人","artist":"Beyond (Performer)","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:12:25 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::syncState stateService play May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 18ms May 12 14:12:25 volumio volumio[809]: info: sendMpdCommand playlistinfo took 2 milliseconds May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:12:25 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:12:25 volumio volumio[809]: verbose: In UPNP mode May 12 14:12:25 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"情人","artist":"Beyond (Performer)","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:12:25 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::syncState stateService play May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play May 12 14:12:25 volumio volumio[809]: info: Received an update from plugin. extracting info from payload May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 29ms May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces system playlist update May 12 14:12:25 volumio volumio[809]: info: Ignoring MPD Status Update May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:25 volumio volumio[809]: info: May 12 14:12:25 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:12:25 volumio volumio[809]: info: ControllerMpd::getState May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 11ms May 12 14:12:25 volumio volumio[809]: info: sendMpdCommand status took 1 milliseconds May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:12:25 volumio volumio[809]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 14:12:25 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:12:25 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:12:25 volumio volumio[809]: verbose: In UPNP mode May 12 14:12:25 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":869,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"504 Kbps","isStreaming":false,"title":"情人","artist":"Beyond","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:12:25 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::syncState stateService play May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play May 12 14:12:25 volumio volumio[809]: info: Received an update from plugin. extracting info from payload May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:25 volumio volumio[809]: info: ------------------------------ 20ms May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:25 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:25 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:25 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:27 volumio volumio[809]: info: May 12 14:12:27 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:12:27 volumio volumio[809]: info: ControllerMpd::getState May 12 14:12:27 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:12:27 volumio volumio[809]: info: sendMpdCommand status took 0 milliseconds May 12 14:12:27 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:12:27 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:12:27 volumio volumio[809]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 14:12:27 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:12:27 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:12:27 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:12:27 volumio volumio[809]: verbose: In UPNP mode May 12 14:12:27 volumio volumio[809]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2768,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"855 Kbps","isStreaming":false,"title":"情人","artist":"Beyond","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:12:27 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:12:27 volumio volumio[809]: info: CoreStateMachine::syncState stateService pause May 12 14:12:27 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play May 12 14:12:27 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:27 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:27 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:27 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer May 12 14:12:27 volumio volumio[809]: info: ------------------------------ 11ms May 12 14:12:27 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:27 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:27 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:28 volumio volumio[809]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Beyond/%E4%B9%90%E4%B8%8E%E6%80%92/1117e744-25be-4dd9-b01f-08205283f8f3.jpg' May 12 14:12:38 volumio volumio[809]: info: May 12 14:12:38 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:12:38 volumio volumio[809]: info: ControllerMpd::getState May 12 14:12:38 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:12:38 volumio volumio[809]: info: sendMpdCommand status took 1 milliseconds May 12 14:12:38 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:12:38 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:12:38 volumio volumio[809]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 14:12:38 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:12:38 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:12:38 volumio volumio[809]: verbose: In UPNP mode May 12 14:12:38 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3660,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"872 Kbps","isStreaming":false,"title":"情人","artist":"Beyond","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:12:38 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:12:38 volumio volumio[809]: info: CoreStateMachine::syncState stateService play May 12 14:12:38 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play May 12 14:12:38 volumio volumio[809]: info: Received an update from plugin. extracting info from payload May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 12 14:12:38 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:38 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:38 volumio volumio[809]: info: ------------------------------ 21ms May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:38 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:38 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:38 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:38 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:38 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:40 volumio volumio[949]: 27 May 12 14:12:40 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:40 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:40 volumio volumio[809]: info: May 12 14:12:40 volumio volumio[809]: ---------------------------- Client requests Volume 27 May 12 14:12:40 volumio volumio[809]: info: VolumeController::SetAlsaVolume27 May 12 14:12:40 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:40 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:40 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:40 volumio volumio[949]: [158B blob data] May 12 14:12:40 volumio volumio[949]: {"time":1715494360496,"response":"volume Success"}27 May 12 14:12:40 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:40 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:40 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:40 volumio volumio[949]: 91 May 12 14:12:40 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:40 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:40 volumio volumio[809]: info: May 12 14:12:40 volumio volumio[809]: ---------------------------- Client requests Volume 91 May 12 14:12:40 volumio volumio[809]: info: VolumeController::SetAlsaVolume91 May 12 14:12:40 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:40 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:40 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:40 volumio volumio[949]: [158B blob data] May 12 14:12:40 volumio volumio[949]: {"time":1715494360719,"response":"volume Success"}91 May 12 14:12:40 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:40 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:40 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:42 volumio volumio[949]: 90 May 12 14:12:42 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:42 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:42 volumio volumio[809]: info: May 12 14:12:42 volumio volumio[809]: ---------------------------- Client requests Volume 90 May 12 14:12:42 volumio volumio[809]: info: VolumeController::SetAlsaVolume90 May 12 14:12:42 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:42 volumio volumio[949]: [158B blob data] May 12 14:12:42 volumio volumio[949]: {"time":1715494362252,"response":"volume Success"}90 May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:42 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:42 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:42 volumio volumio[949]: 36 May 12 14:12:42 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:42 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:42 volumio volumio[809]: info: May 12 14:12:42 volumio volumio[809]: ---------------------------- Client requests Volume 36 May 12 14:12:42 volumio volumio[809]: info: VolumeController::SetAlsaVolume36 May 12 14:12:42 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:42 volumio volumio[949]: [158B blob data] May 12 14:12:42 volumio volumio[949]: {"time":1715494362556,"response":"volume Success"}36 May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:42 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:42 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:42 volumio volumio[949]: 32 May 12 14:12:42 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:42 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:42 volumio volumio[809]: info: May 12 14:12:42 volumio volumio[809]: ---------------------------- Client requests Volume 32 May 12 14:12:42 volumio volumio[809]: info: VolumeController::SetAlsaVolume32 May 12 14:12:42 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:42 volumio volumio[949]: [158B blob data] May 12 14:12:42 volumio volumio[949]: {"time":1715494362686,"response":"volume Success"}32 May 12 14:12:42 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:42 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:42 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:45 volumio volumio[949]: 35 May 12 14:12:45 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:45 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:45 volumio volumio[809]: info: May 12 14:12:45 volumio volumio[809]: ---------------------------- Client requests Volume 35 May 12 14:12:45 volumio volumio[809]: info: VolumeController::SetAlsaVolume35 May 12 14:12:45 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:45 volumio volumio[949]: [158B blob data] May 12 14:12:45 volumio volumio[949]: {"time":1715494365257,"response":"volume Success"}35 May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:45 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:45 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:45 volumio volumio[949]: 51 May 12 14:12:45 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:45 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:45 volumio volumio[809]: info: May 12 14:12:45 volumio volumio[809]: ---------------------------- Client requests Volume 51 May 12 14:12:45 volumio volumio[809]: info: VolumeController::SetAlsaVolume51 May 12 14:12:45 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:45 volumio volumio[949]: [158B blob data] May 12 14:12:45 volumio volumio[949]: {"time":1715494365587,"response":"volume Success"}51 May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:45 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:45 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:45 volumio volumio[949]: 56 May 12 14:12:45 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:12:45 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:12:45 volumio volumio[809]: info: May 12 14:12:45 volumio volumio[809]: ---------------------------- Client requests Volume 56 May 12 14:12:45 volumio volumio[809]: info: VolumeController::SetAlsaVolume56 May 12 14:12:45 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:45 volumio volumio[949]: [158B blob data] May 12 14:12:45 volumio volumio[949]: {"time":1715494365875,"response":"volume Success"}56 May 12 14:12:45 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:45 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:45 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:55 volumio volumio[809]: info: May 12 14:12:55 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:12:55 volumio volumio[809]: info: ControllerMpd::getState May 12 14:12:55 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:12:55 volumio volumio[809]: info: sendMpdCommand status took 1 milliseconds May 12 14:12:55 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:12:55 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:12:55 volumio volumio[809]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 14:12:55 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:12:55 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:12:55 volumio volumio[809]: verbose: In UPNP mode May 12 14:12:55 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":41000,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"812 Kbps","isStreaming":false,"title":"情人","artist":"Beyond","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:12:55 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:12:55 volumio volumio[809]: info: CoreStateMachine::syncState stateService play May 12 14:12:55 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play May 12 14:12:55 volumio volumio[809]: info: Received an update from plugin. extracting info from payload May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 12 14:12:55 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:55 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:12:55 volumio volumio[809]: info: ------------------------------ 17ms May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:55 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:55 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:12:55 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:12:55 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:12:55 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:00 volumio volumio[809]: info: May 12 14:13:00 volumio volumio[809]: ---------------------------- MPD announces state update: player May 12 14:13:00 volumio volumio[809]: info: ControllerMpd::getState May 12 14:13:00 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand status May 12 14:13:00 volumio volumio[809]: info: sendMpdCommand status took 0 milliseconds May 12 14:13:00 volumio volumio[809]: verbose: ControllerMpd::parseState May 12 14:13:00 volumio volumio[809]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 14:13:00 volumio volumio[809]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 14:13:00 volumio volumio[809]: verbose: ControllerMpd::parseTrackInfo May 12 14:13:00 volumio volumio[809]: info: ControllerMpd::pushState May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::servicePushState May 12 14:13:00 volumio volumio[809]: verbose: In UPNP mode May 12 14:13:00 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","position":0,"seek":88000,"duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"786 Kbps","isStreaming":false,"title":"情人","artist":"Beyond","album":"乐与怒","uri":"http://192.168.0.110:10246/MDEServer/89FD72A7-68D4-4E71-9C02-66AD70792663/1000.flac","trackType":"flac"} May 12 14:13:00 volumio volumio[809]: verbose: CURRENT POSITION 0 May 12 14:13:00 volumio volumio[809]: info: CoreStateMachine::syncState stateService play May 12 14:13:00 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play May 12 14:13:00 volumio volumio[809]: info: Received an update from plugin. extracting info from payload May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 12 14:13:00 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:00 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:00 volumio volumio[809]: info: ------------------------------ 18ms May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:00 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:00 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:00 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:00 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:00 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:19 volumio volumio[949]: 57 May 12 14:13:19 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:13:19 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:13:19 volumio volumio[809]: info: May 12 14:13:19 volumio volumio[809]: ---------------------------- Client requests Volume 57 May 12 14:13:19 volumio volumio[809]: info: VolumeController::SetAlsaVolume57 May 12 14:13:19 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:13:19 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:19 volumio volumio[949]: [158B blob data] May 12 14:13:19 volumio volumio[949]: {"time":1715494399397,"response":"volume Success"}57 May 12 14:13:19 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:19 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:19 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:19 volumio volumio[949]: 73 May 12 14:13:19 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:13:19 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:13:19 volumio volumio[809]: info: May 12 14:13:19 volumio volumio[809]: ---------------------------- Client requests Volume 73 May 12 14:13:19 volumio volumio[809]: info: VolumeController::SetAlsaVolume73 May 12 14:13:19 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:19 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:13:19 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:19 volumio volumio[949]: [158B blob data] May 12 14:13:19 volumio volumio[949]: {"time":1715494399706,"response":"volume Success"}73 May 12 14:13:19 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:19 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:19 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:19 volumio volumio[949]: 78 May 12 14:13:20 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:13:20 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:13:20 volumio volumio[809]: info: May 12 14:13:20 volumio volumio[809]: ---------------------------- Client requests Volume 78 May 12 14:13:20 volumio volumio[809]: info: VolumeController::SetAlsaVolume78 May 12 14:13:20 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:20 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:13:20 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:20 volumio volumio[949]: [158B blob data] May 12 14:13:20 volumio volumio[949]: {"time":1715494400015,"response":"volume Success"}78 May 12 14:13:20 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:20 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:20 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:21 volumio volumio[949]: 77 May 12 14:13:21 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:13:21 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:13:21 volumio volumio[809]: info: May 12 14:13:21 volumio volumio[809]: ---------------------------- Client requests Volume 77 May 12 14:13:21 volumio volumio[809]: info: VolumeController::SetAlsaVolume77 May 12 14:13:21 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:13:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:21 volumio volumio[949]: [158B blob data] May 12 14:13:21 volumio volumio[949]: {"time":1715494401879,"response":"volume Success"}77 May 12 14:13:21 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:21 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:21 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:22 volumio volumio[949]: 71 May 12 14:13:22 volumio volumio[949]: % Total % Received % Xferd Average Speed Time Time Time Current May 12 14:13:22 volumio volumio[949]: Dload Upload Total Spent Left Speed May 12 14:13:22 volumio volumio[809]: info: May 12 14:13:22 volumio volumio[809]: ---------------------------- Client requests Volume 71 May 12 14:13:22 volumio volumio[809]: info: VolumeController::SetAlsaVolume71 May 12 14:13:22 volumio volumio[809]: info: CoreStateMachine::pushState May 12 14:13:22 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 14:13:22 volumio volumio[809]: info: CoreCommandRouter::volumioPushState May 12 14:13:22 volumio volumio[949]: [158B blob data] May 12 14:13:22 volumio volumio[949]: {"time":1715494402182,"response":"volume Success"}71 May 12 14:13:22 volumio volumio[809]: info: CoreCommandRouter::volumioGetQueue May 12 14:13:22 volumio volumio[809]: info: CoreStateMachine::getQueue May 12 14:13:22 volumio volumio[809]: info: CorePlayQueue::getQueue May 12 14:13:33 volumio volumio[809]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 14:13:33 volumio volumio[809]: Error: connect ETIMEDOUT 43.226.16.8:443 May 12 14:13:33 volumio volumio[809]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { May 12 14:13:33 volumio volumio[809]: errno: -110, May 12 14:13:33 volumio volumio[809]: code: 'ETIMEDOUT', May 12 14:13:33 volumio volumio[809]: syscall: 'connect', May 12 14:13:33 volumio volumio[809]: address: '43.226.16.8', May 12 14:13:33 volumio volumio[809]: port: 443 May 12 14:13:33 volumio volumio[809]: } May 12 14:13:33 volumio volumio[809]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 14:13:34 volumio sudo[2157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-12 14:12 May 12 14:13:34 volumio sudo[2157]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"