-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Thu 2025-06-26 17:55:38 EDT. -- Jun 26 17:55:30 excelsior go-librespot[1189]: time="2025-06-26T17:55:30-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-09-27T05:42:44-04:00 is before 2025-01-06T00:00:00Z" Jun 26 17:55:30 excelsior systemd[1]: Starting Daily apt download activities... Jun 26 17:55:30 excelsior systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 17:55:30 excelsior systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 17:55:31 excelsior volumio[870]: info: Discovery: A device disappeared from network Jun 26 17:55:31 excelsior volumio[870]: info: Discovery: Device excelsior disappeared from network Jun 26 17:55:31 excelsior volumio[870]: info: Discovery: adding 936c423d-82da-4d92-98ff-afb718ad6ddc Jun 26 17:55:31 excelsior volumio[870]: info: Discovery: Found device Excelsior Jun 26 17:55:31 excelsior volumio[870]: info: CoreCommandRouter::volumioGetState Jun 26 17:55:31 excelsior volumio[870]: info: CorePlayQueue::getTrack 0 Jun 26 17:55:31 excelsior systemd[1]: apt-daily.service: Succeeded. Jun 26 17:55:31 excelsior systemd[1]: Started Daily apt download activities. Jun 26 17:55:31 excelsior systemd[1]: Starting Daily apt upgrade and clean activities... Jun 26 17:55:32 excelsior systemd[1]: apt-daily-upgrade.service: Succeeded. Jun 26 17:55:32 excelsior systemd[1]: Started Daily apt upgrade and clean activities. Jun 26 17:55:33 excelsior volumio[870]: info: Initializing connection to go-librespot Websocket Jun 26 17:55:33 excelsior volumio[870]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 17:55:33 excelsior systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 26 17:55:33 excelsior systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jun 26 17:55:33 excelsior systemd[1]: Stopped go-librespot Daemon. Jun 26 17:55:33 excelsior systemd[1]: Started go-librespot Daemon. Jun 26 17:55:33 excelsior go-librespot[1331]: go-librespot daemon starting... Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=info msg="running go-librespot 0.2.0" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=debug msg="app state loaded" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=debug msg="stored credentials not found" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 26 17:55:34 excelsior go-librespot[1331]: time="2025-06-26T17:55:34-04:00" level=info msg="zeroconf server listening on port 41287" Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 26 17:55:34 excelsior volumio[870]: info: Adding plugin bluetooth to MyMusic Plugins Jun 26 17:55:34 excelsior volumio[870]: info: Adding plugin multiroom to MyMusic Plugins Jun 26 17:55:34 excelsior volumio[870]: info: Adding plugin metavolumio to MyMusic Plugins Jun 26 17:55:34 excelsior volumio[870]: info: Adding plugin cd_controller to MyMusic Plugins Jun 26 17:55:34 excelsior volumio[870]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 26 17:55:34 excelsior volumio[870]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 26 17:55:34 excelsior volumio[870]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 26 17:55:35 excelsior volumio[870]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 26 17:55:35 excelsior volumio[870]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 26 17:55:35 excelsior volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 26 17:55:35 excelsior volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 26 17:55:35 excelsior volumio[870]: info: Starting MyVolumio Remote Streaming Endpoints Jun 26 17:55:35 excelsior volumio[870]: info: MyVolumio login type: Token Jun 26 17:55:35 excelsior volumio[870]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 26 17:55:35 excelsior volumio[870]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 26 17:55:35 excelsior wpa_supplicant[708]: wlan0: Failed to initiate sched scan Jun 26 17:55:36 excelsior volumio[870]: info: Starting Streaming Service Transparent Proxy Jun 26 17:55:36 excelsior volumio[870]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 26 17:55:36 excelsior volumio[870]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 26 17:55:36 excelsior volumio[870]: info: Streaming services startup Jun 26 17:55:36 excelsior volumio[870]: info: Starting Streaming Daemon Jun 26 17:55:36 excelsior sudo[1348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 26 17:55:36 excelsior sudo[1348]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 26 17:55:36 excelsior sudo[1348]: pam_unix(sudo:session): session closed for user root Jun 26 17:55:36 excelsior volumio[870]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 26 17:55:36 excelsior volumio[870]: error: Cannot start Volumio Streaming Daemon Jun 26 17:55:36 excelsior volumio[870]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 26 17:55:36 excelsior volumio[870]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 26 17:55:36 excelsior volumio[870]: info: Initializing connection to go-librespot Websocket Jun 26 17:55:36 excelsior go-librespot[1331]: time="2025-06-26T17:55:36-04:00" level=debug msg="new websocket client" Jun 26 17:55:36 excelsior volumio[870]: info: Connection to go-librespot Websocket established Jun 26 17:55:36 excelsior volumio[870]: error: MyVolumio Custom Token format not valid, refreshing it Jun 26 17:55:36 excelsior go-librespot[1331]: time="2025-06-26T17:55:36-04:00" level=debug msg="obtained new client token: AABW8art3M6I8k30u8LjQTO+ntenQZ73Aai1dcE5CtyIfTrXMisnwEw+XZOO7UHodCln5yxOm9m2G+Xvpb/wMpLR4isJsS0cGvQywReGxmRzEJV4AIU9cfLO7QL0iC2A0mhwGKcQut5bxjweY0RX2df3KOFV+aojea61GDiI5FxQ8o71xjVm7GXYRJfyQJc6D4f7B8Cmg6Sb/JHmaD38mb7Fo5038l4N8xOLwB2gussWZHoDVwf31I4dXE8=" Jun 26 17:55:36 excelsior go-librespot[1331]: time="2025-06-26T17:55:36-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 26 17:55:36 excelsior go-librespot[1331]: time="2025-06-26T17:55:36-04:00" level=debug msg="completed keyexchange" Jun 26 17:55:36 excelsior go-librespot[1331]: time="2025-06-26T17:55:36-04:00" level=debug msg="completed challenge" Jun 26 17:55:36 excelsior go-librespot[1331]: time="2025-06-26T17:55:36-04:00" level=info msg="authenticated AP as kez2l223zgi8fwf8gw1l9j1f0" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=info msg="authenticated Login5 as kez2l223zgi8fwf8gw1l9j1f0" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=info msg="accepted zeroconf user kez2l223zgi8fwf8gw1l9j1f0 from iPhone" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="dealer connection opened" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=trace msg="starting accesspoint recv loop" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=trace msg="starting dealer recv loop" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=trace msg="received accesspoint ping" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="received connection id: YzcyYjVkYjQtNmUzNC00ZWQ5LWI1YjMtN2QyNTNiMDhlMWQxK2RlYWxlcit0Y3A6Ly8wYWIxNDI1ZC5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArRTAyQTQxQkQwNEI3NEVEQzQ1RDQxNTBGNEU1NUIxRjAwNkQxQUQ0NDFDNjQ2RTM5RUIxRUZEQTJGNDYxNTg0QQ==" Jun 26 17:55:37 excelsior volumio[870]: STREAMING PROXY: Starting server on port 3245 Jun 26 17:55:37 excelsior volumio[870]: Node JS runtime: 14 Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=trace msg="received accesspoint pong ack" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="put connect state because NEW_DEVICE" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="update volume to 65535/65535" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="handling transfer player command from 29fb0d05026eac2f35d0fa7f7ea808e2c1264c8f" Jun 26 17:55:37 excelsior volumio[870]: info: MyVolumio login type: Token Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZEVXcC1n1ixxPfbU" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=trace msg="fetched new page 0 with 30 items (list: 30)" uri="spotify:playlist:37i9dQZEVXcC1n1ixxPfbU" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="shuffled context with seed 15472181333365718200 (len: 30, keep: 6)" uri="spotify:playlist:37i9dQZEVXcC1n1ixxPfbU" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="loading track (paused: true, position: 84ms)" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:37 excelsior volumio[870]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 26 17:55:37 excelsior volumio[870]: info: MYVOLUMIO: Adding device Jun 26 17:55:37 excelsior volumio[870]: info: MYVOLUMIO: Evaluating Server Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=trace msg="emitting websocket event: will_play" Jun 26 17:55:37 excelsior volumio[870]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:55hPb6TlB1E6Me2Fc23Jp1","play_origin":"com.spotify.service.carplayv2"}} Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="selected format OGG_VORBIS_320 (ec7845ac8ada88574c2e4a576a169f324d65d469)" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="requested aes key for file ec7845ac8ada88574c2e4a576a169f324d65d469, gid: 55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:37 excelsior go-librespot[1331]: time="2025-06-26T17:55:37-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1370" Jun 26 17:55:38 excelsior volumio[870]: info: MyVolumio status changed Jun 26 17:55:38 excelsior volumio[870]: info: Streaming services startup Jun 26 17:55:38 excelsior volumio[870]: info: Starting Streaming Daemon Jun 26 17:55:38 excelsior volumio[870]: info: Removing browser output: myVolumio user plan is not superstar Jun 26 17:55:38 excelsior volumio[870]: info: Removing audio output: Jun 26 17:55:38 excelsior volumio[870]: info: Stoppping Tunnel 1 Jun 26 17:55:38 excelsior sudo[1371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 26 17:55:38 excelsior sudo[1371]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 26 17:55:38 excelsior sudo[1374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 26 17:55:38 excelsior sudo[1374]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 26 17:55:38 excelsior sudo[1371]: pam_unix(sudo:session): session closed for user root Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="fetched first chunk of 16, total size is 8187417 bytes" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=trace msg="seek to 84ms (diff: 84ms, samples: 3704, bytes: 0)" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="created new output device" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=info msg="loaded track \"When U Go - Edit\" (paused: true, position: 84ms, duration: 212724ms, prefetched: false)" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1130" Jun 26 17:55:38 excelsior volumio[870]: error: Cannot start Volumio Streaming Daemon Jun 26 17:55:38 excelsior volumio[870]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 26 17:55:38 excelsior volumio[870]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 26 17:55:38 excelsior sudo[1374]: pam_unix(sudo:session): session closed for user root Jun 26 17:55:38 excelsior volumio[870]: info: Remote SSH Stopped Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:55hPb6TlB1E6Me2Fc23Jp1" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=trace msg="emitting websocket event: metadata" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=trace msg="emitting websocket event: active" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="sending successful reply for dealer request" Jun 26 17:55:38 excelsior volumio[870]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:55hPb6TlB1E6Me2Fc23Jp1","name":"When U Go - Edit","artist_names":["Girls of the Internet"],"album_name":"When U Go","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0268f8edf44fa389ca84ec4a99","position":84,"duration":212724,"release_date":"year:2017 month:5 day:12","track_number":1,"disc_number":1}} Jun 26 17:55:38 excelsior volumio[870]: SPOTIFY: received: {"type":"active","data":null} Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 26 17:55:38 excelsior volumio[870]: info: Aligning Spotify Volume to Volumio Volume Jun 26 17:55:38 excelsior volumio[870]: info: CoreCommandRouter::volumioGetState Jun 26 17:55:38 excelsior volumio[870]: info: CorePlayQueue::getTrack 0 Jun 26 17:55:38 excelsior volumio[870]: info: Setting Geolocation for MyVolumio to us1 Jun 26 17:55:38 excelsior volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 26 17:55:38 excelsior volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 26 17:55:38 excelsior volumio[870]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=trace msg="emitting websocket event: paused" Jun 26 17:55:38 excelsior volumio[870]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:55hPb6TlB1E6Me2Fc23Jp1","play_origin":"com.spotify.service.carplayv2"}} Jun 26 17:55:38 excelsior volumio[870]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 26 17:55:38 excelsior volumio[870]: TypeError: Cannot read property 'service' of undefined Jun 26 17:55:38 excelsior volumio[870]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Jun 26 17:55:38 excelsior volumio[870]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:274:18) Jun 26 17:55:38 excelsior volumio[870]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Jun 26 17:55:38 excelsior volumio[870]: at WebSocket.emit (events.js:315:20) Jun 26 17:55:38 excelsior volumio[870]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 26 17:55:38 excelsior volumio[870]: at Receiver.emit (events.js:315:20) Jun 26 17:55:38 excelsior volumio[870]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 26 17:55:38 excelsior volumio[870]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 26 17:55:38 excelsior volumio[870]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 26 17:55:38 excelsior volumio[870]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 26 17:55:38 excelsior volumio[870]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 26 17:55:38 excelsior volumio[870]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 26 17:55:38 excelsior volumio[870]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 26 17:55:38 excelsior volumio[870]: at Socket.emit (events.js:315:20) Jun 26 17:55:38 excelsior volumio[870]: at addChunk (internal/streams/readable.js:309:12) Jun 26 17:55:38 excelsior volumio[870]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 26 17:55:38 excelsior volumio[870]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 26 17:55:38 excelsior go-librespot[1331]: time="2025-06-26T17:55:38-04:00" level=trace msg="emitting websocket event: volume" Jun 26 17:55:38 excelsior sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-26 17:54 Jun 26 17:55:38 excelsior sudo[1390]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"