-- Logs begin at Sat 2025-01-18 08:46:12 +07, end at Sun 2025-01-19 07:13:39 +07. -- Jan 19 07:12:04 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 19 07:12:04 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 19 07:12:04 volumio volumio[1077]: info: Discovery: Getting this device information Jan 19 07:12:04 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState Jan 19 07:12:04 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 19 07:12:34 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 19 07:12:34 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 19 07:12:34 volumio volumio[1077]: info: Discovery: Getting this device information Jan 19 07:12:34 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState Jan 19 07:12:34 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 19 07:12:36 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState Jan 19 07:12:36 volumio volumio[1077]: info: CoreCommandRouter::volumioPlay Jan 19 07:12:36 volumio volumio[1077]: info: CoreStateMachine::play index undefined Jan 19 07:12:36 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:12:36 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:12:36 volumio volumio[1077]: info: CoreStateMachine::startPlaybackTimer Jan 19 07:12:36 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:12:36 volumio volumio[1077]: info: [1737245556916] ControllerTidal::clearAddPlayTrack Jan 19 07:12:36 volumio volumio[1077]: info: Getting stream with soundQuality LOSSLESS Jan 19 07:12:36 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand stop Jan 19 07:12:36 volumio volumio[1077]: info: sendMpdCommand stop took 0 milliseconds Jan 19 07:12:36 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand clear Jan 19 07:12:36 volumio volumio[1077]: info: Jan 19 07:12:36 volumio volumio[1077]: ---------------------------- MPD announces system playlist update Jan 19 07:12:36 volumio volumio[1077]: info: Ignoring MPD Status Update Jan 19 07:12:36 volumio volumio[1077]: info: sendMpdCommand clear took 0 milliseconds Jan 19 07:12:36 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/599284&soundQuality=LOSSLESS" Jan 19 07:12:36 volumio volumio[1077]: error: updateQueue error: null Jan 19 07:12:36 volumio volumio[1077]: info: Jan 19 07:12:36 volumio volumio[1077]: ---------------------------- MPD announces system playlist update Jan 19 07:12:36 volumio volumio[1077]: info: Ignoring MPD Status Update Jan 19 07:12:36 volumio volumio[1077]: info: ------------------------------ 2ms Jan 19 07:12:36 volumio volumio[1077]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/599284&soundQuality=LOSSLESS" took 1 milliseconds Jan 19 07:12:36 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 19 07:12:36 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand play Jan 19 07:12:36 volumio volumio[1077]: info: ------------------------------ 1ms Jan 19 07:12:36 volumio volumio[1077]: info: sendMpdCommand play took 1 milliseconds Jan 19 07:12:36 volumio volumio[1077]: STREAMING PROXY: Handling url /?data=tidal://song/599284&soundQuality=LOSSLESS Jan 19 07:12:36 volumio volumio[1077]: info: Executing endpoint getStreamUrltidal Jan 19 07:12:36 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Jan 19 07:12:37 volumio volumio[1077]: info: getStreamUrl took 911 milliseconds Jan 19 07:12:37 volumio volumio[1077]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiQ0MDVlYjVhY2Q3NmNmMDIyNzY1NDQ4MmI1MDA3OTliMS5tcDQ/0.flac?Expires=1737249050&Signature=VuKG8JSI9kYyROmVMJ5z7g5gg~Uek6bNhUztBY5iAdM9p7nQDuQ~9WqNLtBnYGt9N-ndm082EOWRLzbSlbYcu~naEGWUgJbutmeTp5TEdxinbmZotb-rHb-sTHDpxlzwSoXSVZBXMBG7h67OZFvHreDZ88Yga70y3dihME0XLMSkHFWlS7DAiNKxALSb-YLqbHGtDt8h8EjXCSp-4kW~sKI9T7KHfwtM9MAJRkz6gWyksOV1lYUYcz8U1kIcKfgWcoSlG6-5QCpqw15-SeV8ZFJ2eQbu5pFIuKamubFnmPxaZVOsA4RDhZ0s4LxjvqC7Fvop17vruJDAcB77VZkRmA__&Key-Pair-Id=K14LZCZ9QUI4JL Jan 19 07:12:37 volumio volumio[1077]: STREAMING PROXY: Response: 200, length: 17687588 Jan 19 07:12:37 volumio volumio[1077]: info: Jan 19 07:12:37 volumio volumio[1077]: ---------------------------- MPD announces state update: player Jan 19 07:12:37 volumio volumio[1077]: info: ControllerMpd::getState Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand status Jan 19 07:12:37 volumio volumio[1077]: info: Jan 19 07:12:37 volumio volumio[1077]: ---------------------------- MPD announces state update: player Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand clearerror Jan 19 07:12:37 volumio volumio[1077]: info: sendMpdCommand status took 19 milliseconds Jan 19 07:12:37 volumio volumio[1077]: info: ControllerMpd::getState Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand status Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::parseState Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 19 07:12:37 volumio volumio[1077]: info: sendMpdCommand clearerror took 11 milliseconds Jan 19 07:12:37 volumio volumio[1077]: info: sendMpdCommand status took 11 milliseconds Jan 19 07:12:37 volumio volumio[1077]: info: sendMpdCommand playlistinfo took 10 milliseconds Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::parseState Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::parseTrackInfo Jan 19 07:12:37 volumio volumio[1077]: info: ControllerMpd::pushState Jan 19 07:12:37 volumio volumio[1077]: info: CoreCommandRouter::servicePushState Jan 19 07:12:37 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:12:37 volumio volumio[1077]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":174,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"599284&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/599284&soundQuality=LOSSLESS","trackType":"tidal"} Jan 19 07:12:37 volumio volumio[1077]: verbose: CURRENT POSITION 0 Jan 19 07:12:37 volumio volumio[1077]: info: CoreStateMachine::syncState stateService pause Jan 19 07:12:37 volumio volumio[1077]: info: CoreStateMachine::syncState currentStatus stop Jan 19 07:12:37 volumio volumio[1077]: info: CoreStateMachine::pushState Jan 19 07:12:37 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 19 07:12:37 volumio volumio[1077]: info: CoreCommandRouter::volumioPushState Jan 19 07:12:37 volumio volumio[1077]: info: ------------------------------ 71ms Jan 19 07:12:37 volumio volumio[1077]: info: sendMpdCommand playlistinfo took 35 milliseconds Jan 19 07:12:37 volumio volumio[1077]: verbose: ControllerMpd::parseTrackInfo Jan 19 07:12:37 volumio volumio[1077]: info: ControllerMpd::pushState Jan 19 07:12:37 volumio volumio[1077]: info: CoreCommandRouter::servicePushState Jan 19 07:12:37 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:12:37 volumio volumio[1077]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":174,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"599284&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/599284&soundQuality=LOSSLESS","trackType":"tidal"} Jan 19 07:12:37 volumio volumio[1077]: verbose: CURRENT POSITION 0 Jan 19 07:12:37 volumio volumio[1077]: info: CoreStateMachine::syncState stateService pause Jan 19 07:12:37 volumio volumio[1077]: info: CoreStateMachine::syncState currentStatus stop Jan 19 07:12:37 volumio volumio[1077]: info: CoreStateMachine::pushState Jan 19 07:12:37 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 19 07:12:37 volumio volumio[1077]: info: CoreCommandRouter::volumioPushState Jan 19 07:12:37 volumio volumio[1077]: info: ------------------------------ 88ms Jan 19 07:12:38 volumio volumio[1077]: STREAMING PROXY: Client dropped request, destroying Jan 19 07:12:38 volumio volumio[1077]: error: error Jan 19 07:12:38 volumio volumio[1077]: error: error Jan 19 07:12:38 volumio volumio[1077]: error: error Jan 19 07:12:39 volumio volumio[1077]: error: error Jan 19 07:12:39 volumio volumio[1077]: error: error Jan 19 07:12:39 volumio volumio[1077]: error: error Jan 19 07:12:39 volumio volumio[1077]: info: Executing endpoint metavolumio Jan 19 07:12:39 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 19 07:12:40 volumio volumio[1077]: info: Executing endpoint metavolumio Jan 19 07:12:40 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 19 07:12:47 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState Jan 19 07:12:49 volumio volumio[1077]: info: Executing endpoint metavolumio Jan 19 07:12:49 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 19 07:12:51 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 19 07:12:52 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:12:56 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:12:56 volumio volumio[1077]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::ClearQueue Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::stop Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:12:56 volumio volumio[1077]: info: CorePlayQueue::clearPlayQueue Jan 19 07:12:56 volumio volumio[1077]: info: CorePlayQueue::saveQueue Jan 19 07:12:56 volumio volumio[1077]: info: CoreCommandRouter::volumioPushQueue Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::addQueueItems Jan 19 07:12:56 volumio volumio[1077]: info: CorePlayQueue::addQueueItems Jan 19 07:12:56 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:12:56 volumio volumio[1077]: info: Adding Item to queue: upnp/folder/http://192.168.1.60:9050/TMSContentDirectory/Control@0$1$13$77$457 Jan 19 07:12:56 volumio volumio[1077]: info: Exploding uri upnp/folder/http://192.168.1.60:9050/TMSContentDirectory/Control@0$1$13$77$457 in service upnp_browser Jan 19 07:12:56 volumio volumio[1077]: info: CoreCommandRouter::volumioPushQueue Jan 19 07:12:56 volumio volumio[1077]: info: CorePlayQueue::saveQueue Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::updateTrackBlock Jan 19 07:12:56 volumio volumio[1077]: info: CorePlayQueue::getTrackBlock Jan 19 07:12:56 volumio volumio[1077]: info: CoreCommandRouter::volumioPlay Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::play index 0 Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::stop Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::play index undefined Jan 19 07:12:56 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:12:56 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:13:02 volumio volumio[1077]: info: CoreCommandRouter::volumioPlay Jan 19 07:13:02 volumio volumio[1077]: info: CoreStateMachine::play index undefined Jan 19 07:13:02 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:13:02 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:13:04 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 19 07:13:04 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 19 07:13:04 volumio volumio[1077]: info: Discovery: Getting this device information Jan 19 07:13:04 volumio volumio[1077]: info: CoreCommandRouter::volumioGetState Jan 19 07:13:04 volumio volumio[1077]: info: CorePlayQueue::getTrack 0 Jan 19 07:13:04 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 19 07:13:14 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 19 07:13:14 volumio volumio[1077]: info: CURURI: music-library Jan 19 07:13:14 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:13:22 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 19 07:13:22 volumio volumio[1077]: info: CURURI: music-library/USB Jan 19 07:13:22 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:13:25 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:13:25 volumio volumio[1077]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 19 07:13:25 volumio volumio[1077]: info: CoreStateMachine::ClearQueue Jan 19 07:13:25 volumio volumio[1077]: info: CoreStateMachine::stop Jan 19 07:13:25 volumio volumio[1077]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 19 07:13:25 volumio volumio[1077]: info: CorePlayQueue::clearPlayQueue Jan 19 07:13:25 volumio volumio[1077]: info: CorePlayQueue::saveQueue Jan 19 07:13:25 volumio volumio[1077]: info: CoreCommandRouter::volumioPushQueue Jan 19 07:13:25 volumio volumio[1077]: info: CoreStateMachine::addQueueItems Jan 19 07:13:25 volumio volumio[1077]: info: CorePlayQueue::addQueueItems Jan 19 07:13:25 volumio volumio[1077]: info: Preload queue cleared Jan 19 07:13:25 volumio volumio[1077]: info: Adding Item to queue: music-library/USB/New_Volume Jan 19 07:13:25 volumio volumio[1077]: info: Exploding uri music-library/USB/New_Volume in service mpd Jan 19 07:13:38 volumio volumio-remote-updater[678]: [2025-01-19 07:13:38] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Jan 19 07:13:38 volumio volumio[1077]: error: error Jan 19 07:13:38 volumio volumio[1077]: error: error Jan 19 07:13:38 volumio volumio[1077]: error: error Jan 19 07:13:39 volumio volumio[1077]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 19 07:13:39 volumio volumio[1077]: info: CURURI: music-library/USB/New_Volume Jan 19 07:13:39 volumio volumio[1077]: info: ALBUMART /albumart?cacheid=514&web=/Inspiration%2C%20A%20Tribute%20To%20Nat%20King%20Cole/large&path=%2Fmnt%2FUSB%2FNew_Volume%2F%24RECYCLE.BIN%2FS-1-5-21-3461471983-1764115675-635687593-1001%2F%24RQXKVKI.cue)%2Fgeorge_benson-inspiration_0888072345188.cue&metadata=false Jan 19 07:13:39 volumio volumio[1077]: info: URI /mnt/USB/New_Volume/$RECYCLE.BIN/S-1-5-21-3461471983-1764115675-635687593-1001/$RQXKVKI.cue)/george_benson-inspiration_0888072345188.cue Jan 19 07:13:39 volumio volumio[1077]: info: ALBUMART /albumart?cacheid=514&web=/Inspiration%2C%20A%20Tribute%20To%20Nat%20King%20Cole/large&path=%2Fmnt%2FUSB%2FNew_Volume%2F%24RECYCLE.BIN%2FS-1-5-21-3461471983-1764115675-635687593-1001%2F%24RQXKVKI.cue)%2Fgeorge_benson-inspiration_0888072345188.cue&metadata=false Jan 19 07:13:39 volumio volumio[1077]: info: URI /mnt/USB/New_Volume/$RECYCLE.BIN/S-1-5-21-3461471983-1764115675-635687593-1001/$RQXKVKI.cue)/george_benson-inspiration_0888072345188.cue Jan 19 07:13:39 volumio volumio[1077]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 19 07:13:39 volumio volumio[1077]: Error: Unable to resolve or reject the same promise twice Jan 19 07:13:39 volumio volumio[1077]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jan 19 07:13:39 volumio volumio[1077]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Jan 19 07:13:39 volumio volumio[1077]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Jan 19 07:13:39 volumio volumio[1077]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Jan 19 07:13:39 volumio volumio[1077]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Jan 19 07:13:39 volumio volumio[1077]: at Socket.emit (events.js:315:20) Jan 19 07:13:39 volumio volumio[1077]: at addChunk (internal/streams/readable.js:309:12) Jan 19 07:13:39 volumio volumio[1077]: at readableAddChunk (internal/streams/readable.js:280:11) Jan 19 07:13:39 volumio volumio[1077]: at Socket.Readable.push (internal/streams/readable.js:223:10) Jan 19 07:13:39 volumio volumio[1077]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Jan 19 07:13:39 volumio volumio[1077]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 19 07:13:39 volumio sudo[4549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-19 07:12 Jan 19 07:13:39 volumio sudo[4549]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"