-- Logs begin at Tue 2025-05-13 11:26:18 CST, end at Tue 2025-05-13 11:39:51 CST. -- May 13 11:38:22 volumio volumio[1055]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 13 11:38:22 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 13 11:38:22 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 13 11:38:22 volumio sudo[5250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 11:38:23 volumio sudo[5250]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:38:23 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:38:23 volumio sudo[5253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 11:38:23 volumio sudo[5253]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:38:23 volumio sudo[5250]: pam_unix(sudo:session): session closed for user root May 13 11:38:23 volumio systemd[1]: Stopping Music Player Daemon... May 13 11:38:23 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 11:38:23 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 11:38:23 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:38:23 volumio volumio[1055]: info: MPD Permissions set May 13 11:38:23 volumio systemd[1]: mpd.service: Succeeded. May 13 11:38:23 volumio systemd[1]: Stopped Music Player Daemon. May 13 11:38:23 volumio systemd[1]: Starting Music Player Daemon... May 13 11:38:23 volumio sudo[5261]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 11:38:23 volumio sudo[5261]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:38:23 volumio sudo[5261]: pam_unix(sudo:session): session closed for user root May 13 11:38:24 volumio mpd[5263]: May 13 11:38 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 11:38:24 volumio systemd[1]: Started Music Player Daemon. May 13 11:38:24 volumio sudo[5253]: pam_unix(sudo:session): session closed for user root May 13 11:38:24 volumio volumio[1055]: error: updateQueue error: null May 13 11:38:27 volumio volumio[1055]: info: CorePlayQueue::getTrack 0 May 13 11:38:27 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:27 volumio volumio[1055]: info: Prefetching next song May 13 11:38:27 volumio volumio[1055]: info: DOING PREFETCH IN MPD May 13 11:38:27 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf" May 13 11:38:27 volumio volumio[1055]: info: May 13 11:38:27 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:38:27 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:38:27 volumio volumio[1055]: info: sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf" took 1 milliseconds May 13 11:38:27 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand consume 1 May 13 11:38:27 volumio volumio[1055]: info: May 13 11:38:27 volumio volumio[1055]: ---------------------------- MPD announces state update: options May 13 11:38:27 volumio volumio[1055]: info: ------------------------------ 2ms May 13 11:38:27 volumio volumio[1055]: info: sendMpdCommand consume 1 took 2 milliseconds May 13 11:38:27 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:38:27 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:38:27 volumio volumio[1055]: info: sendMpdCommand status took 13 milliseconds May 13 11:38:27 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:38:27 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:38:27 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:38:27 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:27 volumio volumio[1055]: info: CorePlayQueue::getTrack 0 May 13 11:38:27 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:27 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:27 volumio volumio[1055]: info: CorePlayQueue::getTrack 0 May 13 11:38:27 volumio volumio[1055]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 13 11:38:27 volumio volumio[1055]: verbose: CURRENT POSITION 0 May 13 11:38:27 volumio volumio[1055]: info: CoreStateMachine::syncState stateService stop May 13 11:38:27 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus play May 13 11:38:27 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:27 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:27 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:27 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:27 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:27 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:27 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:27 volumio volumio[1055]: info: ------------------------------ 45ms May 13 11:38:32 volumio volumio[1055]: info: CoreCommandRouter::volumioPlay May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::play index undefined May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 11:38:32 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::startPlaybackTimer May 13 11:38:32 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::clearAddPlayTracks USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand stop May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand stop took 2 milliseconds May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand clear May 13 11:38:32 volumio volumio[1055]: info: May 13 11:38:32 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:38:32 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand clear took 4 milliseconds May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf" May 13 11:38:32 volumio volumio[1055]: error: updateQueue error: null May 13 11:38:32 volumio volumio[1055]: info: May 13 11:38:32 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:38:32 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:38:32 volumio volumio[1055]: info: ------------------------------ 6ms May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf" took 4 milliseconds May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand play May 13 11:38:32 volumio volumio[1055]: info: ------------------------------ 5ms May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand play took 4 milliseconds May 13 11:38:32 volumio volumio[1055]: info: May 13 11:38:32 volumio volumio[1055]: ---------------------------- MPD announces state update: player May 13 11:38:32 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:38:32 volumio volumio[1055]: info: May 13 11:38:32 volumio volumio[1055]: ---------------------------- MPD announces state update: player May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand status took 23 milliseconds May 13 11:38:32 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand status took 2 milliseconds May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand playlistinfo took 2 milliseconds May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::parseTrackInfo May 13 11:38:32 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:38:32 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:38:32 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:32 volumio volumio[1055]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":182,"samplerate":"22.58 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Sun is gonna shine again","artist":"Carmen Gomes Inc.","album":"Ray!","uri":"USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf","trackType":"dsf"} May 13 11:38:32 volumio volumio[1055]: verbose: CURRENT POSITION 1 May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::syncState stateService play May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus stop May 13 11:38:32 volumio volumio[1055]: info: ------------------------------ 30ms May 13 11:38:32 volumio volumio[1055]: info: sendMpdCommand playlistinfo took 4 milliseconds May 13 11:38:32 volumio volumio[1055]: verbose: ControllerMpd::parseTrackInfo May 13 11:38:32 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:38:32 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:38:32 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:32 volumio volumio[1055]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":182,"samplerate":"22.58 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Sun is gonna shine again","artist":"Carmen Gomes Inc.","album":"Ray!","uri":"USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/02. The Sun is gonna shine again DSD 512fs - 2ch.dsf","trackType":"dsf"} May 13 11:38:32 volumio volumio[1055]: verbose: CURRENT POSITION 1 May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::syncState stateService play May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus play May 13 11:38:32 volumio volumio[1055]: info: Received an update from plugin. extracting info from payload May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:32 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:32 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:32 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:32 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:32 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:32 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:32 volumio volumio[1055]: info: ------------------------------ 38ms May 13 11:38:36 volumio volumio[1055]: info: VolumeController::SetAlsaVolume84 May 13 11:38:36 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:36 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:36 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:36 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:37 volumio volumio[1055]: info: VolumeController::SetAlsaVolume98 May 13 11:38:37 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:37 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:37 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:37 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:38 volumio volumio[1055]: info: VolumeController::SetAlsaVolume7 May 13 11:38:38 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:38 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:38 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:38 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:38:40 volumio volumio[1055]: info: VolumeController::SetAlsaVolume97 May 13 11:38:40 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:38:40 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:38:40 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:38:40 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:02 volumio volumio[1055]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 13 11:39:02 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 13 11:39:02 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 13 11:39:02 volumio sudo[5387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 11:39:02 volumio sudo[5387]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:39:02 volumio sudo[5387]: pam_unix(sudo:session): session closed for user root May 13 11:39:02 volumio sudo[5390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 11:39:02 volumio sudo[5390]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:39:02 volumio systemd[1]: Stopping Music Player Daemon... May 13 11:39:02 volumio volumio[1055]: info: MPD Permissions set May 13 11:39:02 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:02 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 11:39:02 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 11:39:02 volumio systemd[1]: mpd.service: Succeeded. May 13 11:39:02 volumio systemd[1]: Stopped Music Player Daemon. May 13 11:39:02 volumio systemd[1]: Starting Music Player Daemon... May 13 11:39:02 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:02 volumio sudo[5396]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 11:39:02 volumio sudo[5396]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:39:02 volumio sudo[5396]: pam_unix(sudo:session): session closed for user root May 13 11:39:04 volumio mpd[5400]: May 13 11:39 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 11:39:04 volumio systemd[1]: Started Music Player Daemon. May 13 11:39:04 volumio sudo[5390]: pam_unix(sudo:session): session closed for user root May 13 11:39:04 volumio volumio[1055]: error: updateQueue error: null May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::volumioNext May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::next May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::stop May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::stPlaybackTimer May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::updateTrackBlock May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrackBlock May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::serviceStop May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 1 May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::serviceStop May 13 11:39:09 volumio volumio[1055]: info: ControllerMpd::stop May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand stop May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand stop took 9 milliseconds May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::play index undefined May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::startPlaybackTimer May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::clearAddPlayTracks USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/03. CC Rider DSD 512fs - 2ch.dsf May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand stop May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::updateTrackBlock May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrackBlock May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand stop took 3 milliseconds May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand clear May 13 11:39:09 volumio volumio[1055]: info: May 13 11:39:09 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:39:09 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand clear took 6 milliseconds May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/03. CC Rider DSD 512fs - 2ch.dsf" May 13 11:39:09 volumio volumio[1055]: error: updateQueue error: null May 13 11:39:09 volumio volumio[1055]: info: May 13 11:39:09 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:39:09 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:39:09 volumio volumio[1055]: info: ------------------------------ 7ms May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/03. CC Rider DSD 512fs - 2ch.dsf" took 4 milliseconds May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand play May 13 11:39:09 volumio volumio[1055]: info: ------------------------------ 4ms May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand play took 4 milliseconds May 13 11:39:09 volumio volumio[1055]: info: May 13 11:39:09 volumio volumio[1055]: ---------------------------- MPD announces state update: player May 13 11:39:09 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:39:09 volumio volumio[1055]: info: May 13 11:39:09 volumio volumio[1055]: ---------------------------- MPD announces state update: player May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand status took 37 milliseconds May 13 11:39:09 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand status took 4 milliseconds May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand playlistinfo took 5 milliseconds May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::parseTrackInfo May 13 11:39:09 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:09 volumio volumio[1055]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":309,"samplerate":"22.58 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CC Rider","artist":"Carmen Gomes Inc.","album":"Ray!","uri":"USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/03. CC Rider DSD 512fs - 2ch.dsf","trackType":"dsf"} May 13 11:39:09 volumio volumio[1055]: verbose: CURRENT POSITION 2 May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::syncState stateService play May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus stop May 13 11:39:09 volumio volumio[1055]: info: ------------------------------ 52ms May 13 11:39:09 volumio volumio[1055]: info: sendMpdCommand playlistinfo took 8 milliseconds May 13 11:39:09 volumio volumio[1055]: verbose: ControllerMpd::parseTrackInfo May 13 11:39:09 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:09 volumio volumio[1055]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":309,"samplerate":"22.58 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CC Rider","artist":"Carmen Gomes Inc.","album":"Ray!","uri":"USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/03. CC Rider DSD 512fs - 2ch.dsf","trackType":"dsf"} May 13 11:39:09 volumio volumio[1055]: verbose: CURRENT POSITION 2 May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::syncState stateService play May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus play May 13 11:39:09 volumio volumio[1055]: info: Received an update from plugin. extracting info from payload May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:09 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:09 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:09 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:09 volumio volumio[1055]: info: ------------------------------ 50ms May 13 11:39:14 volumio kernel: sd 1:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#0 Sense Key : Aborted Command [current] May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#0 Add. Sense: Data phase CRC error detected May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 0f 6b 0f d0 00 01 00 00 May 13 11:39:15 volumio kernel: I/O error, dev sdb, sector 258674640 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#1 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#1 Sense Key : Aborted Command [current] May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#1 Add. Sense: Data phase CRC error detected May 13 11:39:15 volumio kernel: sd 1:0:0:0: [sdb] tag#1 CDB: Read(10) 28 00 0f 6b 10 d0 00 01 00 00 May 13 11:39:15 volumio kernel: I/O error, dev sdb, sector 258674896 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:16 volumio kernel: sd 1:0:0:0: [sdb] tag#16 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:16 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Sense Key : Aborted Command [current] May 13 11:39:16 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Add. Sense: Data phase CRC error detected May 13 11:39:16 volumio kernel: sd 1:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 0f 83 72 00 00 00 50 00 May 13 11:39:16 volumio kernel: I/O error, dev sdb, sector 260272640 op 0x0:(READ) flags 0x80700 phys_seg 10 prio class 2 May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#16 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Sense Key : Aborted Command [current] May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Add. Sense: Data phase CRC error detected May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 0f 83 72 50 00 01 00 00 May 13 11:39:17 volumio kernel: I/O error, dev sdb, sector 260272720 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#17 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Sense Key : Aborted Command [current] May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Add. Sense: Data phase CRC error detected May 13 11:39:17 volumio kernel: sd 1:0:0:0: [sdb] tag#17 CDB: Read(10) 28 00 0f 83 76 50 00 01 00 00 May 13 11:39:17 volumio kernel: I/O error, dev sdb, sector 260273744 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#18 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#18 Sense Key : Aborted Command [current] May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#18 Add. Sense: Data phase CRC error detected May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#18 CDB: Read(10) 28 00 0f 83 78 50 00 01 00 00 May 13 11:39:18 volumio kernel: I/O error, dev sdb, sector 260274256 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#16 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Sense Key : Aborted Command [current] May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Add. Sense: Data phase CRC error detected May 13 11:39:18 volumio kernel: sd 1:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 0f 83 7d 50 00 01 00 00 May 13 11:39:18 volumio kernel: I/O error, dev sdb, sector 260275536 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#17 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Sense Key : Aborted Command [current] May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Add. Sense: Data phase CRC error detected May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#17 CDB: Read(10) 28 00 0f 83 7f 50 00 01 00 00 May 13 11:39:19 volumio kernel: I/O error, dev sdb, sector 260276048 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#16 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Sense Key : Aborted Command [current] May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Add. Sense: Data phase CRC error detected May 13 11:39:19 volumio kernel: sd 1:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 0f 83 82 50 00 01 00 00 May 13 11:39:19 volumio kernel: I/O error, dev sdb, sector 260276816 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#17 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Sense Key : Aborted Command [current] May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Add. Sense: Data phase CRC error detected May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#17 CDB: Read(10) 28 00 0f 83 83 50 00 01 00 00 May 13 11:39:20 volumio kernel: I/O error, dev sdb, sector 260277072 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#16 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Sense Key : Aborted Command [current] May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Add. Sense: Data phase CRC error detected May 13 11:39:20 volumio kernel: sd 1:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 0f 83 84 50 00 01 00 00 May 13 11:39:20 volumio kernel: I/O error, dev sdb, sector 260277328 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:21 volumio kernel: sd 1:0:0:0: [sdb] tag#19 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:21 volumio kernel: sd 1:0:0:0: [sdb] tag#19 Sense Key : Aborted Command [current] May 13 11:39:21 volumio kernel: sd 1:0:0:0: [sdb] tag#19 Add. Sense: Data phase CRC error detected May 13 11:39:21 volumio kernel: sd 1:0:0:0: [sdb] tag#19 CDB: Read(10) 28 00 0f 83 89 50 00 01 00 00 May 13 11:39:21 volumio kernel: I/O error, dev sdb, sector 260278608 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#17 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Sense Key : Aborted Command [current] May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Add. Sense: Data phase CRC error detected May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#17 CDB: Read(10) 28 00 0f 83 8d 50 00 01 00 00 May 13 11:39:22 volumio kernel: I/O error, dev sdb, sector 260279632 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#18 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#18 Sense Key : Aborted Command [current] May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#18 Add. Sense: Data phase CRC error detected May 13 11:39:22 volumio kernel: sd 1:0:0:0: [sdb] tag#18 CDB: Read(10) 28 00 0f 83 8e 50 00 01 00 00 May 13 11:39:22 volumio kernel: I/O error, dev sdb, sector 260279888 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 Sense Key : Aborted Command [current] May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 Add. Sense: Data phase CRC error detected May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 CDB: Read(10) 28 00 0f 83 97 50 00 01 00 00 May 13 11:39:23 volumio kernel: I/O error, dev sdb, sector 260282192 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 Sense Key : Aborted Command [current] May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 Add. Sense: Data phase CRC error detected May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#19 CDB: Read(10) 28 00 0f 85 be 50 00 01 00 00 May 13 11:39:23 volumio kernel: I/O error, dev sdb, sector 260423248 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#16 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Sense Key : Aborted Command [current] May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#16 Add. Sense: Data phase CRC error detected May 13 11:39:23 volumio kernel: sd 1:0:0:0: [sdb] tag#16 CDB: Read(10) 28 00 0f 85 bf 50 00 01 00 00 May 13 11:39:23 volumio kernel: I/O error, dev sdb, sector 260423504 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:24 volumio kernel: sd 1:0:0:0: [sdb] tag#18 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:24 volumio kernel: sd 1:0:0:0: [sdb] tag#18 Sense Key : Aborted Command [current] May 13 11:39:24 volumio kernel: sd 1:0:0:0: [sdb] tag#18 Add. Sense: Data phase CRC error detected May 13 11:39:24 volumio kernel: sd 1:0:0:0: [sdb] tag#18 CDB: Read(10) 28 00 0f 85 c0 50 00 01 00 00 May 13 11:39:24 volumio kernel: I/O error, dev sdb, sector 260423760 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#20 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Sense Key : Aborted Command [current] May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Add. Sense: Data phase CRC error detected May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#20 CDB: Read(10) 28 00 0f 85 c2 50 00 01 00 00 May 13 11:39:25 volumio kernel: I/O error, dev sdb, sector 260424272 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#17 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Sense Key : Aborted Command [current] May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#17 Add. Sense: Data phase CRC error detected May 13 11:39:25 volumio kernel: sd 1:0:0:0: [sdb] tag#17 CDB: Read(10) 28 00 0f 91 ce d0 00 01 00 00 May 13 11:39:25 volumio kernel: I/O error, dev sdb, sector 261213904 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:25 volumio volumio[1055]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 13 11:39:25 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 13 11:39:25 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 13 11:39:26 volumio sudo[5487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 11:39:26 volumio sudo[5487]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:39:26 volumio sudo[5487]: pam_unix(sudo:session): session closed for user root May 13 11:39:26 volumio sudo[5490]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 11:39:26 volumio sudo[5490]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:39:26 volumio systemd[1]: Stopping Music Player Daemon... May 13 11:39:26 volumio volumio[1055]: info: MPD Permissions set May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 11:39:26 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 11:39:26 volumio systemd[1]: mpd.service: Succeeded. May 13 11:39:26 volumio systemd[1]: Stopped Music Player Daemon. May 13 11:39:26 volumio systemd[1]: Starting Music Player Daemon... May 13 11:39:26 volumio sudo[5498]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 11:39:26 volumio sudo[5498]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:39:26 volumio sudo[5498]: pam_unix(sudo:session): session closed for user root May 13 11:39:27 volumio mpd[5500]: May 13 11:39 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 11:39:27 volumio systemd[1]: Started Music Player Daemon. May 13 11:39:27 volumio sudo[5490]: pam_unix(sudo:session): session closed for user root May 13 11:39:27 volumio volumio[1055]: error: updateQueue error: null May 13 11:39:34 volumio volumio[1055]: info: CoreCommandRouter::volumioPrevious May 13 11:39:34 volumio volumio[1055]: info: CoreStateMachine::previous May 13 11:39:34 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:34 volumio volumio[1055]: info: ControllerMpd::seek May 13 11:39:34 volumio volumio[1055]: error: [2@0] {seek} Bad song index May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::volumioNext May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::next May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::stop May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::stPlaybackTimer May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::updateTrackBlock May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrackBlock May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::serviceStop May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 2 May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::serviceStop May 13 11:39:41 volumio volumio[1055]: info: ControllerMpd::stop May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand stop May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand stop took 27 milliseconds May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::play index undefined May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::setConsumeUpdateService undefined May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::startPlaybackTimer May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::clearAddPlayTracks USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/04. Let the good times roll DSD 512fs - 2ch.dsf May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand stop May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::updateTrackBlock May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrackBlock May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand stop took 3 milliseconds May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand clear May 13 11:39:41 volumio volumio[1055]: info: May 13 11:39:41 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:39:41 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand clear took 3 milliseconds May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/04. Let the good times roll DSD 512fs - 2ch.dsf" May 13 11:39:41 volumio volumio[1055]: error: updateQueue error: null May 13 11:39:41 volumio volumio[1055]: info: May 13 11:39:41 volumio volumio[1055]: ---------------------------- MPD announces system playlist update May 13 11:39:41 volumio volumio[1055]: info: Ignoring MPD Status Update May 13 11:39:41 volumio volumio[1055]: info: ------------------------------ 11ms May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand add "USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/04. Let the good times roll DSD 512fs - 2ch.dsf" took 6 milliseconds May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand play May 13 11:39:41 volumio volumio[1055]: info: ------------------------------ 8ms May 13 11:39:41 volumio volumio[1055]: info: May 13 11:39:41 volumio volumio[1055]: ---------------------------- MPD announces state update: player May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand play took 26 milliseconds May 13 11:39:41 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:39:41 volumio volumio[1055]: info: May 13 11:39:41 volumio volumio[1055]: ---------------------------- MPD announces state update: player May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand status took 12 milliseconds May 13 11:39:41 volumio volumio[1055]: info: ControllerMpd::getState May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand status May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand status took 6 milliseconds May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand playlistinfo took 6 milliseconds May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::parseState May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::parseTrackInfo May 13 11:39:41 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:41 volumio volumio[1055]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"22.58 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Let the good times roll","artist":"Carmen Gomes Inc.","album":"Ray!","uri":"USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/04. Let the good times roll DSD 512fs - 2ch.dsf","trackType":"dsf"} May 13 11:39:41 volumio volumio[1055]: verbose: CURRENT POSITION 3 May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::syncState stateService play May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus stop May 13 11:39:41 volumio volumio[1055]: info: ------------------------------ 25ms May 13 11:39:41 volumio volumio[1055]: info: sendMpdCommand playlistinfo took 7 milliseconds May 13 11:39:41 volumio volumio[1055]: verbose: ControllerMpd::parseTrackInfo May 13 11:39:41 volumio volumio[1055]: info: ControllerMpd::pushState May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::servicePushState May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:41 volumio volumio[1055]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"22.58 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Let the good times roll","artist":"Carmen Gomes Inc.","album":"Ray!","uri":"USB/F094BBF894BBBF80/SONY 爵士/[Native]Carmen Gomes Inc.-Ray!-2021[DSD512]/DSD 512fs - 2ch/04. Let the good times roll DSD 512fs - 2ch.dsf","trackType":"dsf"} May 13 11:39:41 volumio volumio[1055]: verbose: CURRENT POSITION 3 May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::syncState stateService play May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::syncState currentStatus play May 13 11:39:41 volumio volumio[1055]: info: Received an update from plugin. extracting info from payload May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:41 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:41 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:41 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:41 volumio volumio[1055]: info: ------------------------------ 43ms May 13 11:39:41 volumio kernel: sd 1:0:0:0: [sdb] tag#22 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:41 volumio kernel: sd 1:0:0:0: [sdb] tag#22 Sense Key : Aborted Command [current] May 13 11:39:41 volumio kernel: sd 1:0:0:0: [sdb] tag#22 Add. Sense: Data phase CRC error detected May 13 11:39:41 volumio kernel: sd 1:0:0:0: [sdb] tag#22 CDB: Read(10) 28 00 0e e8 07 f0 00 01 00 00 May 13 11:39:41 volumio kernel: I/O error, dev sdb, sector 250087408 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:42 volumio kernel: sd 1:0:0:0: [sdb] tag#23 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:42 volumio kernel: sd 1:0:0:0: [sdb] tag#23 Sense Key : Aborted Command [current] May 13 11:39:42 volumio kernel: sd 1:0:0:0: [sdb] tag#23 Add. Sense: Data phase CRC error detected May 13 11:39:42 volumio kernel: sd 1:0:0:0: [sdb] tag#23 CDB: Read(10) 28 00 0e e8 09 f0 00 01 00 00 May 13 11:39:42 volumio kernel: I/O error, dev sdb, sector 250087920 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:42 volumio ntpd[1644]: 193.182.111.143 local addr 192.168.2.106 -> May 13 11:39:43 volumio kernel: sd 1:0:0:0: [sdb] Unaligned partial completion (resid=41280, sector_sz=512) May 13 11:39:43 volumio kernel: sd 1:0:0:0: [sdb] tag#20 CDB: Read(10) 28 00 0e e8 0a f0 00 01 00 00 May 13 11:39:43 volumio kernel: sd 1:0:0:0: [sdb] tag#20 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:43 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Sense Key : Aborted Command [current] May 13 11:39:43 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Add. Sense: Data phase CRC error detected May 13 11:39:43 volumio kernel: sd 1:0:0:0: [sdb] tag#20 CDB: Read(10) 28 00 0e e8 0a f0 00 01 00 00 May 13 11:39:43 volumio kernel: I/O error, dev sdb, sector 250088176 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#20 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Sense Key : Aborted Command [current] May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Add. Sense: Data phase CRC error detected May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#20 CDB: Read(10) 28 00 0e e8 0e f0 00 01 00 00 May 13 11:39:44 volumio kernel: I/O error, dev sdb, sector 250089200 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#21 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#21 Sense Key : Aborted Command [current] May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#21 Add. Sense: Data phase CRC error detected May 13 11:39:44 volumio kernel: sd 1:0:0:0: [sdb] tag#21 CDB: Read(10) 28 00 0e e8 0f f0 00 01 00 00 May 13 11:39:44 volumio kernel: I/O error, dev sdb, sector 250089456 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:45 volumio kernel: sd 1:0:0:0: [sdb] tag#23 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:45 volumio kernel: sd 1:0:0:0: [sdb] tag#23 Sense Key : Aborted Command [current] May 13 11:39:45 volumio kernel: sd 1:0:0:0: [sdb] tag#23 Add. Sense: Data phase CRC error detected May 13 11:39:45 volumio kernel: sd 1:0:0:0: [sdb] tag#23 CDB: Read(10) 28 00 0e e8 10 f0 00 01 00 00 May 13 11:39:45 volumio kernel: I/O error, dev sdb, sector 250089712 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] Unaligned partial completion (resid=41288, sector_sz=512) May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#20 CDB: Read(10) 28 00 0e e8 14 f0 00 01 00 00 May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#20 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Sense Key : Aborted Command [current] May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#20 Add. Sense: Data phase CRC error detected May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#20 CDB: Read(10) 28 00 0e e8 14 f0 00 01 00 00 May 13 11:39:48 volumio kernel: I/O error, dev sdb, sector 250090736 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#21 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#21 Sense Key : Aborted Command [current] May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#21 Add. Sense: Data phase CRC error detected May 13 11:39:48 volumio kernel: sd 1:0:0:0: [sdb] tag#21 CDB: Read(10) 28 00 0e e8 15 f0 00 01 00 00 May 13 11:39:48 volumio kernel: I/O error, dev sdb, sector 250090992 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:49 volumio kernel: sd 1:0:0:0: [sdb] tag#21 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s May 13 11:39:49 volumio kernel: sd 1:0:0:0: [sdb] tag#21 Sense Key : Aborted Command [current] May 13 11:39:49 volumio kernel: sd 1:0:0:0: [sdb] tag#21 Add. Sense: Data phase CRC error detected May 13 11:39:49 volumio kernel: sd 1:0:0:0: [sdb] tag#21 CDB: Read(10) 28 00 0e e8 16 f0 00 01 00 00 May 13 11:39:49 volumio kernel: I/O error, dev sdb, sector 250091248 op 0x0:(READ) flags 0x80700 phys_seg 32 prio class 2 May 13 11:39:50 volumio volumio[1055]: info: VolumeController::SetAlsaVolume69 May 13 11:39:50 volumio volumio[1055]: info: CoreStateMachine::pushState May 13 11:39:50 volumio volumio[1055]: info: CorePlayQueue::getTrack 3 May 13 11:39:50 volumio volumio[1055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:39:50 volumio volumio[1055]: info: CoreCommandRouter::volumioPushState May 13 11:39:50 volumio volumio[1055]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 11:39:50 volumio volumio[1055]: Error: connect ETIMEDOUT 104.31.142.88:443 May 13 11:39:50 volumio volumio[1055]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { May 13 11:39:50 volumio volumio[1055]: errno: -110, May 13 11:39:50 volumio volumio[1055]: code: 'ETIMEDOUT', May 13 11:39:50 volumio volumio[1055]: syscall: 'connect', May 13 11:39:50 volumio volumio[1055]: address: '104.31.142.88', May 13 11:39:50 volumio volumio[1055]: port: 443 May 13 11:39:50 volumio volumio[1055]: } May 13 11:39:50 volumio volumio[1055]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 11:39:51 volumio sudo[5553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 11:38 May 13 11:39:51 volumio sudo[5553]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 12:21:23 PM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="a9588e47e4b05f1a05bf70b4acc7555c"