-- Logs begin at Thu 2019-02-14 19:11:59 KST, end at Tue 2024-11-26 20:12:44 KST. -- Nov 26 20:11:02 hswh-dx volumio[794]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Nov 26 20:11:03 hswh-dx volumio[794]: info: browseTIDALUri took 914 milliseconds Nov 26 20:11:03 hswh-dx volumio[794]: info: Preload queue cleared Nov 26 20:11:03 hswh-dx volumio[794]: info: Preloading song: tidal://song/119141960 Nov 26 20:11:03 hswh-dx volumio[794]: info: Preloading song: tidal://song/119141961 Nov 26 20:11:03 hswh-dx volumio[794]: info: Exploding uri tidal://song/119141960 in service tidal Nov 26 20:11:03 hswh-dx volumio[794]: info: Exploding uri tidal://song/119141961 in service tidal Nov 26 20:11:03 hswh-dx volumio[794]: info: explodeTIDALUri took 527 milliseconds Nov 26 20:11:03 hswh-dx volumio[794]: info: explodeTIDALUri took 530 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: info: Preload queue cleared Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::ClearQueue Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::stop Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::updateTrackBlock Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::getTrackBlock Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::stPlaybackTimer Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::pushState Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::getTrack 4 Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::volumioPushState Nov 26 20:11:06 hswh-dx volumio[794]: info: MRS: Pushing multiroomSync output update for this device Nov 26 20:11:06 hswh-dx volumio[794]: info: MRS: Pushing multiroomSync output Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::serviceStop Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::getTrack 4 Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::serviceStop Nov 26 20:11:06 hswh-dx volumio[794]: info: [1732619466382] ControllerTidal::stop Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 26 20:11:06 hswh-dx volumio[794]: info: ControllerMpd::stop Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand stop Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::clearPlayQueue Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::saveQueue Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::volumioPushQueue Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::addQueueItems Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::addQueueItems Nov 26 20:11:06 hswh-dx volumio[794]: info: Preload queue cleared Nov 26 20:11:06 hswh-dx volumio[794]: info: Adding Item to queue: tidal://song/119141960 Nov 26 20:11:06 hswh-dx volumio[794]: info: Using cached record of: tidal://song/119141960 Nov 26 20:11:06 hswh-dx volumio[794]: info: Adding Item to queue: tidal://song/119141961 Nov 26 20:11:06 hswh-dx volumio[794]: info: Using cached record of: tidal://song/119141961 Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::volumioPushQueue Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::saveQueue Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::updateTrackBlock Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::getTrackBlock Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::volumioPlay Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::play index 0 Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::stop Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::play index undefined Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::getTrack 0 Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::startPlaybackTimer Nov 26 20:11:06 hswh-dx volumio[794]: info: CorePlayQueue::getTrack 0 Nov 26 20:11:06 hswh-dx volumio[794]: info: [1732619466415] ControllerTidal::clearAddPlayTrack Nov 26 20:11:06 hswh-dx volumio[794]: info: Getting stream with soundQuality LOSSLESS Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand stop Nov 26 20:11:06 hswh-dx volumio[794]: info: Nov 26 20:11:06 hswh-dx volumio[794]: ---------------------------- MPD announces state update: player Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand stop took 50 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: info: ControllerMpd::getState Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand status Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand stop took 17 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand clear Nov 26 20:11:06 hswh-dx volumio[794]: info: Nov 26 20:11:06 hswh-dx volumio[794]: ---------------------------- MPD announces system playlist update Nov 26 20:11:06 hswh-dx volumio[794]: info: Ignoring MPD Status Update Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand status took 11 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand clear took 8 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::parseState Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/119141960&soundQuality=LOSSLESS" Nov 26 20:11:06 hswh-dx volumio[794]: error: updateQueue error: null Nov 26 20:11:06 hswh-dx volumio[794]: info: Nov 26 20:11:06 hswh-dx volumio[794]: ---------------------------- MPD announces system playlist update Nov 26 20:11:06 hswh-dx volumio[794]: info: Ignoring MPD Status Update Nov 26 20:11:06 hswh-dx volumio[794]: info: ------------------------------ 7ms Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand playlistinfo took 4 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/119141960&soundQuality=LOSSLESS" took 4 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::parseTrackInfo Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 26 20:11:06 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand play Nov 26 20:11:06 hswh-dx volumio[794]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 26 20:11:06 hswh-dx volumio[794]: info: ------------------------------ 26ms Nov 26 20:11:06 hswh-dx volumio[794]: STREAMING PROXY: Handling url /?data=tidal://song/119141960&soundQuality=LOSSLESS Nov 26 20:11:06 hswh-dx volumio[794]: info: ------------------------------ 14ms Nov 26 20:11:06 hswh-dx volumio[794]: info: sendMpdCommand play took 8 milliseconds Nov 26 20:11:06 hswh-dx volumio[794]: info: Executing endpoint getStreamUrltidal Nov 26 20:11:06 hswh-dx volumio[794]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Nov 26 20:11:07 hswh-dx volumio[794]: info: getStreamUrl took 794 milliseconds Nov 26 20:11:07 hswh-dx volumio[794]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEidmNTQ4ZDJkMjI2ZjQ4MjlmM2JjNTA2ZGQ0NmY4ZTkyY182MS5tcDQ/0.flac?Expires=1732623067&Signature=D2L9kR5ywG~f2LnxZSr2EjLj~vx4pb-RAk10ik7sIS2tByxbAo6BkVMT~~YhmcopA1Mdx0AGGzZ-EeUki3m5JR-OHrUtit0MY~9xCYhI5gTPlyKIYTHi5Rsp24ByNnvFEF1U1Cj37e-oFimsO18coKt1zMV4L-mqqKBC90Uwh69M~c4EQkQt1szrFBODfCVPoy09T3Plq2TOZz6N4QLd8rdx9qJAyZiCIuJjbaryjVpX5oIHIuxCjpphec6jXd6yFqRIcH3nIBvoFJ46U6UlvMcpI-T4vYN5qdyB50XEME977G~5vNWlRp2I95RNCKbqTiy~BsfcRfByzVtJ1L852Q__&Key-Pair-Id=K14LZCZ9QUI4JL Nov 26 20:11:07 hswh-dx volumio[794]: STREAMING PROXY: Response: 200, length: 32866368 Nov 26 20:11:07 hswh-dx volumio[794]: info: Nov 26 20:11:07 hswh-dx volumio[794]: ---------------------------- MPD announces state update: player Nov 26 20:11:07 hswh-dx volumio[794]: info: ControllerMpd::getState Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand status Nov 26 20:11:07 hswh-dx volumio[794]: info: Nov 26 20:11:07 hswh-dx volumio[794]: ---------------------------- MPD announces state update: player Nov 26 20:11:07 hswh-dx volumio[794]: info: ControllerMpd::getState Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand status Nov 26 20:11:07 hswh-dx volumio[794]: info: sendMpdCommand status took 2 milliseconds Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::parseState Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 20:11:07 hswh-dx volumio[794]: info: sendMpdCommand status took 3 milliseconds Nov 26 20:11:07 hswh-dx volumio[794]: info: sendMpdCommand playlistinfo took 2 milliseconds Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::parseState Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::parseTrackInfo Nov 26 20:11:07 hswh-dx volumio[794]: info: ControllerMpd::pushState Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreCommandRouter::servicePushState Nov 26 20:11:07 hswh-dx volumio[794]: info: CorePlayQueue::getTrack 0 Nov 26 20:11:07 hswh-dx volumio[794]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":624,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"119141960&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/119141960&soundQuality=LOSSLESS","trackType":"tidal"} Nov 26 20:11:07 hswh-dx volumio[794]: verbose: CURRENT POSITION 0 Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreStateMachine::syncState stateService play Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreStateMachine::syncState currentStatus stop Nov 26 20:11:07 hswh-dx volumio[794]: info: ------------------------------ 10ms Nov 26 20:11:07 hswh-dx volumio[794]: info: sendMpdCommand playlistinfo took 4 milliseconds Nov 26 20:11:07 hswh-dx volumio[794]: verbose: ControllerMpd::parseTrackInfo Nov 26 20:11:07 hswh-dx volumio[794]: info: ControllerMpd::pushState Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreCommandRouter::servicePushState Nov 26 20:11:07 hswh-dx volumio[794]: info: CorePlayQueue::getTrack 0 Nov 26 20:11:07 hswh-dx volumio[794]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":624,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"119141960&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/119141960&soundQuality=LOSSLESS","trackType":"tidal"} Nov 26 20:11:07 hswh-dx volumio[794]: verbose: CURRENT POSITION 0 Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreStateMachine::syncState stateService play Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreStateMachine::syncState currentStatus play Nov 26 20:11:07 hswh-dx volumio[794]: info: Received an update from plugin. extracting info from payload Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreStateMachine::pushState Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreCommandRouter::volumioPushState Nov 26 20:11:07 hswh-dx volumio[794]: info: MRS: Pushing multiroomSync output update for this device Nov 26 20:11:07 hswh-dx volumio[794]: info: MRS: Pushing multiroomSync output Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreStateMachine::pushState Nov 26 20:11:07 hswh-dx volumio[794]: info: CoreCommandRouter::volumioPushState Nov 26 20:11:07 hswh-dx volumio[794]: info: MRS: Pushing multiroomSync output update for this device Nov 26 20:11:07 hswh-dx volumio[794]: info: MRS: Pushing multiroomSync output Nov 26 20:11:07 hswh-dx volumio[794]: info: ------------------------------ 35ms Nov 26 20:11:07 hswh-dx volumio[794]: info: touch_display: Setting screensaver timeout to 0 seconds. Nov 26 20:11:08 hswh-dx volumio[794]: info: CoreCommandRouter::volumioGetState Nov 26 20:11:08 hswh-dx volumio[794]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Nov 26 20:11:08 hswh-dx volumio[794]: info: touch_display: Setting screensaver timeout to 0 seconds. Nov 26 20:11:11 hswh-dx volumio[794]: STREAMING PROXY: Client dropped request, destroying Nov 26 20:11:15 hswh-dx volumiologrotate[550]: ls: cannot access '/var/log/samba/log.wb-HSWH': No such file or directory Nov 26 20:11:15 hswh-dx volumiologrotate[550]: ls: cannot access 'DX': No such file or directory Nov 26 20:12:15 hswh-dx volumiologrotate[550]: ls: cannot access '/var/log/samba/log.wb-HSWH': No such file or directory Nov 26 20:12:15 hswh-dx volumiologrotate[550]: ls: cannot access 'DX': No such file or directory Nov 26 20:12:43 hswh-dx volumio[794]: info: CoreCommandRouter::volumioSaveQueueToPlaylist Nov 26 20:12:43 hswh-dx volumio[794]: info: CoreStateMachine::getQueue Nov 26 20:12:43 hswh-dx volumio[794]: info: CorePlayQueue::getQueue Nov 26 20:12:43 hswh-dx volumio[794]: info: Saving Cloud item Schubert Symphony No. 8 "Unfinished", Bruno Walter Nov 26 20:12:43 hswh-dx volumio[794]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Nov 26 20:12:43 hswh-dx volumio[794]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 26 20:12:43 hswh-dx volumio[794]: Error: Reference.child failed: First argument was an invalid path = "/user_data/Y1tqxwgnPBO41HjZ1ERZzk9xxef1/myPlaylists/Schubert Symphony No. 8 "Unfinished", Bruno Walter". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]" Nov 26 20:12:43 hswh-dx volumio[794]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15) Nov 26 20:12:43 hswh-dx volumio[794]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5) Nov 26 20:12:43 hswh-dx volumio[794]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17) Nov 26 20:12:43 hswh-dx volumio[794]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48) Nov 26 20:12:43 hswh-dx volumio[794]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817) Nov 26 20:12:43 hswh-dx volumio[794]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840) Nov 26 20:12:43 hswh-dx volumio[794]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337) Nov 26 20:12:43 hswh-dx volumio[794]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1083:32) Nov 26 20:12:43 hswh-dx volumio[794]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31) Nov 26 20:12:43 hswh-dx volumio[794]: at PlaylistManager.commonAddItemsToPlaylist (/volumio/app/playlistManager.js:834:8) Nov 26 20:12:43 hswh-dx volumio[794]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 26 20:12:44 hswh-dx sudo[1545]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-26 20:11 Nov 26 20:12:44 hswh-dx sudo[1545]: 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"