-- Logs begin at Mon 2026-05-18 15:39:25 CEST, end at Sun 2026-05-31 11:27:42 CEST. -- May 31 11:26:29 volumio volumio[983]: verbose: New Socket.io Connection to 192.168.178.66 from 192.168.178.58 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetVisibleSources May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: Listing playlists May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetVisibleSources May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: Listing playlists May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetVisibleSources May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: Listing playlists May 31 11:26:29 volumio volumio[983]: info: Received Get System Info May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:26:29 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 31 11:26:29 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 31 11:26:41 volumio ntpd[776]: 85.163.168.227 local addr 192.168.178.66 -> May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 11:26:45 volumio volumio[983]: info: Retrieving Cloud Streaming UI May 31 11:26:45 volumio volumio[983]: info: Getting Tidal Cloud Configuration May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 11:26:45 volumio volumio[983]: info: Getting Qobuz Cloud Configuration May 31 11:26:45 volumio volumio[983]: info: Asking plugin for UI Config May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 11:26:45 volumio volumio[983]: info: Getting Spotify Cloud Configuration May 31 11:26:45 volumio volumio[983]: info: Asking plugin for UI Config May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 11:26:45 volumio volumio[983]: info: Saving Spotify Acccount May 31 11:26:45 volumio volumio[983]: info: Got Tidal Cloud Configuration May 31 11:26:45 volumio volumio[983]: info: Got it May 31 11:26:45 volumio volumio[983]: info: Got it May 31 11:26:45 volumio volumio[983]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 11:26:45 volumio volumio[983]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::volumioGetBrowseSources May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::volumioGetBrowseSources May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::volumioGetBrowseSources May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 11:26:45 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 31 11:26:49 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 11:26:53 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 11:26:57 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 11:27:15 volumio volumio[983]: verbose: New Socket.io Connection to 192.168.178.66 from 192.168.178.58 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/26.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetVisibleSources May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: Listing playlists May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetVisibleSources May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: Listing playlists May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetVisibleSources May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: Listing playlists May 31 11:27:15 volumio volumio[983]: info: Received Get System Info May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 31 11:27:15 volumio volumio[983]: info: Discovery: Getting this device information May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 31 11:27:15 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:16 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 31 11:27:18 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 11:27:22 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 11:27:27 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 31 11:27:27 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 31 11:27:34 volumio volumio[983]: info: Enabling plugin spop May 31 11:27:34 volumio volumio[983]: info: Loading plugin "spop"... May 31 11:27:34 volumio volumio[983]: info: PLUGIN START: spop May 31 11:27:34 volumio volumio[983]: info: Creating Spotify config file May 31 11:27:34 volumio volumio[983]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 11:27:34 volumio volumio[983]: info: Done. May 31 11:27:34 volumio volumio[983]: info: Spotify config file written May 31 11:27:34 volumio volumio[983]: info: No need to fix Spotify hosts May 31 11:27:34 volumio sudo[23083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 31 11:27:34 volumio sudo[23083]: pam_unix(sudo:session): session opened for user root by (uid=0) May 31 11:27:35 volumio systemd[1]: Started go-librespot Daemon. May 31 11:27:35 volumio go-librespot[23085]: go-librespot daemon starting... May 31 11:27:35 volumio sudo[23083]: pam_unix(sudo:session): session closed for user root May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=info msg="running go-librespot 0.7.1" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=debug msg="no app state found" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=debug msg="stored credentials not found" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=info msg="generated new device id: 4feb2dfebfac65aab3232f1eb70e48463c9b90a7" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=info msg="zeroconf server listening on port 45363" May 31 11:27:35 volumio go-librespot[23085]: time="2026-05-31T11:27:35+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration" May 31 11:27:38 volumio volumio[983]: info: go-librespot daemon successfully initialized May 31 11:27:40 volumio go-librespot[23085]: time="2026-05-31T11:27:40+02:00" level=debug msg="obtained new client token: AADMn8X+biaOHsz/sI6yjgHO/923zJ2JfX1Kj1+oQAewAkgBD6kaM2jv+v0RGEQuXtvoP1oAEaAlcdsCQooQQm0EaPchJHaX9yRUVHSGBIV0Y5/1LhLGUfbj98rTmIsIOMpYs0ZONsxDkuMs6FR0KJfsgjKuE1iy7Leqcmmy+QOKjwPaJwqe3kYcK+lSqm/LE/A5Ueqs/GIiAcyJzJG7IxQP3cMOhJjVd7aSVUh9oM7vaia1ayIjmQ==" May 31 11:27:40 volumio go-librespot[23085]: time="2026-05-31T11:27:40+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="completed keyexchange" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="completed challenge" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=info msg="authenticated AP" username="sp***so" May 31 11:27:41 volumio volumio[983]: info: Initializing connection to go-librespot Websocket May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="new websocket client" May 31 11:27:41 volumio volumio[983]: info: Connection to go-librespot Websocket established May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=info msg="authenticated Login5" username="sp***so" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=info msg="accepted zeroconf from iPhone" username="sp***so" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="dealer connection opened" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="starting accesspoint recv loop" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="starting dealer recv loop" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="received accesspoint ping" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="received connection id: YTZmOTcxNWQtYjE3...NTY4RDIwNDE4Mw==" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="received accesspoint pong ack" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="put connect state because NEW_DEVICE" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="update volume requested to 65535/65535" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="handling transfer player command from 21ef8b275a71c2aa432a4565741ca94324c4556b" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="resolved context of track" uri="spotify:album:6rgYzxu0cLIZchJFtNro98" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="fetched new page 0 with 14 items (list: 14)" uri="spotify:album:6rgYzxu0cLIZchJFtNro98" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="loading track (paused: true, position: 171787ms)" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="emitting websocket event: will_play" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1222" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="selected format OGG_VORBIS_320 (3fbebcb71703e97a8eefbcf690b53ab24597269d)" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="requested aes key for file 3fbebcb71703e97a8eefbcf690b53ab24597269d, gid: 1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="fetched first chunk of 15, total size is 7476484 bytes" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="fetched chunk 14/14, size: 136452" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="fetched chunk 13/14, size: 524288" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="seek to 171787ms (diff: 98ms, samples: 7575806, bytes: 6982154)" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="created new output device" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=info msg="loaded track \"I Stockholm - Live\" (paused: true, position: 171787ms, duration: 180160ms, prefetched: false)" uri="spotify:track:1Nc3lWHBXPJleFDNNOX6hr" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="emitting websocket event: metadata" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="emitting websocket event: active" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="sending successful reply for dealer request" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 31 11:27:41 volumio volumio[983]: info: Aligning Spotify Volume to Volumio Volume May 31 11:27:41 volumio volumio[983]: info: CoreCommandRouter::volumioGetState May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="emitting websocket event: paused" May 31 11:27:41 volumio volumio[983]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 11:27:41 volumio volumio[983]: TypeError: Cannot read property 'service' of undefined May 31 11:27:41 volumio volumio[983]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:345:50) May 31 11:27:41 volumio volumio[983]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:279:18) May 31 11:27:41 volumio volumio[983]: at WebSocket.message (/data/plugins/music_service/spop/index.js:198:14) May 31 11:27:41 volumio volumio[983]: at WebSocket.emit (events.js:315:20) May 31 11:27:41 volumio volumio[983]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1225:20) May 31 11:27:41 volumio volumio[983]: at Receiver.emit (events.js:315:20) May 31 11:27:41 volumio volumio[983]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 31 11:27:41 volumio volumio[983]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 31 11:27:41 volumio volumio[983]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 31 11:27:41 volumio volumio[983]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 31 11:27:41 volumio volumio[983]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 31 11:27:41 volumio go-librespot[23085]: time="2026-05-31T11:27:41+02:00" level=trace msg="emitting websocket event: volume" May 31 11:27:42 volumio sudo[23105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-05-31 11:26 May 31 11:27:42 volumio sudo[23105]: 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="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"