-- Logs begin at Fri 2024-03-22 17:18:45 CST, end at Thu 2024-04-11 15:34:45 CST. -- Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 15:33:15 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 15:33:58 volumio volumio[2191]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::volumioGetState Apr 11 15:33:58 volumio volumio[2191]: info: Restoring Previous Volume level: 100 false false Apr 11 15:33:58 volumio volumio[2191]: info: Disable softmixer device for audio device Apr 11 15:33:58 volumio volumio[2191]: info: Output device has changed, restarting MPD Apr 11 15:33:58 volumio volumio[2191]: info: Output device has changed, restarting Shairport Sync Apr 11 15:33:58 volumio sudo[5354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 15:33:58 volumio sudo[5354]: pam_env(sudo:session): Unable to open env file: /etc/default/locale: No such file or directory Apr 11 15:33:58 volumio sudo[5354]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 15:33:58 volumio sudo[5357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 15:33:58 volumio volumio[2191]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 15:33:58 volumio volumio[2191]: info: Volume configurations have been set Apr 11 15:33:58 volumio sudo[5357]: pam_env(sudo:session): Unable to open env file: /etc/default/locale: No such file or directory Apr 11 15:33:58 volumio sudo[5357]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 15:33:58 volumio sudo[5354]: pam_unix(sudo:session): session closed for user root Apr 11 15:33:58 volumio systemd[1]: Stopping Music Player Daemon... Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 15:33:58 volumio volumio[2191]: info: Updating Volume Controller Parameters: Device: 0 Name: Analog Audio Out Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10 Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 15:33:58 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:33:58 volumio systemd[1]: mpd.service: Succeeded. Apr 11 15:33:58 volumio systemd[1]: Stopped Music Player Daemon. Apr 11 15:33:58 volumio volumio[2191]: info: CoreCommandRouter::volumioGetQueue Apr 11 15:33:58 volumio volumio[2191]: info: CoreStateMachine::getQueue Apr 11 15:33:58 volumio volumio[2191]: info: CorePlayQueue::getQueue Apr 11 15:33:58 volumio volumio[2191]: info: MPD Permissions set Apr 11 15:33:58 volumio volumio[2191]: info: Asound.conf file written Apr 11 15:33:58 volumio systemd[1]: Starting Music Player Daemon... Apr 11 15:33:58 volumio sudo[5379]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 11 15:33:58 volumio sudo[5379]: pam_env(sudo:session): Unable to open env file: /etc/default/locale: No such file or directory Apr 11 15:33:58 volumio sudo[5379]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 15:33:59 volumio sudo[5379]: pam_unix(sudo:session): session closed for user root Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 15:33:59 volumio volumio[2191]: info: Updating Volume Controller Parameters: Device: 0 Name: Analog Audio Out Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 10 Apr 11 15:33:59 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 15:33:59 volumio volumio[2191]: info: CoreCommandRouter::volumioGetQueue Apr 11 15:33:59 volumio volumio[2191]: info: CoreStateMachine::getQueue Apr 11 15:33:59 volumio volumio[2191]: info: CorePlayQueue::getQueue Apr 11 15:33:59 volumio volumio[2191]: info: Starting Shairport Sync Apr 11 15:33:59 volumio sudo[5405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 15:33:59 volumio sudo[5405]: pam_env(sudo:session): Unable to open env file: /etc/default/locale: No such file or directory Apr 11 15:33:59 volumio sudo[5405]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 15:33:59 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 11 15:33:59 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 11 15:33:59 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 11 15:33:59 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 11 15:33:59 volumio sudo[5405]: pam_unix(sudo:session): session closed for user root Apr 11 15:33:59 volumio volumio[2191]: info: Shairport-Sync Started Apr 11 15:34:00 volumio mpd[5377]: config_file: config parameter "gapless_mp3_playback" on line 19 is deprecated Apr 11 15:34:00 volumio mpd[5377]: config_file: config parameter "buffer_before_play" on line 85 is deprecated Apr 11 15:34:00 volumio mpd[5377]: config_file: config parameter "id3v1_encoding" on line 99 is deprecated Apr 11 15:34:00 volumio mpd[5377]: Apr 11 15:34 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 15:34:00 volumio mpd[5377]: Apr 11 15:34 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Apr 11 15:34:00 volumio mpd[5377]: Apr 11 15:34 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Apr 11 15:34:00 volumio systemd[1]: Started Music Player Daemon. Apr 11 15:34:00 volumio sudo[5357]: pam_unix(sudo:session): session closed for user root Apr 11 15:34:00 volumio volumio[2191]: error: updateQueue error: null Apr 11 15:34:03 volumio volumio[2191]: info: VolumeController::SetAlsaVolume100 Apr 11 15:34:03 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:03 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:03 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:03 volumio volumio[2191]: info: CoreCommandRouter::volumioGetQueue Apr 11 15:34:03 volumio volumio[2191]: info: CoreStateMachine::getQueue Apr 11 15:34:03 volumio volumio[2191]: info: CorePlayQueue::getQueue Apr 11 15:34:11 volumio volumio[2191]: info: CoreCommandRouter::volumioPlay Apr 11 15:34:11 volumio volumio[2191]: verbose: UNSET VOLATILE Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::play index 1 Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::stop Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:11 volumio volumio[2191]: verbose: UNSET VOLATILE Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::play index undefined Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:11 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::startPlaybackTimer Apr 11 15:34:11 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:11 volumio volumio[2191]: info: [1712820851823] ControllerUPNPBrowser::clearAddPlayTrack Apr 11 15:34:11 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 15:34:11 volumio volumio[2191]: info: sendMpdCommand stop took 10 milliseconds Apr 11 15:34:11 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 15:34:11 volumio volumio[2191]: info: Apr 11 15:34:11 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:11 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:11 volumio volumio[2191]: info: sendMpdCommand clear took 4 milliseconds Apr 11 15:34:11 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.23.23:50002/m/NDLNA/4559.flac" Apr 11 15:34:11 volumio volumio[2191]: error: updateQueue error: null Apr 11 15:34:11 volumio volumio[2191]: info: ------------------------------ 8ms Apr 11 15:34:11 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.23.23:50002/m/NDLNA/4559.flac" Apr 11 15:34:11 volumio volumio[2191]: info: Apr 11 15:34:11 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:11 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:11 volumio volumio[2191]: info: sendMpdCommand add "http://192.168.23.23:50002/m/NDLNA/4559.flac" took 5 milliseconds Apr 11 15:34:11 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 15:34:11 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand play Apr 11 15:34:11 volumio volumio[2191]: info: ------------------------------ 10ms Apr 11 15:34:11 volumio volumio[2191]: info: sendMpdCommand play took 8 milliseconds Apr 11 15:34:11 volumio volumio[2191]: info: Apr 11 15:34:11 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:11 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:11 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:11 volumio kernel: [SNDCODEC][sunxi_card_hw_params][620]:stream_flag: 0 Apr 11 15:34:12 volumio volumio[2191]: info: Apr 11 15:34:12 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:12 volumio volumio[2191]: info: sendMpdCommand status took 241 milliseconds Apr 11 15:34:12 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:12 volumio volumio[2191]: info: sendMpdCommand status took 25 milliseconds Apr 11 15:34:12 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 22 milliseconds Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:12 volumio volumio[2191]: info: ControllerMpd::pushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::servicePushState Apr 11 15:34:12 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:12 volumio volumio[2191]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4559.flac","artist":null,"album":null,"uri":"http://192.168.23.23:50002/m/NDLNA/4559.flac","trackType":"flac"} Apr 11 15:34:12 volumio volumio[2191]: verbose: CURRENT POSITION 1 Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::syncState stateService play Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::syncState currentStatus stop Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:12 volumio volumio[2191]: info: ------------------------------ 325ms Apr 11 15:34:12 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 11 15:34:12 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:12 volumio volumio[2191]: info: ControllerMpd::pushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::servicePushState Apr 11 15:34:12 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:12 volumio volumio[2191]: verbose: STATE SERVICE {"status":"play","position":0,"seek":868,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"644 Kbps","isStreaming":false,"title":"4559.flac","artist":null,"album":null,"uri":"http://192.168.23.23:50002/m/NDLNA/4559.flac","trackType":"flac"} Apr 11 15:34:12 volumio volumio[2191]: verbose: CURRENT POSITION 1 Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::syncState stateService play Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::syncState currentStatus play Apr 11 15:34:12 volumio volumio[2191]: info: Received an update from plugin. extracting info from payload Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:12 volumio volumio[2191]: info: ------------------------------ 142ms Apr 11 15:34:12 volumio volumio[2191]: info: CoreCommandRouter::volumioGetQueue Apr 11 15:34:12 volumio volumio[2191]: info: CoreStateMachine::getQueue Apr 11 15:34:12 volumio volumio[2191]: info: CorePlayQueue::getQueue Apr 11 15:34:30 volumio volumio[2191]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/ABBA/The%20Visitors%20(Deluxe%20Edition)/0017b12b-dfe8-4078-9871-90fafbef911c.jpg' Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::volumioPlay Apr 11 15:34:33 volumio volumio[2191]: verbose: UNSET VOLATILE Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::play index 2 Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::stop Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:33 volumio volumio[2191]: verbose: UNSET VOLATILE Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::stPlaybackTimer Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::updateTrackBlock Apr 11 15:34:33 volumio volumio[2191]: info: CorePlayQueue::getTrackBlock Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:33 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::serviceStop Apr 11 15:34:33 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::serviceStop Apr 11 15:34:33 volumio volumio[2191]: info: [1712820873325] ControllerUPNPBrowser::stop Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand stop took 234 milliseconds Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::play index undefined Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:33 volumio volumio[2191]: info: CorePlayQueue::getTrack 2 Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::startPlaybackTimer Apr 11 15:34:33 volumio volumio[2191]: info: CorePlayQueue::getTrack 2 Apr 11 15:34:33 volumio volumio[2191]: info: [1712820873564] ControllerUPNPBrowser::clearAddPlayTrack Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 15:34:33 volumio volumio[2191]: info: Apr 11 15:34:33 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:33 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand stop took 9 milliseconds Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 15:34:33 volumio volumio[2191]: info: Apr 11 15:34:33 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:33 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand status took 10 milliseconds Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand clear took 7 milliseconds Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.23.23:50002/m/NDLNA/4561.flac" Apr 11 15:34:33 volumio volumio[2191]: error: updateQueue error: null Apr 11 15:34:33 volumio volumio[2191]: info: ------------------------------ 13ms Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:33 volumio volumio[2191]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 15:34:33 volumio volumio[2191]: info: ------------------------------ 26ms Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.23.23:50002/m/NDLNA/4561.flac" Apr 11 15:34:33 volumio volumio[2191]: info: Apr 11 15:34:33 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:33 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand add "http://192.168.23.23:50002/m/NDLNA/4561.flac" took 3 milliseconds Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand play Apr 11 15:34:33 volumio volumio[2191]: info: ------------------------------ 7ms Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand play took 6 milliseconds Apr 11 15:34:33 volumio volumio[2191]: info: Apr 11 15:34:33 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:33 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:33 volumio kernel: [SNDCODEC][sunxi_card_hw_params][620]:stream_flag: 0 Apr 11 15:34:33 volumio volumio[2191]: info: Apr 11 15:34:33 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand status took 254 milliseconds Apr 11 15:34:33 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:33 volumio volumio[2191]: info: Apr 11 15:34:33 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:33 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand status took 27 milliseconds Apr 11 15:34:33 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:33 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:33 volumio volumio[2191]: info: ControllerMpd::pushState Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::servicePushState Apr 11 15:34:33 volumio volumio[2191]: info: CorePlayQueue::getTrack 2 Apr 11 15:34:33 volumio volumio[2191]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"彩云深处","artist":"李烁","album":null,"uri":"http://192.168.23.23:50002/m/NDLNA/4561.flac","trackType":"flac"} Apr 11 15:34:33 volumio volumio[2191]: verbose: CURRENT POSITION 2 Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::syncState stateService play Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::syncState currentStatus stop Apr 11 15:34:33 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:33 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:33 volumio volumio[2191]: info: ------------------------------ 359ms Apr 11 15:34:34 volumio volumio[2191]: info: ------------------------------ 110ms Apr 11 15:34:34 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 11 15:34:34 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:34 volumio volumio[2191]: info: ControllerMpd::pushState Apr 11 15:34:34 volumio volumio[2191]: info: CoreCommandRouter::servicePushState Apr 11 15:34:34 volumio volumio[2191]: info: CorePlayQueue::getTrack 2 Apr 11 15:34:34 volumio volumio[2191]: verbose: STATE SERVICE {"status":"play","position":0,"seek":868,"duration":230,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"684 Kbps","isStreaming":false,"title":"彩云深处","artist":"李烁","album":null,"uri":"http://192.168.23.23:50002/m/NDLNA/4561.flac","trackType":"flac"} Apr 11 15:34:34 volumio volumio[2191]: verbose: CURRENT POSITION 2 Apr 11 15:34:34 volumio volumio[2191]: info: CoreStateMachine::syncState stateService play Apr 11 15:34:34 volumio volumio[2191]: info: CoreStateMachine::syncState currentStatus play Apr 11 15:34:34 volumio volumio[2191]: info: Received an update from plugin. extracting info from payload Apr 11 15:34:34 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:34 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:34 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:34 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:34 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:34 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:34 volumio volumio[2191]: info: ------------------------------ 208ms Apr 11 15:34:36 volumio volumio[2191]: info: CoreCommandRouter::volumioPlay Apr 11 15:34:36 volumio volumio[2191]: verbose: UNSET VOLATILE Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::play index 1 Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::stop Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:36 volumio volumio[2191]: verbose: UNSET VOLATILE Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::stPlaybackTimer Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::updateTrackBlock Apr 11 15:34:36 volumio volumio[2191]: info: CorePlayQueue::getTrackBlock Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:36 volumio volumio[2191]: info: CorePlayQueue::getTrack 2 Apr 11 15:34:36 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:36 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:36 volumio volumio[2191]: info: CoreStateMachine::serviceStop Apr 11 15:34:36 volumio volumio[2191]: info: CorePlayQueue::getTrack 2 Apr 11 15:34:36 volumio volumio[2191]: info: CoreCommandRouter::serviceStop Apr 11 15:34:36 volumio volumio[2191]: info: [1712820876881] ControllerUPNPBrowser::stop Apr 11 15:34:36 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand stop took 229 milliseconds Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::play index undefined Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 15:34:37 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::startPlaybackTimer Apr 11 15:34:37 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:37 volumio volumio[2191]: info: [1712820877115] ControllerUPNPBrowser::clearAddPlayTrack Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 15:34:37 volumio volumio[2191]: info: Apr 11 15:34:37 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:37 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand stop took 8 milliseconds Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 15:34:37 volumio volumio[2191]: info: Apr 11 15:34:37 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:37 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand status took 9 milliseconds Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand clear took 8 milliseconds Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.23.23:50002/m/NDLNA/4559.flac" Apr 11 15:34:37 volumio volumio[2191]: error: updateQueue error: null Apr 11 15:34:37 volumio volumio[2191]: info: ------------------------------ 27ms Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 23 milliseconds Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.23.23:50002/m/NDLNA/4559.flac" Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:37 volumio volumio[2191]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 15:34:37 volumio volumio[2191]: info: ------------------------------ 43ms Apr 11 15:34:37 volumio volumio[2191]: info: Apr 11 15:34:37 volumio volumio[2191]: ---------------------------- MPD announces system playlist update Apr 11 15:34:37 volumio volumio[2191]: info: Ignoring MPD Status Update Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand add "http://192.168.23.23:50002/m/NDLNA/4559.flac" took 7 milliseconds Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand play Apr 11 15:34:37 volumio volumio[2191]: info: ------------------------------ 7ms Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand play took 5 milliseconds Apr 11 15:34:37 volumio volumio[2191]: info: Apr 11 15:34:37 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:37 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:37 volumio kernel: [SNDCODEC][sunxi_card_hw_params][620]:stream_flag: 0 Apr 11 15:34:37 volumio volumio[2191]: info: Apr 11 15:34:37 volumio volumio[2191]: ---------------------------- MPD announces state update: player Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand status took 246 milliseconds Apr 11 15:34:37 volumio volumio[2191]: info: ControllerMpd::getState Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand status Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand status took 13 milliseconds Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::parseState Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:37 volumio volumio[2191]: info: ControllerMpd::pushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::servicePushState Apr 11 15:34:37 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:37 volumio volumio[2191]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4559.flac","artist":null,"album":null,"uri":"http://192.168.23.23:50002/m/NDLNA/4559.flac","trackType":"flac"} Apr 11 15:34:37 volumio volumio[2191]: verbose: CURRENT POSITION 1 Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::syncState stateService play Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::syncState currentStatus stop Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:37 volumio volumio[2191]: info: ------------------------------ 289ms Apr 11 15:34:37 volumio volumio[2191]: info: sendMpdCommand playlistinfo took 24 milliseconds Apr 11 15:34:37 volumio volumio[2191]: verbose: ControllerMpd::parseTrackInfo Apr 11 15:34:37 volumio volumio[2191]: info: ControllerMpd::pushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::servicePushState Apr 11 15:34:37 volumio volumio[2191]: info: CorePlayQueue::getTrack 1 Apr 11 15:34:37 volumio volumio[2191]: verbose: STATE SERVICE {"status":"play","position":0,"seek":868,"duration":303,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"644 Kbps","isStreaming":false,"title":"4559.flac","artist":null,"album":null,"uri":"http://192.168.23.23:50002/m/NDLNA/4559.flac","trackType":"flac"} Apr 11 15:34:37 volumio volumio[2191]: verbose: CURRENT POSITION 1 Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::syncState stateService play Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::syncState currentStatus play Apr 11 15:34:37 volumio volumio[2191]: info: Received an update from plugin. extracting info from payload Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:37 volumio volumio[2191]: info: CoreStateMachine::pushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::volumioPushState Apr 11 15:34:37 volumio volumio[2191]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 15:34:37 volumio volumio[2191]: info: ------------------------------ 68ms Apr 11 15:34:42 volumio volumio[2191]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 15:34:42 volumio volumio[2191]: { Error: connect ETIMEDOUT 128.121.243.228:443 Apr 11 15:34:42 volumio volumio[2191]: at Object._errnoException (util.js:1022:11) Apr 11 15:34:42 volumio volumio[2191]: at _exceptionWithHostPort (util.js:1044:20) Apr 11 15:34:42 volumio volumio[2191]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1198:14) Apr 11 15:34:42 volumio volumio[2191]: code: 'ETIMEDOUT', Apr 11 15:34:42 volumio volumio[2191]: errno: 'ETIMEDOUT', Apr 11 15:34:42 volumio volumio[2191]: syscall: 'connect', Apr 11 15:34:42 volumio volumio[2191]: address: '128.121.243.228', Apr 11 15:34:42 volumio volumio[2191]: port: 443 } Apr 11 15:34:42 volumio volumio[2191]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 15:34:45 volumio sudo[5503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-11 15:33 Apr 11 15:34:45 volumio sudo[5503]: pam_env(sudo:session): Unable to open env file: /etc/default/locale: No such file or directory Apr 11 15:34:45 volumio sudo[5503]: pam_unix(sudo:session): session opened for user root by (uid=0) NAME="Ubuntu" VERSION="20.04.5 LTS (Focal Fossa)" ID=ubuntu ID_LIKE=debian PRETTY_NAME="Ubuntu 20.04.5 LTS" VERSION_ID="20.04" HOME_URL="https://www.ubuntu.com/" SUPPORT_URL="https://help.ubuntu.com/" BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/" PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy" VERSION_CODENAME=focal UBUNTU_CODENAME=focal