-- Logs begin at Tue 2026-02-17 21:59:22 GMT, end at Sat 2026-02-21 09:16:12 GMT. -- Feb 21 09:15:00 hifi sudo[2489]: pam_unix(sudo:session): session closed for user root Feb 21 09:15:01 hifi volumio[963]: info: TidalConnect service stoped! Feb 21 09:15:03 hifi volumio[963]: info: TidalConnect service stoped! Feb 21 09:15:03 hifi volumio[963]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Feb 21 09:15:03 hifi volumio[963]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Feb 21 09:15:03 hifi sudo[2515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Feb 21 09:15:03 hifi sudo[2515]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:15:03 hifi systemd[1]: Started Volumio Tidal Connect Service. Feb 21 09:15:03 hifi sudo[2515]: pam_unix(sudo:session): session closed for user root Feb 21 09:15:03 hifi volumio[963]: info: Executing endpoint tc_getconfig Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Feb 21 09:15:03 hifi vtcs[2517]: STARTING TidalConnect services, version: 1.6.1 Feb 21 09:15:03 hifi vtcs[2517]: STARTED TidalConnect services. Feb 21 09:15:03 hifi volumio[963]: info: Executing endpoint tc_connect Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Feb 21 09:15:03 hifi volumio[963]: info: Connecting to TidalConnect Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::servicePushState Feb 21 09:15:03 hifi volumio[963]: info: CoreStateMachine::pushState Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::volumioPushState Feb 21 09:15:03 hifi volumio[963]: info: MRS: Pushing multiroomSync output update for this device Feb 21 09:15:03 hifi volumio[963]: info: MRS: Pushing multiroomSync output Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::volumioGetState Feb 21 09:15:03 hifi volumio[963]: info: CorePlayQueue::getTrack 0 Feb 21 09:15:03 hifi volumio[963]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::servicePushState Feb 21 09:15:03 hifi volumio[963]: info: CoreStateMachine::pushState Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::volumioPushState Feb 21 09:15:03 hifi volumio[963]: info: MRS: Pushing multiroomSync output update for this device Feb 21 09:15:03 hifi volumio[963]: info: MRS: Pushing multiroomSync output Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::volumioGetState Feb 21 09:15:03 hifi volumio[963]: info: CorePlayQueue::getTrack 0 Feb 21 09:15:03 hifi volumio[963]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Feb 21 09:15:03 hifi volumio5-onboarding[1557]: time=2026-02-21T09:15:03.349Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.22:42234 @ 0x1dcb0e0" state=STATUS_PLAYING positionMs=239000 volume=77 Feb 21 09:15:03 hifi volumio5-onboarding[1557]: time=2026-02-21T09:15:03.349Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.22:42234 @ 0x1dcb0e0" id= title="Caught Out In My Pants" Feb 21 09:15:03 hifi volumio5-onboarding[1557]: time=2026-02-21T09:15:03.349Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.22:42234 @ 0x1dcb0e0" state=STATUS_PLAYING positionMs=239000 volume=77 Feb 21 09:15:03 hifi volumio5-onboarding[1557]: time=2026-02-21T09:15:03.349Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.22:42234 @ 0x1dcb0e0" id= title="Caught Out In My Pants" Feb 21 09:15:03 hifi volumio[963]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Feb 21 09:15:03 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:06 hifi volumio[963]: info: TidalConnect service started! Feb 21 09:15:06 hifi volumio[963]: info: Done. Feb 21 09:15:07 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:11 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:13 hifi go-librespot[1196]: time="2026-02-21T09:15:13Z" level=trace msg="received accesspoint ping" Feb 21 09:15:13 hifi go-librespot[1196]: time="2026-02-21T09:15:13Z" level=trace msg="received accesspoint pong ack" Feb 21 09:15:15 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:19 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:22 hifi go-librespot[1196]: time="2026-02-21T09:15:22Z" level=trace msg="sent dealer ping" Feb 21 09:15:22 hifi go-librespot[1196]: time="2026-02-21T09:15:22Z" level=trace msg="received dealer pong" Feb 21 09:15:23 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:27 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3569" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=info msg="playback was transferred to " Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=trace msg="closed output device because of stop command" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="put connect state inactive" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=trace msg="emitting websocket event: inactive" Feb 21 09:15:29 hifi volumio[963]: SPOTIFY: received: {"type":"inactive","data":null} Feb 21 09:15:29 hifi volumio[963]: error: Failed to decode event: inactive Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="dealer connection closed" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="dealer recv loop stopped" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="obtained new client token: AABmKoSm8R16N8ebAZCdCM/NiMxndnrE0IzdP3dplosi/vcMhAq223FECV5UI7PHto25neepT8Pa+fsMAA5QgDvk72uXKOOBPDD+UXAoQ7tZiDEMxb2wLLtEOseIPhvEKRinGtpJUFTTurYHWdAv9ral1ZFScIs7jlE/FYBsjs0m6HeYdhlNgLNhLngq4BJWndnxUpnw8jeC4/Z/lCaVmkWKYtLmQtoWhkCqpywAZDiJfNI+ImvwZYf8" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 21 09:15:29 hifi go-librespot[1196]: time="2026-02-21T09:15:29Z" level=error msg="failed restoring session after logout" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 21 09:15:32 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:36 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:40 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:44 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:48 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:51 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:15:56 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:16:00 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:16:04 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:16:08 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:16:11 hifi volumio[963]: info: Disabling MyMusic plugin upnp Feb 21 09:16:11 hifi sudo[2662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Feb 21 09:16:11 hifi sudo[2662]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 09:16:11 hifi systemd[1]: Stopping UPnP Renderer front-end to MPD... Feb 21 09:16:11 hifi volumio[963]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 21 09:16:11 hifi volumio[963]: error: Upnp client error: Error: This socket has been ended by the other party Feb 21 09:16:11 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 21 09:16:12 hifi volumio[963]: info: Enabling MyMusic plugin upnp Feb 21 09:16:12 hifi volumio[963]: info: Enabling plugin upnp Feb 21 09:16:12 hifi volumio[963]: info: Loading plugin "upnp"... Feb 21 09:16:12 hifi volumio[963]: info: [1771665372126] Starting Upmpd Daemon Feb 21 09:16:12 hifi volumio[963]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 21 09:16:12 hifi volumio[963]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 09:16:12 hifi volumio[963]: Error: listen EADDRINUSE: address already in use :::6599 Feb 21 09:16:12 hifi volumio[963]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Feb 21 09:16:12 hifi volumio[963]: at listenInCluster (net.js:1366:12) Feb 21 09:16:12 hifi volumio[963]: at Server.listen (net.js:1452:7) Feb 21 09:16:12 hifi volumio[963]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Feb 21 09:16:12 hifi volumio[963]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Feb 21 09:16:12 hifi volumio[963]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Feb 21 09:16:12 hifi volumio[963]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 21 09:16:12 hifi volumio[963]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Feb 21 09:16:12 hifi volumio[963]: code: 'EADDRINUSE', Feb 21 09:16:12 hifi volumio[963]: errno: -98, Feb 21 09:16:12 hifi volumio[963]: syscall: 'listen', Feb 21 09:16:12 hifi volumio[963]: address: '::', Feb 21 09:16:12 hifi volumio[963]: port: 6599 Feb 21 09:16:12 hifi volumio[963]: } Feb 21 09:16:12 hifi volumio[963]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 09:16:12 hifi sudo[2688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-21 09:15 Feb 21 09:16:12 hifi sudo[2688]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 01:46:18 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3e9dbaf8f44792d26e97456a18f12823"