-- Logs begin at Wed 2025-01-08 22:30:03 CET, end at Sat 2025-01-11 20:08:13 CET. -- Jan 11 20:07:14 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 20:07:14 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 20:07:14 rivo volumio[3186]: info: Discovery: Getting this device information Jan 11 20:07:14 rivo volumio[3186]: info: CoreCommandRouter::volumioGetState Jan 11 20:07:14 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 20:07:37 rivo volumio[3186]: info: CorePlayQueue::getTrack 0 Jan 11 20:07:37 rivo volumio[3186]: info: CorePlayQueue::getTrack 1 Jan 11 20:07:37 rivo volumio[3186]: info: Prefetching next song Jan 11 20:07:37 rivo volumio[3186]: info: [1736622457506] ControllerQobuz::prefetch Jan 11 20:07:37 rivo volumio[3186]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/58989823" Jan 11 20:07:37 rivo volumio[3186]: STREAMING PROXY: Handling url /?data=qobuz://song/58989823 Jan 11 20:07:37 rivo volumio[3186]: info: Executing endpoint getStreamUrlqobuz Jan 11 20:07:37 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 11 20:07:38 rivo volumio[3186]: info: getStreamUrl took 606 milliseconds Jan 11 20:07:38 rivo volumio[3186]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2801117&eid=58989823&fmt=7&profile=raw&app_id=539451548&cid=1966015&etsp=1736626057&hmac=N8lS3lj7__XOv_Z06kI0o_gkTbs Jan 11 20:07:38 rivo volumio[3186]: STREAMING PROXY: Response: 200, length: 47011441 Jan 11 20:07:38 rivo volumio[3186]: STREAMING PROXY: Client dropped request, destroying Jan 11 20:07:38 rivo volumio[3186]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/58989823" Jan 11 20:07:38 rivo volumio[3186]: info: Jan 11 20:07:38 rivo volumio[3186]: ---------------------------- MPD announces system playlist update Jan 11 20:07:38 rivo volumio[3186]: info: Ignoring MPD Status Update Jan 11 20:07:38 rivo volumio[3186]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/58989823" took 2 milliseconds Jan 11 20:07:38 rivo volumio[3186]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 11 20:07:38 rivo volumio[3186]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 11 20:07:38 rivo volumio[3186]: STREAMING PROXY: Handling url /?data=qobuz://song/58989823 Jan 11 20:07:38 rivo volumio[3186]: info: ------------------------------ 3ms Jan 11 20:07:38 rivo volumio[3186]: info: sendMpdCommand consume 1 took 2 milliseconds Jan 11 20:07:38 rivo volumio[3186]: info: Executing endpoint getStreamUrlqobuz Jan 11 20:07:38 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 11 20:07:39 rivo volumio[3186]: info: getStreamUrl took 570 milliseconds Jan 11 20:07:39 rivo volumio[3186]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2801117&eid=58989823&fmt=7&profile=raw&app_id=539451548&cid=1966015&etsp=1736626059&hmac=vknjrXbF0kr5MVjtXoni1uoxqM0 Jan 11 20:07:39 rivo volumio[3186]: STREAMING PROXY: Response: 200, length: 47011441 Jan 11 20:07:41 rivo volumio[3186]: info: Jan 11 20:07:41 rivo volumio[3186]: ---------------------------- MPD announces system playlist update Jan 11 20:07:41 rivo volumio[3186]: info: Ignoring MPD Status Update Jan 11 20:07:41 rivo volumio[3186]: info: Jan 11 20:07:41 rivo volumio[3186]: ---------------------------- MPD announces state update: player Jan 11 20:07:41 rivo volumio[3186]: info: ControllerMpd::getState Jan 11 20:07:41 rivo volumio[3186]: verbose: ControllerMpd::sendMpdCommand status Jan 11 20:07:41 rivo volumio[3186]: info: ------------------------------ 4ms Jan 11 20:07:41 rivo volumio[3186]: info: sendMpdCommand status took 2 milliseconds Jan 11 20:07:41 rivo volumio[3186]: verbose: ControllerMpd::parseState Jan 11 20:07:41 rivo volumio[3186]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 20:07:41 rivo volumio[3186]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 11 20:07:41 rivo volumio[3186]: verbose: ControllerMpd::parseTrackInfo Jan 11 20:07:41 rivo volumio[3186]: info: ControllerMpd::pushState Jan 11 20:07:41 rivo volumio[3186]: info: CoreCommandRouter::servicePushState Jan 11 20:07:41 rivo volumio[3186]: info: CorePlayQueue::getTrack 0 Jan 11 20:07:41 rivo volumio[3186]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":168,"samplerate":"88.2 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2432 Kbps","isStreaming":false,"title":"58989823","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58989823","trackType":"qobuz"} Jan 11 20:07:41 rivo volumio[3186]: verbose: CURRENT POSITION 0 Jan 11 20:07:41 rivo volumio[3186]: info: CoreStateMachine::syncState stateService play Jan 11 20:07:41 rivo volumio[3186]: info: CoreStateMachine::syncState currentStatus play Jan 11 20:07:41 rivo volumio[3186]: info: Received an update from plugin. extracting info from payload Jan 11 20:07:41 rivo volumio[3186]: info: CoreStateMachine::pushState Jan 11 20:07:41 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 20:07:41 rivo volumio[3186]: info: CoreCommandRouter::volumioPushState Jan 11 20:07:41 rivo volumio[3186]: info: MRS: Pushing multiroomSync output update for this device Jan 11 20:07:41 rivo volumio[3186]: info: MRS: Pushing multiroomSync output Jan 11 20:07:41 rivo volumio[3186]: info: CoreStateMachine::pushState Jan 11 20:07:41 rivo volumio[3186]: info: CoreCommandRouter::volumioPushState Jan 11 20:07:41 rivo volumio[3186]: info: MRS: Pushing multiroomSync output update for this device Jan 11 20:07:41 rivo volumio[3186]: info: MRS: Pushing multiroomSync output Jan 11 20:07:41 rivo volumio[3186]: info: ------------------------------ 32ms Jan 11 20:07:41 rivo volumio[3186]: info: Signalling Playback active due to playback status change Jan 11 20:07:41 rivo volumio[3186]: info: Signalling Playback active due to playback status change Jan 11 20:07:41 rivo volumio[3186]: info: Updating RAAT Signal Path Jan 11 20:07:41 rivo volumio[3186]: info: Updating RAAT Signal Path Jan 11 20:07:42 rivo volumio[3186]: info: CoreStateMachine::startPlaybackTimer Jan 11 20:07:42 rivo volumio[3186]: info: CorePlayQueue::getTrack 1 Jan 11 20:07:42 rivo volumio[3186]: info: CoreStateMachine::pushState Jan 11 20:07:42 rivo volumio[3186]: info: CorePlayQueue::getTrack 1 Jan 11 20:07:42 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 20:07:42 rivo volumio[3186]: info: CoreCommandRouter::volumioPushState Jan 11 20:07:42 rivo volumio[3186]: info: MRS: Pushing multiroomSync output update for this device Jan 11 20:07:42 rivo volumio[3186]: info: MRS: Pushing multiroomSync output Jan 11 20:07:42 rivo volumio[3186]: info: Signalling Playback active due to playback status change Jan 11 20:07:42 rivo volumio[3186]: info: Updating RAAT Signal Path Jan 11 20:07:44 rivo volumio[3186]: STREAMING PROXY: Client dropped request, destroying Jan 11 20:07:44 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 20:07:44 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 20:07:44 rivo volumio[3186]: info: Discovery: Getting this device information Jan 11 20:07:44 rivo volumio[3186]: info: CoreCommandRouter::volumioGetState Jan 11 20:07:44 rivo volumio[3186]: info: CorePlayQueue::getTrack 1 Jan 11 20:07:44 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 20:08:11 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: qobuz , explodeUri Jan 11 20:08:11 rivo volumio[3186]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 11 20:08:12 rivo volumio[3186]: info: explodeUri took 655 milliseconds Jan 11 20:08:12 rivo volumio[3186]: info: Saving Cloud item Royal Con..bow Mussorgki Jan 11 20:08:12 rivo volumio[3186]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Jan 11 20:08:12 rivo volumio[3186]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 20:08:12 rivo volumio[3186]: Error: Reference.child failed: First argument was an invalid path = "/user_data/HChUTMmKbaa2hksy3Jz8ffWfeeU2/myPlaylists/Royal Con..bow Mussorgki". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]" Jan 11 20:08:12 rivo volumio[3186]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15) Jan 11 20:08:12 rivo volumio[3186]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5) Jan 11 20:08:12 rivo volumio[3186]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17) Jan 11 20:08:12 rivo volumio[3186]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48) Jan 11 20:08:12 rivo volumio[3186]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817) Jan 11 20:08:12 rivo volumio[3186]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840) Jan 11 20:08:12 rivo volumio[3186]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337) Jan 11 20:08:12 rivo volumio[3186]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1097:32) Jan 11 20:08:12 rivo volumio[3186]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31) Jan 11 20:08:12 rivo volumio[3186]: at /volumio/app/playlistManager.js:588:20 Jan 11 20:08:12 rivo volumio[3186]: at /volumio/node_modules/jsonfile/index.js:46:5 Jan 11 20:08:12 rivo volumio[3186]: at /volumio/node_modules/graceful-fs/graceful-fs.js:123:16 Jan 11 20:08:12 rivo volumio[3186]: at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:71:3) Jan 11 20:08:12 rivo volumio[3186]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 20:08:13 rivo sudo[6133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 20:07 Jan 11 20:08:13 rivo sudo[6133]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"