-- Logs begin at Thu 2019-02-14 12:11:58 EET, end at Sat 2025-05-17 20:07:24 EEST. -- May 17 20:06:03 volumio2 volumio[960]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 17 20:06:03 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 17 20:06:03 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 17 20:06:03 volumio2 sudo[5267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 20:06:03 volumio2 sudo[5267]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 20:06:03 volumio2 sudo[5267]: pam_unix(sudo:session): session closed for user root May 17 20:06:03 volumio2 volumio[960]: info: MPD Permissions set May 17 20:06:03 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 20:06:03 volumio2 sudo[5271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 20:06:03 volumio2 sudo[5271]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 20:06:03 volumio2 systemd[1]: Stopping Music Player Daemon... May 17 20:06:03 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 20:06:03 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 20:06:03 volumio2 volumio[960]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 20:06:03 volumio2 systemd[1]: mpd.service: Succeeded. May 17 20:06:03 volumio2 volumio[960]: info: CoreCommandRouter::volumioGetState May 17 20:06:03 volumio2 systemd[1]: Stopped Music Player Daemon. May 17 20:06:03 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:06:03 volumio2 volumio[960]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 20:06:03 volumio2 systemd[1]: Starting Music Player Daemon... May 17 20:06:03 volumio2 volumio[960]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 20:06:03 volumio2 sudo[5277]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 20:06:03 volumio2 sudo[5277]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 20:06:03 volumio2 sudo[5277]: pam_unix(sudo:session): session closed for user root May 17 20:06:04 volumio2 mpd[5279]: May 17 20:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 17 20:06:04 volumio2 systemd[1]: Started Music Player Daemon. May 17 20:06:04 volumio2 sudo[5271]: pam_unix(sudo:session): session closed for user root May 17 20:06:04 volumio2 volumio[960]: error: updateQueue error: null May 17 20:06:55 volumio2 volumio[960]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] May 17 20:06:55 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts May 17 20:06:55 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions May 17 20:06:55 volumio2 sudo[5403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 17 20:06:55 volumio2 sudo[5403]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 20:06:55 volumio2 sudo[5403]: pam_unix(sudo:session): session closed for user root May 17 20:06:55 volumio2 volumio[960]: info: MPD Permissions set May 17 20:06:55 volumio2 sudo[5406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 17 20:06:55 volumio2 sudo[5406]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 20:06:55 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 20:06:55 volumio2 systemd[1]: Stopping Music Player Daemon... May 17 20:06:55 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 17 20:06:55 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 17 20:06:55 volumio2 systemd[1]: mpd.service: Succeeded. May 17 20:06:55 volumio2 volumio[960]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 20:06:55 volumio2 systemd[1]: Stopped Music Player Daemon. May 17 20:06:55 volumio2 volumio[960]: info: CoreCommandRouter::volumioGetState May 17 20:06:55 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:06:55 volumio2 volumio[960]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 17 20:06:55 volumio2 systemd[1]: Starting Music Player Daemon... May 17 20:06:55 volumio2 volumio[960]: ------------------------------------ BT MESSAGE: BT STATUS: running May 17 20:06:55 volumio2 sudo[5413]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 17 20:06:55 volumio2 sudo[5413]: pam_unix(sudo:session): session opened for user root by (uid=0) May 17 20:06:55 volumio2 sudo[5413]: pam_unix(sudo:session): session closed for user root May 17 20:06:56 volumio2 mpd[5415]: May 17 20:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 17 20:06:56 volumio2 systemd[1]: Started Music Player Daemon. May 17 20:06:56 volumio2 sudo[5406]: pam_unix(sudo:session): session closed for user root May 17 20:06:56 volumio2 volumio[960]: error: updateQueue error: null May 17 20:07:04 volumio2 volumio[960]: info: CoreCommandRouter::volumioPlay May 17 20:07:04 volumio2 volumio[960]: info: CoreStateMachine::play index undefined May 17 20:07:04 volumio2 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 17 20:07:04 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:04 volumio2 volumio[960]: info: CoreStateMachine::startPlaybackTimer May 17 20:07:04 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:04 volumio2 volumio[960]: info: CoreCommandRouter::volumioGetVisibleSources May 17 20:07:04 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 17 20:07:04 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 17 20:07:04 volumio2 volumio[960]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio May 17 20:07:04 volumio2 volumio[960]: info: ControllerMpd::resume May 17 20:07:04 volumio2 volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 17 20:07:04 volumio2 volumio[960]: info: sendMpdCommand play took 0 milliseconds May 17 20:07:04 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:04 volumio2 volumio[960]: info: CorePlayQueue::getTrack 4 May 17 20:07:06 volumio2 volumio[960]: info: CoreCommandRouter::volumioPlay May 17 20:07:06 volumio2 volumio[960]: info: CoreStateMachine::play index undefined May 17 20:07:06 volumio2 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 17 20:07:06 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:06 volumio2 volumio[960]: info: CoreStateMachine::startPlaybackTimer May 17 20:07:06 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:06 volumio2 volumio[960]: info: CoreCommandRouter::volumioGetVisibleSources May 17 20:07:06 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 17 20:07:06 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 17 20:07:06 volumio2 volumio[960]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio May 17 20:07:06 volumio2 volumio[960]: info: ControllerMpd::resume May 17 20:07:06 volumio2 volumio[960]: verbose: ControllerMpd::sendMpdCommand play May 17 20:07:06 volumio2 volumio[960]: info: sendMpdCommand play took 0 milliseconds May 17 20:07:21 volumio2 volumio[960]: info: Preload queue cleared May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::volumioReplaceandPlayItems May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::ClearQueue May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::stop May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::updateTrackBlock May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::getTrackBlock May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::stPlaybackTimer May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::pushState May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::volumioPushState May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::volumioGetState May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::serviceStop May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::serviceStop May 17 20:07:21 volumio2 volumio[960]: info: ControllerMpd::stop May 17 20:07:21 volumio2 volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::clearPlayQueue May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::saveQueue May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::volumioPushQueue May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::addQueueItems May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::addQueueItems May 17 20:07:21 volumio2 volumio[960]: info: Preload queue cleared May 17 20:07:21 volumio2 volumio[960]: info: Adding Item to queue: music-library/USB/RECOVERY/11k2_44k1.wav May 17 20:07:21 volumio2 volumio[960]: info: Exploding uri music-library/USB/RECOVERY/11k2_44k1.wav in service mpd May 17 20:07:21 volumio2 volumio[960]: info: Adding Item to queue: music-library/USB/RECOVERY/12 Sinfonie Nr. 9 d-Moll, op. 125- IVg. – Poco allegro, stringendo il tempo, sempre più allegro – Prestissimo – Maestoso – Prestissimo.wav May 17 20:07:21 volumio2 volumio[960]: info: Exploding uri music-library/USB/RECOVERY/12 Sinfonie Nr. 9 d-Moll, op. 125- IVg. – Poco allegro, stringendo il tempo, sempre più allegro – Prestissimo – Maestoso – Prestissimo.wav in service mpd May 17 20:07:21 volumio2 volumio[960]: info: Adding Item to queue: music-library/USB/RECOVERY/12k_48k.wav May 17 20:07:21 volumio2 volumio[960]: info: Exploding uri music-library/USB/RECOVERY/12k_48k.wav in service mpd May 17 20:07:21 volumio2 volumio[960]: info: Adding Item to queue: music-library/USB/RECOVERY/997Hz_44k1.wav May 17 20:07:21 volumio2 volumio[960]: info: Exploding uri music-library/USB/RECOVERY/997Hz_44k1.wav in service mpd May 17 20:07:21 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2F11k2_44k1.wav&metadata=false May 17 20:07:21 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/11k2_44k1.wav May 17 20:07:21 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2F12%20Sinfonie%20Nr.%209%20d-Moll%2C%20op.%20125-%20IVg.%20%E2%80%93%20Poco%20allegro%2C%20stringendo%20il%20tempo%2C%20sempre%20pi%C3%B9%20allegro%20%E2%80%93%20Prestissimo%20%E2%80%93%20Maestoso%20%E2%80%93%20Prestissimo.wav&metadata=false May 17 20:07:21 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/12 Sinfonie Nr. 9 d-Moll, op. 125- IVg. – Poco allegro, stringendo il tempo, sempre più allegro – Prestissimo – Maestoso – Prestissimo.wav May 17 20:07:21 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2F12k_48k.wav&metadata=false May 17 20:07:21 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/12k_48k.wav May 17 20:07:21 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2F997Hz_44k1.wav&metadata=false May 17 20:07:21 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/997Hz_44k1.wav May 17 20:07:21 volumio2 volumio[960]: info: sendMpdCommand stop took 28 milliseconds May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::volumioPushQueue May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::saveQueue May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::updateTrackBlock May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::getTrackBlock May 17 20:07:21 volumio2 volumio[960]: info: CoreCommandRouter::volumioPlay May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::play index 3 May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 17 20:07:21 volumio2 volumio[960]: info: CoreStateMachine::addQueueItems May 17 20:07:21 volumio2 volumio[960]: info: CorePlayQueue::addQueueItems May 17 20:07:21 volumio2 volumio[960]: info: Preload queue cleared May 17 20:07:21 volumio2 volumio[960]: info: Adding Item to queue: music-library/USB/RECOVERY/997Hz_48k.wav May 17 20:07:21 volumio2 volumio[960]: info: Exploding uri music-library/USB/RECOVERY/997Hz_48k.wav in service mpd May 17 20:07:21 volumio2 volumio[960]: info: Adding Item to queue: music-library/USB/RECOVERY/HOME 13-06-2024 May 17 20:07:21 volumio2 volumio[960]: info: Exploding uri music-library/USB/RECOVERY/HOME 13-06-2024 in service mpd May 17 20:07:23 volumio2 volumio[960]: info: CoreStateMachine::stop May 17 20:07:23 volumio2 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 17 20:07:23 volumio2 volumio[960]: info: CoreStateMachine::play index undefined May 17 20:07:23 volumio2 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined May 17 20:07:23 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:23 volumio2 volumio[960]: info: CoreStateMachine::startPlaybackTimer May 17 20:07:23 volumio2 volumio[960]: info: CorePlayQueue::getTrack 3 May 17 20:07:23 volumio2 volumio[960]: info: CoreCommandRouter::volumioGetVisibleSources May 17 20:07:23 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 17 20:07:23 volumio2 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 17 20:07:23 volumio2 volumio[960]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio May 17 20:07:23 volumio2 volumio[960]: verbose: ControllerMpd::clearAddPlayTracks USB/RECOVERY/997Hz_44k1.wav May 17 20:07:23 volumio2 volumio[960]: verbose: ControllerMpd::sendMpdCommand stop May 17 20:07:23 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2F997Hz_48k.wav&metadata=false May 17 20:07:23 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/997Hz_48k.wav May 17 20:07:23 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2FHOME%2013-06-2024%2FChris%2FDeree%2FGenEd%2FPresentation%20Skills%2FInformative%20Speech%2Fwetransfer-335b65.zip&metadata=false May 17 20:07:23 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/HOME 13-06-2024/Chris/Deree/GenEd/Presentation Skills/Informative Speech/wetransfer-335b65.zip May 17 20:07:23 volumio2 volumio[960]: info: ALBUMART /albumart?cacheid=792&web=//extralarge&path=%2Fmnt%2FUSB%2FRECOVERY%2FHOME%2013-06-2024%2FChris%2FDeree%2FGenEd%2FPresentation%20Skills%2FInformative%20Speech%2Fwetransfer-335b65.zip&metadata=false May 17 20:07:23 volumio2 volumio[960]: info: URI /mnt/USB/RECOVERY/HOME 13-06-2024/Chris/Deree/GenEd/Presentation Skills/Informative Speech/wetransfer-335b65.zip May 17 20:07:23 volumio2 volumio[960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 20:07:23 volumio2 volumio[960]: Error: Unable to resolve or reject the same promise twice May 17 20:07:23 volumio2 volumio[960]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 17 20:07:23 volumio2 volumio[960]: at /volumio/app/plugins/music_service/mpd/index.js:2569:21 May 17 20:07:23 volumio2 volumio[960]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 17 20:07:23 volumio2 volumio[960]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 17 20:07:23 volumio2 volumio[960]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 17 20:07:23 volumio2 volumio[960]: at Socket.emit (events.js:315:20) May 17 20:07:23 volumio2 volumio[960]: at addChunk (internal/streams/readable.js:309:12) May 17 20:07:23 volumio2 volumio[960]: at readableAddChunk (internal/streams/readable.js:280:11) May 17 20:07:23 volumio2 volumio[960]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 17 20:07:23 volumio2 volumio[960]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 17 20:07:23 volumio2 volumio[960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 17 20:07:24 volumio2 sudo[5517]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-17 20:06 May 17 20:07:24 volumio2 sudo[5517]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"