-- Logs begin at Thu 2019-02-14 10:11:58 UTC, end at Thu 2025-09-11 20:45:45 UTC. -- Sep 11 20:44:02 volumiorasp volumio[996]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Sep 11 20:44:02 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Sep 11 20:44:02 volumiorasp volumio[996]: info: Creating Spotify config file Sep 11 20:44:02 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 20:44:02 volumiorasp volumio[996]: info: Spotify config file written Sep 11 20:44:02 volumiorasp sudo[1509]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 11 20:44:02 volumiorasp sudo[1509]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:44:02 volumiorasp systemd[1]: Stopping go-librespot Daemon... Sep 11 20:44:02 volumiorasp systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 11 20:44:02 volumiorasp systemd[1]: go-librespot-daemon.service: Succeeded. Sep 11 20:44:02 volumiorasp systemd[1]: Stopped go-librespot Daemon. Sep 11 20:44:02 volumiorasp volumio[996]: info: Connection to go-librespot Websocket closed Sep 11 20:44:03 volumiorasp systemd[1]: Started go-librespot Daemon. Sep 11 20:44:03 volumiorasp go-librespot[1511]: Librespot-go daemon starting... Sep 11 20:44:03 volumiorasp sudo[1509]: pam_unix(sudo:session): session closed for user root Sep 11 20:44:03 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:03Z" level=info msg="generated new device id: 7fc9292b2604a7c141826c94002853fd8c39c4db" Sep 11 20:44:03 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:03Z" 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]" Sep 11 20:44:03 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:03Z" 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]" Sep 11 20:44:03 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:03Z" 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]" Sep 11 20:44:03 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:03Z" level=debug msg="zeroconf server listening on port 35695" Sep 11 20:44:05 volumiorasp volumio[996]: info: Initializing connection to go-librespot Websocket Sep 11 20:44:05 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:05Z" level=debug msg="new websocket client" Sep 11 20:44:05 volumiorasp volumio[996]: info: Connection to go-librespot Websocket established Sep 11 20:44:06 volumiorasp volumio[996]: info: go-librespot daemon successfully initialized Sep 11 20:44:07 volumiorasp volumio[996]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 11 20:44:08 volumiorasp volumio[996]: info: Getting Spotify volume Sep 11 20:44:08 volumiorasp volumio[996]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Sep 11 20:44:08 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:44:08 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:08 volumiorasp volumio[996]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Sep 11 20:44:09 volumiorasp volumio[996]: info: Initializing connection to go-librespot Websocket Sep 11 20:44:09 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:09Z" level=debug msg="new websocket client" Sep 11 20:44:09 volumiorasp volumio[996]: info: Connection to go-librespot Websocket established Sep 11 20:44:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 11 20:44:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 11 20:44:12 volumiorasp volumio[996]: info: Getting Spotify volume Sep 11 20:44:12 volumiorasp volumio[996]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Sep 11 20:44:12 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:44:12 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:12 volumiorasp volumio[996]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Sep 11 20:44:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:44:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:44:16 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:44:16 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:44:16 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:44:22 volumiorasp go-librespot[1511]: time="2025-09-11T20:44:22Z" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Sep 11 20:44:22 volumiorasp volumio[996]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Sep 11 20:44:22 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 11 20:44:22 volumiorasp volumio[996]: info: Disabling plugin spop Sep 11 20:44:22 volumiorasp volumio[996]: info: Done. Sep 11 20:44:22 volumiorasp volumio[996]: info: Connection to go-librespot Websocket closed Sep 11 20:44:22 volumiorasp sudo[1579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Sep 11 20:44:22 volumiorasp sudo[1579]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:44:22 volumiorasp systemd[1]: Stopping go-librespot Daemon... Sep 11 20:44:22 volumiorasp systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 11 20:44:22 volumiorasp systemd[1]: go-librespot-daemon.service: Succeeded. Sep 11 20:44:22 volumiorasp systemd[1]: Stopped go-librespot Daemon. Sep 11 20:44:22 volumiorasp volumio[996]: info: Connection to go-librespot Websocket closed Sep 11 20:44:22 volumiorasp sudo[1579]: pam_unix(sudo:session): session closed for user root Sep 11 20:44:23 volumiorasp volumio[996]: info: Enabling plugin spop Sep 11 20:44:23 volumiorasp volumio[996]: info: Loading plugin "spop"... Sep 11 20:44:23 volumiorasp volumio[996]: info: PLUGIN START: spop Sep 11 20:44:23 volumiorasp volumio[996]: info: Creating Spotify config file Sep 11 20:44:23 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 20:44:23 volumiorasp volumio[996]: info: Done. Sep 11 20:44:23 volumiorasp volumio[996]: info: Spotify config file written Sep 11 20:44:23 volumiorasp volumio[996]: info: No need to fix Spotify hosts Sep 11 20:44:23 volumiorasp sudo[1596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 11 20:44:23 volumiorasp sudo[1596]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:44:23 volumiorasp volumio[996]: info: An error occurred while refreshing Spotify Token Error: Bad Request Sep 11 20:44:23 volumiorasp systemd[1]: Started go-librespot Daemon. Sep 11 20:44:23 volumiorasp go-librespot[1598]: Librespot-go daemon starting... Sep 11 20:44:23 volumiorasp sudo[1596]: pam_unix(sudo:session): session closed for user root Sep 11 20:44:23 volumiorasp go-librespot[1598]: time="2025-09-11T20:44:23Z" level=info msg="generated new device id: c8597337bf1972766584633410da6a92cba72a86" Sep 11 20:44:23 volumiorasp go-librespot[1598]: time="2025-09-11T20:44:23Z" 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]" Sep 11 20:44:23 volumiorasp go-librespot[1598]: time="2025-09-11T20:44:23Z" 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]" Sep 11 20:44:23 volumiorasp go-librespot[1598]: time="2025-09-11T20:44:23Z" 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]" Sep 11 20:44:23 volumiorasp go-librespot[1598]: time="2025-09-11T20:44:23Z" level=debug msg="zeroconf server listening on port 39075" Sep 11 20:44:26 volumiorasp volumio[996]: info: go-librespot daemon successfully initialized Sep 11 20:44:26 volumiorasp volumio[996]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Sep 11 20:44:26 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 11 20:44:26 volumiorasp volumio[996]: info: Disabling plugin spop Sep 11 20:44:26 volumiorasp volumio[996]: info: Done. Sep 11 20:44:26 volumiorasp sudo[1607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Sep 11 20:44:26 volumiorasp sudo[1607]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:44:26 volumiorasp systemd[1]: Stopping go-librespot Daemon... Sep 11 20:44:26 volumiorasp systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 11 20:44:26 volumiorasp systemd[1]: go-librespot-daemon.service: Succeeded. Sep 11 20:44:26 volumiorasp systemd[1]: Stopped go-librespot Daemon. Sep 11 20:44:26 volumiorasp sudo[1607]: pam_unix(sudo:session): session closed for user root Sep 11 20:44:27 volumiorasp volumio[996]: info: Enabling plugin spop Sep 11 20:44:27 volumiorasp volumio[996]: info: Loading plugin "spop"... Sep 11 20:44:27 volumiorasp volumio[996]: info: PLUGIN START: spop Sep 11 20:44:27 volumiorasp volumio[996]: info: Creating Spotify config file Sep 11 20:44:27 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 11 20:44:27 volumiorasp volumio[996]: info: Done. Sep 11 20:44:27 volumiorasp volumio[996]: info: Spotify config file written Sep 11 20:44:27 volumiorasp volumio[996]: info: No need to fix Spotify hosts Sep 11 20:44:27 volumiorasp sudo[1610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 11 20:44:27 volumiorasp sudo[1610]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:44:27 volumiorasp volumio[996]: info: An error occurred while refreshing Spotify Token Error: Bad Request Sep 11 20:44:27 volumiorasp systemd[1]: Started go-librespot Daemon. Sep 11 20:44:27 volumiorasp go-librespot[1612]: Librespot-go daemon starting... Sep 11 20:44:27 volumiorasp sudo[1610]: pam_unix(sudo:session): session closed for user root Sep 11 20:44:27 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:27Z" level=info msg="generated new device id: b72145fe762a5940d47e2bc975579bd75b59b011" Sep 11 20:44:27 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:27Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Sep 11 20:44:27 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:27Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 11 20:44:27 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:27Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 11 20:44:27 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:27Z" level=debug msg="zeroconf server listening on port 34251" Sep 11 20:44:29 volumiorasp volumio[996]: info: Initializing connection to go-librespot Websocket Sep 11 20:44:29 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:29Z" level=debug msg="new websocket client" Sep 11 20:44:29 volumiorasp volumio[996]: info: Connection to go-librespot Websocket established Sep 11 20:44:30 volumiorasp volumio[996]: info: go-librespot daemon successfully initialized Sep 11 20:44:32 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetQueue Sep 11 20:44:32 volumiorasp volumio[996]: info: CoreStateMachine::getQueue Sep 11 20:44:32 volumiorasp volumio[996]: info: CorePlayQueue::getQueue Sep 11 20:44:32 volumiorasp volumio[996]: info: Getting Spotify volume Sep 11 20:44:32 volumiorasp volumio[996]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 11 20:44:32 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:44:32 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:32 volumiorasp volumio[996]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Sep 11 20:44:33 volumiorasp volumio[996]: info: Initializing connection to go-librespot Websocket Sep 11 20:44:33 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:33Z" level=debug msg="new websocket client" Sep 11 20:44:33 volumiorasp volumio[996]: info: Connection to go-librespot Websocket established Sep 11 20:44:36 volumiorasp volumio[996]: info: Getting Spotify volume Sep 11 20:44:36 volumiorasp volumio[996]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 11 20:44:36 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:44:36 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:36 volumiorasp volumio[996]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Sep 11 20:44:39 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 11 20:44:42 volumiorasp volumio[996]: error: Error browsing0:Error: connect EHOSTUNREACH 192.168.178.125:50001 Sep 11 20:44:42 volumiorasp volumio[996]: error: Failed to execute browseSource: Sep 11 20:44:44 volumiorasp volumio[996]: info: CoreCommandRouter::volumioPlay Sep 11 20:44:44 volumiorasp volumio[996]: info: CoreStateMachine::play index undefined Sep 11 20:44:44 volumiorasp volumio[996]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 11 20:44:44 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:46 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:44:46 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:44:46 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:44:46 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:44:46 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:44:46 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:44:50 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:50Z" level=debug msg="obtained new client token: AADXI6xOPMAtxucyO20RBv/4WNTjM0BahoMo26qo0KZVe/U9HgRAVQC0ahOyn65r2rmeLUMmXgh5UX5ALXXtfbnKFny+Zi0DQrITSqykg4OXETf863pRv22utp1za10edStuTcPVr2yMF5pW0qM+4KLz879DaQeHJTUk4Vbne2yUa8zoU9S+uLKNhSo2E3wR9YSrQJpSrpJMjwc7ob2nJVoe1X6aGkTjmf5TpBayC1uPChHiANbg1aU9fYX0Gw==" Sep 11 20:44:50 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:50Z" level=info msg="connected to ap-gew4.spotify.com:4070" Sep 11 20:44:50 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:50Z" level=debug msg="completed keyexchange" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="completed challenge" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="authenticated as 31kkdidd3zqkeskldnrgkuyipu3y" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="authenticated as 31kkdidd3zqkeskldnrgkuyipu3y" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="dealer connection opened" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=info msg="accepted zeroconf user 31kkdidd3zqkeskldnrgkuyipu3y from S23+ di Stefano" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="autoplay enabled: false" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="received connection id: ZGVjYWNmODMtZjk3Mi00YTQwLWFiOWMtNDQ5N2FiODA0MjJkK2RlYWxlcit0Y3A6Ly8wYWIxNTFlMC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNUM5NEU3MDFCRDY1NkYxMzhEMjgxREJENzc2OUFCQkU3QkFEMTkwMzhCNDI3MjlCNjYwQUZBRjU3NTMxQTE2Ng==" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="put connect state because NEW_DEVICE" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="handling transfer player command from c883b7d56c7451d3a22df6a1db5a8bd194b2eed5" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="resolved context of track" uri="spotify:artist:1dfeR4HaWDbWqFHLkxsg1d" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=trace msg="fetched new page 0 with 10 items (list: 10)" uri="spotify:artist:1dfeR4HaWDbWqFHLkxsg1d" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="loading track (paused: false, position: 39410ms)" uri="spotify:track:5T8EDUDqKcs6OSOwEsfqG7" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=trace msg="emitting websocket event: will_play" Sep 11 20:44:51 volumiorasp volumio[996]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5T8EDUDqKcs6OSOwEsfqG7","play_origin":"free-tier-artist"}} Sep 11 20:44:51 volumiorasp volumio[996]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5T8EDUDqKcs6OSOwEsfqG7","play_origin":"free-tier-artist"}} Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=warning msg="failed handling dealer request" error="failed loading current track (transfer): failed creating stream for spotify:track:5T8EDUDqKcs6OSOwEsfqG7: no supported formats" Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 11 20:44:51 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:51Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1709" Sep 11 20:44:52 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:52Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Sep 11 20:44:52 volumiorasp go-librespot[1612]: time="2025-09-11T20:44:52Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1301" Sep 11 20:45:08 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Sep 11 20:45:08 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Sep 11 20:45:08 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Sep 11 20:45:08 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Sep 11 20:45:10 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetVisibleSources Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:11 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 11 20:45:11 volumiorasp volumio[996]: info: Received Get System Info Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:11 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:11 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:11 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:11 volumiorasp volumio[996]: info: Listing playlists Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetQueue Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreStateMachine::getQueue Sep 11 20:45:11 volumiorasp volumio[996]: info: CorePlayQueue::getQueue Sep 11 20:45:11 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 11 20:45:12 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89:3000 from 192.168.178.175 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:13 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:13 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:13 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89:3000 from 192.168.178.175 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 12 Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:13 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 11 20:45:13 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 11 20:45:14 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:14 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:14 volumiorasp sudo[1739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 11 20:45:14 volumiorasp sudo[1739]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:14 volumiorasp sudo[1739]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:14 volumiorasp sudo[1741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 11 20:45:14 volumiorasp sudo[1741]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:14 volumiorasp sudo[1741]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:15 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Sep 11 20:45:15 volumiorasp sudo[1745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 11 20:45:15 volumiorasp sudo[1745]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:15 volumiorasp sudo[1745]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:15 volumiorasp sudo[1747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 11 20:45:15 volumiorasp sudo[1747]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:15 volumiorasp sudo[1747]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:15 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetVisibleSources Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:15 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 11 20:45:15 volumiorasp volumio[996]: info: Received Get System Info Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:15 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:15 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:15 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:15 volumiorasp volumio[996]: info: Listing playlists Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 11 20:45:15 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 11 20:45:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:16 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:16 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:16 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:16 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 11 20:45:17 volumiorasp volumio[996]: info: Received Get System Info Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:17 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:17 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Sep 11 20:45:17 volumiorasp sudo[1753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Sep 11 20:45:17 volumiorasp sudo[1753]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:17 volumiorasp sudo[1758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Sep 11 20:45:17 volumiorasp sudo[1758]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:17 volumiorasp sudo[1753]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:17 volumiorasp sudo[1758]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:17 volumiorasp sudo[1765]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Sep 11 20:45:17 volumiorasp sudo[1765]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:17 volumiorasp sudo[1771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Sep 11 20:45:17 volumiorasp sudo[1771]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:17 volumiorasp sudo[1765]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:17 volumiorasp sudo[1771]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:17 volumiorasp sudo[1779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 11 20:45:17 volumiorasp sudo[1779]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Sep 11 20:45:17 volumiorasp sudo[1779]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:17 volumiorasp sudo[1781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 11 20:45:17 volumiorasp sudo[1781]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:17 volumiorasp sudo[1781]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 11 20:45:17 volumiorasp volumio[996]: info: Received Get System Info Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:17 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:17 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:17 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:17 volumiorasp sudo[1785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 11 20:45:17 volumiorasp sudo[1785]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:21 volumiorasp sudo[1785]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:22 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89:3000 from 192.168.178.175 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 14 Sep 11 20:45:25 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 11 20:45:33 volumiorasp volumio[996]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 11 20:45:33 volumiorasp volumio[996]: info: Received Get System Version Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 11 20:45:33 volumiorasp volumio[996]: info: Received Get System Info Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:33 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:33 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:33 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:35 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetQueue Sep 11 20:45:35 volumiorasp volumio[996]: info: CoreStateMachine::getQueue Sep 11 20:45:35 volumiorasp volumio[996]: info: CorePlayQueue::getQueue Sep 11 20:45:38 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 11 20:45:41 volumiorasp volumio[996]: info: Preload queue cleared Sep 11 20:45:43 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:43 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:44 volumiorasp sudo[1835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 11 20:45:44 volumiorasp sudo[1835]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:44 volumiorasp sudo[1835]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:44 volumiorasp sudo[1837]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 11 20:45:44 volumiorasp sudo[1837]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:44 volumiorasp sudo[1837]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:44 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Sep 11 20:45:44 volumiorasp sudo[1841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 11 20:45:44 volumiorasp sudo[1841]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:44 volumiorasp sudo[1841]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:44 volumiorasp sudo[1843]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 11 20:45:44 volumiorasp sudo[1843]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 11 20:45:44 volumiorasp sudo[1843]: pam_unix(sudo:session): session closed for user root Sep 11 20:45:44 volumiorasp volumio[996]: verbose: New Socket.io Connection to 192.168.178.89 from 192.168.178.175 UA: Mozilla/5.0 (Linux; Android 15; SM-S916B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/139.0.7258.158 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetVisibleSources Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:44 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetQueue Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreStateMachine::getQueue Sep 11 20:45:44 volumiorasp volumio[996]: info: CorePlayQueue::getQueue Sep 11 20:45:44 volumiorasp volumio[996]: info: Listing playlists Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 11 20:45:44 volumiorasp volumio[996]: info: Received Get System Info Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 11 20:45:44 volumiorasp volumio[996]: info: Discovery: Getting this device information Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:44 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::volumioGetState Sep 11 20:45:44 volumiorasp volumio[996]: info: CorePlayQueue::getTrack 0 Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 11 20:45:44 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 11 20:45:45 volumiorasp volumio[996]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 11 20:45:45 volumiorasp volumio[996]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 11 20:45:45 volumiorasp volumio[996]: TypeError: Cannot read property 'length' of undefined Sep 11 20:45:45 volumiorasp volumio[996]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 11 20:45:45 volumiorasp volumio[996]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 11 20:45:45 volumiorasp volumio[996]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 11 20:45:45 volumiorasp volumio[996]: at Parser.emit (events.js:315:20) Sep 11 20:45:45 volumiorasp volumio[996]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 11 20:45:45 volumiorasp volumio[996]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 11 20:45:45 volumiorasp volumio[996]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 11 20:45:45 volumiorasp volumio[996]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 11 20:45:45 volumiorasp volumio[996]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 11 20:45:45 volumiorasp volumio[996]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 11 20:45:45 volumiorasp volumio[996]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 11 20:45:45 volumiorasp volumio[996]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 11 20:45:45 volumiorasp volumio[996]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 11 20:45:45 volumiorasp volumio[996]: at IncomingMessage.emit (events.js:327:22) Sep 11 20:45:45 volumiorasp volumio[996]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 11 20:45:45 volumiorasp volumio[996]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 11 20:45:45 volumiorasp volumio[996]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 11 20:45:45 volumiorasp sudo[1855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-11 20:44 Sep 11 20:45:45 volumiorasp sudo[1855]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"