-- Logs begin at Thu 2019-02-14 19:11:59 KST, end at Sat 2025-05-31 20:49:04 KST. -- May 31 20:48:02 hswhdx volumio[779]: Searching plugin music_service/tidal May 31 20:48:02 hswhdx volumio[779]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 31 20:48:02 hswhdx volumio[779]: info: searchTIDALUri took 621 milliseconds May 31 20:48:02 hswhdx volumio[779]: info: search took 622 milliseconds May 31 20:48:02 hswhdx volumio[779]: info: All search sources collected, pushing search results May 31 20:48:04 hswhdx volumio[779]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri May 31 20:48:05 hswhdx volumio[779]: info: browseTIDALUri took 643 milliseconds May 31 20:48:05 hswhdx volumio[779]: info: Preload queue cleared May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820567 May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820569 May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820570 May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820572 May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820575 May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820578 May 31 20:48:05 hswhdx volumio[779]: info: Preloading song: tidal://song/211820582 May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820567 in service tidal May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820569 in service tidal May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820570 in service tidal May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820572 in service tidal May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820575 in service tidal May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820578 in service tidal May 31 20:48:05 hswhdx volumio[779]: info: Exploding uri tidal://song/211820582 in service tidal May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 604 milliseconds May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 571 milliseconds May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 576 milliseconds May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 616 milliseconds May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 628 milliseconds May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 590 milliseconds May 31 20:48:06 hswhdx volumio[779]: info: explodeTIDALUri took 583 milliseconds May 31 20:48:18 hswhdx volumio[779]: info: Preload queue cleared May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::volumioReplaceandPlayItems May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::ClearQueue May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::stop May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::stPlaybackTimer May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::updateTrackBlock May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrackBlock May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::pushState May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrack 0 May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::volumioPushState May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::serviceStop May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrack 0 May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::serviceStop May 31 20:48:18 hswhdx volumio[779]: info: [1748692098893] ControllerWebradio::stop May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand stop May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::clearPlayQueue May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::saveQueue May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::volumioPushQueue May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::addQueueItems May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::addQueueItems May 31 20:48:18 hswhdx volumio[779]: info: Preload queue cleared May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820567 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820567 May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::volumioPushQueue May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::saveQueue May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::updateTrackBlock May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrackBlock May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::volumioPlay May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::play index 0 May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::addQueueItems May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::addQueueItems May 31 20:48:18 hswhdx volumio[779]: info: Preload queue cleared May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820569 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820569 May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820570 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820570 May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820572 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820572 May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820575 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820575 May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820578 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820578 May 31 20:48:18 hswhdx volumio[779]: info: Adding Item to queue: tidal://song/211820582 May 31 20:48:18 hswhdx volumio[779]: info: Using cached record of: tidal://song/211820582 May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::stop May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 20:48:18 hswhdx volumio[779]: info: CoreCommandRouter::volumioPushQueue May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::saveQueue May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::play index undefined May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::updateTrackBlock May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrackBlock May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrack 0 May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::startPlaybackTimer May 31 20:48:18 hswhdx volumio[779]: info: CorePlayQueue::getTrack 0 May 31 20:48:18 hswhdx volumio[779]: info: [1748692098947] ControllerTidal::clearAddPlayTrack May 31 20:48:18 hswhdx volumio[779]: info: Getting stream with soundQuality LOSSLESS May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand stop May 31 20:48:18 hswhdx volumio[779]: info: May 31 20:48:18 hswhdx volumio[779]: ---------------------------- MPD announces state update: player May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand stop took 75 milliseconds May 31 20:48:18 hswhdx volumio[779]: info: ControllerMpd::getState May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand status May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand stop took 21 milliseconds May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand clear May 31 20:48:18 hswhdx volumio[779]: info: May 31 20:48:18 hswhdx volumio[779]: ---------------------------- MPD announces system playlist update May 31 20:48:18 hswhdx volumio[779]: info: Ignoring MPD Status Update May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand status took 7 milliseconds May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand clear took 5 milliseconds May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::parseState May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/211820567&soundQuality=LOSSLESS" May 31 20:48:18 hswhdx volumio[779]: error: updateQueue error: null May 31 20:48:18 hswhdx volumio[779]: info: May 31 20:48:18 hswhdx volumio[779]: ---------------------------- MPD announces system playlist update May 31 20:48:18 hswhdx volumio[779]: info: Ignoring MPD Status Update May 31 20:48:18 hswhdx volumio[779]: info: ------------------------------ 11ms May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand playlistinfo took 9 milliseconds May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/211820567&soundQuality=LOSSLESS" took 9 milliseconds May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::parseTrackInfo May 31 20:48:18 hswhdx volumio[779]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 20:48:18 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand play May 31 20:48:18 hswhdx volumio[779]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 31 20:48:18 hswhdx volumio[779]: info: ------------------------------ 25ms May 31 20:48:18 hswhdx volumio[779]: info: ------------------------------ 8ms May 31 20:48:18 hswhdx volumio[779]: info: sendMpdCommand play took 5 milliseconds May 31 20:48:18 hswhdx volumio[779]: STREAMING PROXY: Handling url /?data=tidal://song/211820567&soundQuality=LOSSLESS May 31 20:48:19 hswhdx volumio[779]: info: Executing endpoint getStreamUrltidal May 31 20:48:19 hswhdx volumio[779]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 31 20:48:19 hswhdx volumio[779]: info: getStreamUrl took 736 milliseconds May 31 20:48:19 hswhdx volumio[779]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEic1ZGQzMGUxMWYwZGRhZDc0YWU3ZjAyNmM0ZmFlZTZiMl82MS5tcDQ/0.flac?Expires=1748695699&Signature=ft3vKEVn2xKOoEsxLM~kBms9W4t59drFh1el61TKGHvs52izpbv1K5yjziE3-0sdho0hVCJsqafO09VQ5C0ElCyFEWu7PSl6tYUKnlRYuyeuc~1uEru~AE1ImsK90wX-poRrTSBMQGVjRLV-ymFzEm75u44EnOZzhUizqyI6f1P6KOpdf6jy1yAkYv6pzpU2wITWVWBYcbGe8sALNq7cIFP86WJ6V~ayRcAooetWqrWzWSopha9K9~joc4yyVzwwBN7x05IRz-h2zCVKDdy6Q6sOH5qGfoGSHvEPuMFT6zrlTF8IM9qQzmikE6uidrEPi5S7JnVJgYgbaoLs82UH~g__&Key-Pair-Id=K14LZCZ9QUI4JL May 31 20:48:20 hswhdx volumio[779]: STREAMING PROXY: Response: 200, length: 24123421 May 31 20:48:20 hswhdx volumio[779]: info: May 31 20:48:20 hswhdx volumio[779]: ---------------------------- MPD announces state update: player May 31 20:48:20 hswhdx volumio[779]: info: ControllerMpd::getState May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand status May 31 20:48:20 hswhdx volumio[779]: info: May 31 20:48:20 hswhdx volumio[779]: ---------------------------- MPD announces state update: player May 31 20:48:20 hswhdx volumio[779]: info: ControllerMpd::getState May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand status May 31 20:48:20 hswhdx volumio[779]: info: sendMpdCommand status took 3 milliseconds May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::parseState May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 20:48:20 hswhdx volumio[779]: info: sendMpdCommand status took 3 milliseconds May 31 20:48:20 hswhdx volumio[779]: info: sendMpdCommand playlistinfo took 2 milliseconds May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::parseState May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::parseTrackInfo May 31 20:48:20 hswhdx volumio[779]: info: ControllerMpd::pushState May 31 20:48:20 hswhdx volumio[779]: info: CoreCommandRouter::servicePushState May 31 20:48:20 hswhdx volumio[779]: info: CorePlayQueue::getTrack 0 May 31 20:48:20 hswhdx volumio[779]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":257,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"211820567&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/211820567&soundQuality=LOSSLESS","trackType":"tidal"} May 31 20:48:20 hswhdx volumio[779]: verbose: CURRENT POSITION 0 May 31 20:48:20 hswhdx volumio[779]: info: CoreStateMachine::syncState stateService play May 31 20:48:20 hswhdx volumio[779]: info: CoreStateMachine::syncState currentStatus stop May 31 20:48:20 hswhdx volumio[779]: info: ------------------------------ 14ms May 31 20:48:20 hswhdx volumio[779]: info: sendMpdCommand playlistinfo took 4 milliseconds May 31 20:48:20 hswhdx volumio[779]: verbose: ControllerMpd::parseTrackInfo May 31 20:48:20 hswhdx volumio[779]: info: ControllerMpd::pushState May 31 20:48:20 hswhdx volumio[779]: info: CoreCommandRouter::servicePushState May 31 20:48:20 hswhdx volumio[779]: info: CorePlayQueue::getTrack 0 May 31 20:48:20 hswhdx volumio[779]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":257,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"211820567&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/211820567&soundQuality=LOSSLESS","trackType":"tidal"} May 31 20:48:20 hswhdx volumio[779]: verbose: CURRENT POSITION 0 May 31 20:48:20 hswhdx volumio[779]: info: CoreStateMachine::syncState stateService play May 31 20:48:20 hswhdx volumio[779]: info: CoreStateMachine::syncState currentStatus play May 31 20:48:20 hswhdx volumio[779]: info: Received an update from plugin. extracting info from payload May 31 20:48:20 hswhdx volumio[779]: info: CoreStateMachine::pushState May 31 20:48:20 hswhdx volumio[779]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 20:48:20 hswhdx volumio[779]: info: CoreCommandRouter::volumioPushState May 31 20:48:20 hswhdx volumio[779]: info: CoreStateMachine::pushState May 31 20:48:20 hswhdx volumio[779]: info: CoreCommandRouter::volumioPushState May 31 20:48:20 hswhdx volumio[779]: info: ------------------------------ 44ms May 31 20:48:20 hswhdx volumio[779]: info: touch_display: Setting screensaver timeout to 0 seconds. May 31 20:48:23 hswhdx volumio[779]: STREAMING PROXY: Client dropped request, destroying May 31 20:49:02 hswhdx volumio[779]: info: CoreCommandRouter::volumioSaveQueueToPlaylist May 31 20:49:02 hswhdx volumio[779]: info: CoreStateMachine::getQueue May 31 20:49:02 hswhdx volumio[779]: info: CorePlayQueue::getQueue May 31 20:49:02 hswhdx volumio[779]: info: Saving Cloud item Richard Strauss: Ein Heldenleben, op. 40 May 31 20:49:02 hswhdx volumio[779]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem May 31 20:49:02 hswhdx volumio[779]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 20:49:02 hswhdx volumio[779]: Error: Reference.child failed: First argument was an invalid path = "/user_data/Y1tqxwgnPBO41HjZ1ERZzk9xxef1/myPlaylists/Richard Strauss: Ein Heldenleben, op. 40". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]" May 31 20:49:02 hswhdx volumio[779]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15) May 31 20:49:02 hswhdx volumio[779]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5) May 31 20:49:02 hswhdx volumio[779]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17) May 31 20:49:02 hswhdx volumio[779]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48) May 31 20:49:02 hswhdx volumio[779]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817) May 31 20:49:02 hswhdx volumio[779]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840) May 31 20:49:02 hswhdx volumio[779]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337) May 31 20:49:02 hswhdx volumio[779]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) May 31 20:49:02 hswhdx volumio[779]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31) May 31 20:49:02 hswhdx volumio[779]: at PlaylistManager.commonAddItemsToPlaylist (/volumio/app/playlistManager.js:834:8) May 31 20:49:02 hswhdx volumio[779]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 20:49:04 hswhdx sudo[3913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-31 20:48 May 31 20:49:04 hswhdx sudo[3913]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"