Feb 12 09:40:01 volumio volumio[1124]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 09:40:01 volumio volumio[1124]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 09:40:01 volumio volumio[1124]: info: Streaming services startup Feb 12 09:40:01 volumio volumio[1124]: info: Starting Streaming Daemon Feb 12 09:40:01 volumio sudo[1514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 09:40:01 volumio sudo[1514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 09:40:01 volumio volumio[1124]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 09:40:01 volumio sudo[1514]: pam_unix(sudo:session): session closed for user root Feb 12 09:40:01 volumio volumio[1124]: info: Initializing connection to go-librespot Websocket Feb 12 09:40:02 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 09:40:02 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:02 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 09:40:02 volumio volumio[1124]: error: Cannot start Volumio Streaming Daemon Feb 12 09:40:02 volumio volumio[1124]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 09:40:02 volumio volumio[1124]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 09:40:02 volumio go-librespot[1388]: time="2026-02-12T09:40:02Z" level=debug msg="new websocket client" Feb 12 09:40:02 volumio volumio[1124]: verbose: New Socket.io Connection to 192.168.2.249 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 11 Feb 12 09:40:03 volumio volumio[1124]: info: Connection to go-librespot Websocket established Feb 12 09:40:03 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:03 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:03 volumio volumio[1124]: error: MyVolumio Custom Token format not valid, refreshing it Feb 12 09:40:03 volumio volumio[1124]: verbose: New Socket.io Connection to 192.168.2.249 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 12 Feb 12 09:40:03 volumio volumio[1124]: verbose: New Socket.io Connection to 192.168.2.249 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 13 Feb 12 09:40:03 volumio volumio[1124]: verbose: New Socket.io Connection to 192.168.2.249 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 14 Feb 12 09:40:04 volumio volumio[1124]: verbose: New Socket.io Connection to 192.168.2.249 from 192.168.2.200 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 15 Feb 12 09:40:05 volumio volumio-remote-updater[652]: Test mode disabled Feb 12 09:40:05 volumio volumio-remote-updater[652]: Alpha mode disabled Feb 12 09:40:05 volumio volumio-remote-updater[652]: Alpha legacy test mode disabled Feb 12 09:40:05 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 12 09:40:05 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 09:40:05 volumio go-librespot[1388]: time="2026-02-12T09:40:05Z" level=trace msg="sent dealer ping" Feb 12 09:40:05 volumio go-librespot[1388]: time="2026-02-12T09:40:05Z" level=trace msg="received dealer pong" Feb 12 09:40:05 volumio volumio[1124]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n\n

NEW ADDITIONS

\n\n","title":"Update v4.096","updateavailable":true} Feb 12 09:40:05 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 12 09:40:05 volumio volumio[1124]: info: CoreCommandRouter::volumioGetVisibleSources Feb 12 09:40:05 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 09:40:05 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:05 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:06 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 12 09:40:06 volumio volumio[1124]: info: Received Get System Info Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 09:40:06 volumio volumio[1124]: info: Discovery: Getting this device information Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:06 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:06 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:06 volumio volumio[1124]: info: Listing playlists Feb 12 09:40:06 volumio volumio[1124]: info: Getting Spotify volume Feb 12 09:40:06 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 12 09:40:07 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 12 09:40:07 volumio volumio[1124]: info: MyVolumio login type: Token Feb 12 09:40:07 volumio volumio[1124]: info: Spotify volume: 100 Feb 12 09:40:07 volumio volumio[1124]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Feb 12 09:40:08 volumio volumio[1124]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Feb 12 09:40:09 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:09 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:09 volumio volumio[1124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Feb 12 09:40:09 volumio volumio[1124]: SPOTIFY: SPOTIFY VOLUME 100 Feb 12 09:40:09 volumio volumio[1124]: SPOTIFY: VOLUMIO VOLUME 46 Feb 12 09:40:09 volumio volumio[1124]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 12 09:40:09 volumio volumio[1124]: info: Setting Spotify Volume from Volumio: 46 Feb 12 09:40:09 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:09 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:09 volumio volumio[1124]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 09:40:10 volumio volumio[1124]: info: MyVolumio token set successfully Feb 12 09:40:10 volumio volumio[1124]: info: MYVOLUMIO: Adding device Feb 12 09:40:10 volumio volumio[1124]: info: MYVOLUMIO: Evaluating Server Feb 12 09:40:12 volumio volumio[1124]: SPOTIFY: SETTING SPOTIFY VOLUME 46 Feb 12 09:40:12 volumio volumio[1124]: info: Sending Spotify command with payload to local API: /player/volume Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::volumioGetBrowseSources Feb 12 09:40:12 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 09:40:12 volumio volumio[1124]: info: MyVolumio status changed Feb 12 09:40:12 volumio volumio[1124]: info: Streaming services startup Feb 12 09:40:12 volumio volumio[1124]: info: Starting Streaming Daemon Feb 12 09:40:12 volumio volumio[1124]: info: Removing browser output: myVolumio user plan is not superstar Feb 12 09:40:12 volumio volumio[1124]: info: Removing audio output: Feb 12 09:40:12 volumio volumio[1124]: info: Stoppping Tunnel 1 Feb 12 09:40:12 volumio sudo[1560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 09:40:12 volumio sudo[1560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 09:40:12 volumio sudo[1562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 12 09:40:12 volumio sudo[1562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 09:40:12 volumio sudo[1560]: pam_unix(sudo:session): session closed for user root Feb 12 09:40:12 volumio go-librespot[1388]: time="2026-02-12T09:40:12Z" level=debug msg="update volume requested to 30146/65535" Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 12 09:40:12 volumio sudo[1562]: pam_unix(sudo:session): session closed for user root Feb 12 09:40:13 volumio volumio[1124]: info: Setting Geolocation for MyVolumio to eu3 Feb 12 09:40:13 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:13 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:13 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:13 volumio go-librespot[1388]: time="2026-02-12T09:40:13Z" level=debug msg="put connect state because VOLUME_CHANGED" Feb 12 09:40:13 volumio go-librespot[1388]: time="2026-02-12T09:40:13Z" level=trace msg="emitting websocket event: volume" Feb 12 09:40:13 volumio volumio[1124]: info: Remote SSH Stopped Feb 12 09:40:13 volumio volumio[1124]: error: Cannot start Volumio Streaming Daemon Feb 12 09:40:13 volumio volumio[1124]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 09:40:13 volumio volumio[1124]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 09:40:13 volumio volumio[1124]: SPOTIFY: received: {"type":"volume","data":{"value":46,"max":100}} Feb 12 09:40:13 volumio volumio[1124]: SPOTIFY: RECEIVED SPOTIFY VOLUME 46 Feb 12 09:40:13 volumio volumio[1124]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 09:40:14 volumio volumio[1124]: info: Updating MyVolumio device info Feb 12 09:40:14 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:14 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:14 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:14 volumio volumio[1124]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 09:40:17 volumio volumio[1124]: info: MYVOLUMIO: Adding device Feb 12 09:40:17 volumio volumio[1124]: info: MYVOLUMIO: Evaluating Server Feb 12 09:40:19 volumio volumio[1124]: info: Setting Geolocation for MyVolumio to eu9 Feb 12 09:40:19 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:19 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:19 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:19 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:19 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:19 volumio volumio[1124]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 09:40:20 volumio volumio[1124]: info: Updating MyVolumio device info Feb 12 09:40:20 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:20 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:20 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:21 volumio volumio[1124]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 09:40:21 volumio upmpdcli[1597]: writing RSA key Feb 12 09:40:21 volumio volumio[1124]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 12 09:40:21 volumio volumio[1124]: info: Completed starting MyVolumio Plugin Feb 12 09:40:21 volumio volumio[1124]: [Metrics] CommandRouter: 74s 889.21ms Feb 12 09:40:21 volumio volumio[1124]: info: CoreCommandRouter::volumiosetStartupVolume Feb 12 09:40:21 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 09:40:21 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 09:40:21 volumio volumio[1124]: info: CoreCommandRouter::Close All Modals sent Feb 12 09:40:21 volumio volumio[1124]: info: CoreCommandRouter::Close All Modals sent Feb 12 09:40:22 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 12 09:40:22 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 12 09:40:22 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 12 09:40:28 volumio volumio[1124]: info: BOOT COMPLETED Feb 12 09:40:34 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:34 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:35 volumio go-librespot[1388]: time="2026-02-12T09:40:35Z" level=trace msg="sent dealer ping" Feb 12 09:40:35 volumio go-librespot[1388]: time="2026-02-12T09:40:35Z" level=trace msg="received dealer pong" Feb 12 09:40:48 volumio volumio[1124]: info: CoreCommandRouter::volumioGetQueue Feb 12 09:40:48 volumio volumio[1124]: info: CoreStateMachine::getQueue Feb 12 09:40:48 volumio volumio[1124]: info: CorePlayQueue::getQueue Feb 12 09:40:49 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:40:49 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:40:57 volumio volumio[1124]: Searching plugin music_service/spop Feb 12 09:40:57 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 09:40:58 volumio volumio[1124]: info: All search sources collected, pushing search results Feb 12 09:40:59 volumio volumio[1124]: Searching plugin music_service/spop Feb 12 09:40:59 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 09:41:00 volumio volumio[1124]: info: All search sources collected, pushing search results Feb 12 09:41:04 volumio volumio[1124]: Searching plugin music_service/spop Feb 12 09:41:04 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 09:41:04 volumio volumio[1124]: info: CoreCommandRouter::volumioGetState Feb 12 09:41:04 volumio volumio[1124]: info: CorePlayQueue::getTrack 0 Feb 12 09:41:05 volumio go-librespot[1388]: time="2026-02-12T09:41:05Z" level=trace msg="sent dealer ping" Feb 12 09:41:05 volumio go-librespot[1388]: time="2026-02-12T09:41:05Z" level=trace msg="received dealer pong" Feb 12 09:41:05 volumio volumio[1124]: info: All search sources collected, pushing search results Feb 12 09:41:10 volumio volumio[1124]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 12 09:41:10 volumio volumio[1124]: info: In handleBrowseUri, curUri=spotify:artist:6PY4JG7pN9XLvTg703NvDC Feb 12 09:41:11 volumio volumio[1124]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 09:41:11 volumio volumio[1124]: TypeError: Cannot read properties of undefined (reading 'url') Feb 12 09:41:11 volumio volumio[1124]: at /data/plugins/music_service/spop/index.js:2449:60 Feb 12 09:41:11 volumio volumio[1124]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 12 09:41:11 volumio volumio[1124]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 09:41:17 volumio sudo[1725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 09:40' Feb 12 09:41:17 volumio sudo[1725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"