-- 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