-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-12-18 18:34:10 CET. --
Dec 18 18:33:01 volumio sudo[22935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Dec 18 18:33:01 volumio sudo[22935]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 18:33:01 volumio sudo[22935]: pam_unix(sudo:session): session closed for user root
Dec 18 18:33:01 volumio volumio[22506]: info: Volumio BT Module successfully started
Dec 18 18:33:01 volumio volumio[22506]: info: TidalConnect service stoped!
Dec 18 18:33:01 volumio volumio[22506]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 18 18:33:01 volumio volumio[22506]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 18 18:33:01 volumio sudo[22946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 18 18:33:01 volumio sudo[22946]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 18:33:01 volumio systemd[1]: Started Volumio Tidal Connect Service.
Dec 18 18:33:01 volumio sudo[22946]: pam_unix(sudo:session): session closed for user root
Dec 18 18:33:01 volumio volumio[22506]: info: Executing endpoint tc_getconfig
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 18 18:33:01 volumio vtcs[22948]: STARTING TidalConnect services, version: 1.5.1-beta1
Dec 18 18:33:01 volumio vtcs[22948]: STARTED TidalConnect services.
Dec 18 18:33:01 volumio volumio[22506]: info: Executing endpoint tc_connect
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 18 18:33:01 volumio volumio[22506]: info: Connecting to TidalConnect
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::servicePushState
Dec 18 18:33:01 volumio volumio[22506]: info: CoreStateMachine::pushState
Dec 18 18:33:01 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::volumioPushState
Dec 18 18:33:01 volumio volumio[22506]: info: MRS: Pushing multiroomSync output update for this device
Dec 18 18:33:01 volumio volumio[22506]: info: MRS: Pushing multiroomSync output
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::volumioGetState
Dec 18 18:33:01 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:01 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:01 volumio volumio[22506]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::servicePushState
Dec 18 18:33:01 volumio volumio[22506]: info: CoreStateMachine::pushState
Dec 18 18:33:01 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::volumioPushState
Dec 18 18:33:01 volumio volumio[22506]: info: MRS: Pushing multiroomSync output update for this device
Dec 18 18:33:01 volumio volumio[22506]: info: MRS: Pushing multiroomSync output
Dec 18 18:33:01 volumio volumio[22506]: info: CoreCommandRouter::volumioGetState
Dec 18 18:33:01 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:01 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:01 volumio volumio[22506]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect
Dec 18 18:33:01 volumio sudo[22968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Dec 18 18:33:01 volumio sudo[22968]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 18:33:01 volumio systemd[1]: Stopping MPD Monitor Service...
Dec 18 18:33:02 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM
Dec 18 18:33:02 volumio systemd[1]: mpd_monitor.service: Succeeded.
Dec 18 18:33:02 volumio systemd[1]: Stopped MPD Monitor Service.
Dec 18 18:33:02 volumio volumio[22506]: ------------------------------------ BT MESSAGE: BT STATUS: running
Dec 18 18:33:02 volumio volumio[22506]: ------------------------------------ BT MESSAGE: BT STATUS: waiting
Dec 18 18:33:02 volumio systemd[1]: Started MPD Monitor Service.
Dec 18 18:33:02 volumio sudo[22968]: pam_unix(sudo:session): session closed for user root
Dec 18 18:33:02 volumio mpd_monitor.sh[22970]: MPD Monitor Service: Starting MPD Monitor Service
Dec 18 18:33:02 volumio volumio[22506]: info: Successfully started MPD Monitor
Dec 18 18:33:03 volumio volumio[22506]: info: MRS: Getting audio outputs on start
Dec 18 18:33:03 volumio volumio[22506]: info: MRS: Requesting all other devices output
Dec 18 18:33:04 volumio volumio[22506]: info: TidalConnect service started!
Dec 18 18:33:04 volumio volumio[22506]: [Metrics] CommandRouter: 27s 665.30ms
Dec 18 18:33:04 volumio volumio[22506]: info: CoreCommandRouter::volumiosetStartupVolume
Dec 18 18:33:04 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 18:33:04 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 18:33:04 volumio volumio[22506]: info: CoreCommandRouter::Close All Modals sent
Dec 18 18:33:04 volumio volumio[22506]: info: CoreCommandRouter::Close All Modals sent
Dec 18 18:33:05 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 18 18:33:05 volumio volumio[22506]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Dec 18 18:33:05 volumio volumio[22506]: info: CoreCommandRouter::volumioGetState
Dec 18 18:33:05 volumio volumio[22506]: info: CorePlayQueue::getTrack 0
Dec 18 18:33:05 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Dec 18 18:33:05 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 18 18:33:05 volumio volumio[22506]: xcb_connection_has_error() returned true
Dec 18 18:33:05 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Dec 18 18:33:09 volumio kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 2 ep 1
Dec 18 18:33:09 volumio kernel: xhci_hcd 0000:01:00.0: @000000042951ad70 00000000 00000000 0e000000 02028001
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 18 18:33:10 volumio volumio-remote-updater[641]: No test mode
Dec 18 18:33:10 volumio volumio-remote-updater[641]: No alpha test mode
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Dec 18 18:33:10 volumio volumio[22506]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix TIDAL low quality (AAC) playback
- Fix for DLNA Server discovery
- Fix for Plugins installation
NEW ADDITIONS
- BLE-based onboarding setup
- Update TIDAL SDK
","title":"Update v3.886","updateavailable":true}
Dec 18 18:33:10 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Dec 18 18:33:11 volumio volumio[22506]: info: BOOT COMPLETED
Dec 18 18:33:29 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri
Dec 18 18:33:29 volumio volumio[22506]: info: browseTIDALUri took 663 milliseconds
Dec 18 18:33:29 volumio volumio[22506]: info: Preload queue cleared
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104077
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104078
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104080
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104081
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104082
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104083
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104084
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104085
Dec 18 18:33:29 volumio volumio[22506]: info: Preloading song: tidal://song/1104086
Dec 18 18:33:29 volumio volumio[22506]: info: Exploding uri tidal://song/1104077 in service tidal
Dec 18 18:33:29 volumio volumio[22506]: info: Exploding uri tidal://song/1104078 in service tidal
Dec 18 18:33:29 volumio volumio[22506]: info: Exploding uri tidal://song/1104080 in service tidal
Dec 18 18:33:29 volumio volumio[22506]: info: Exploding uri tidal://song/1104081 in service tidal
Dec 18 18:33:30 volumio volumio[22506]: info: Exploding uri tidal://song/1104082 in service tidal
Dec 18 18:33:30 volumio volumio[22506]: info: Exploding uri tidal://song/1104083 in service tidal
Dec 18 18:33:30 volumio volumio[22506]: info: Exploding uri tidal://song/1104084 in service tidal
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 299 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: Exploding uri tidal://song/1104085 in service tidal
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 354 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: Exploding uri tidal://song/1104086 in service tidal
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 321 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 319 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 303 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 342 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 327 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 363 milliseconds
Dec 18 18:33:30 volumio volumio[22506]: info: explodeTIDALUri took 348 milliseconds
Dec 18 18:33:40 volumio volumio[22506]: info: Listing playlists
Dec 18 18:34:09 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: tidal , explodeUri
Dec 18 18:34:09 volumio volumio[22506]: info: explodeTIDALUri took 663 milliseconds
Dec 18 18:34:09 volumio volumio[22506]: info: Saving Cloud item Oscar P. trio
Dec 18 18:34:09 volumio volumio[22506]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem
Dec 18 18:34:09 volumio volumio[22506]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 18 18:34:09 volumio volumio[22506]: Error: Reference.child failed: First argument was an invalid path = "/user_data/uf5oZnno2TSEyjJL0pQZavktXds2/myPlaylists/Oscar P. trio". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]"
Dec 18 18:34:09 volumio volumio[22506]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15)
Dec 18 18:34:09 volumio volumio[22506]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5)
Dec 18 18:34:09 volumio volumio[22506]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17)
Dec 18 18:34:09 volumio volumio[22506]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48)
Dec 18 18:34:09 volumio volumio[22506]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817)
Dec 18 18:34:09 volumio volumio[22506]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840)
Dec 18 18:34:09 volumio volumio[22506]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337)
Dec 18 18:34:09 volumio volumio[22506]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32)
Dec 18 18:34:09 volumio volumio[22506]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31)
Dec 18 18:34:09 volumio volumio[22506]: at /volumio/app/playlistManager.js:588:20
Dec 18 18:34:09 volumio volumio[22506]: at /volumio/node_modules/jsonfile/index.js:46:5
Dec 18 18:34:09 volumio volumio[22506]: at /volumio/node_modules/graceful-fs/graceful-fs.js:123:16
Dec 18 18:34:09 volumio volumio[22506]: at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:63:3)
Dec 18 18:34:09 volumio volumio[22506]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 18 18:34:10 volumio sudo[23138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-18 18:33
Dec 18 18:34:10 volumio sudo[23138]: 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="cc50ad4a2058d01de272214eb33827883bd2b7d8"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET"
VOLUMIO_VERSION="3.874"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"