Dec 15 20:10:01 volumio-hall volumio[23781]: info: go-librespot daemon successfully initialized Dec 15 20:10:02 volumio-hall sudo[24032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:10:02 volumio-hall sudo[24032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:02 volumio-hall sudo[24035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:10:02 volumio-hall sudo[24035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:02 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:10:02 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:10:02 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:02 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:02 volumio-hall mpd_monitor.sh[24037]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:10:02 volumio-hall sudo[24032]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:02 volumio-hall volumio[23781]: info: Successfully started MPD Monitor Dec 15 20:10:02 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:10:02 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:10:02 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:02 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:02 volumio-hall sudo[24035]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:02 volumio-hall volumio[23781]: info: Successfully started MPD Monitor Dec 15 20:10:02 volumio-hall mpd_monitor.sh[24040]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:10:02 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:10:02 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:03 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:03 volumio-hall go-librespot[24044]: go-librespot daemon starting... Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="app state loaded" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=info msg="zeroconf server listening on port 35135" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="obtained new client token: AAAOpBLNthG46hqhU2Z8YVGYllzlXoIuouRhFKcccs9KKAJJVzEeAMvQM8Bm38E1y06GgK7FLvW8+1X+HxOnpIKICvJoNk10aX+Okf7O0t+zs3gyghZedvPIf4SCYECe63zC0UUnY7RQccMIddkPnqZOkzjVTJpIpju+4csg8KBhTz1BhrTxisfa36mj412oqucghnr7K9F2iDnkPXQNmYNJHHKtw4RQHLA38vxlnk7z3vNqqT7HrcdD5w==" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:03 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:03+05:30" level=debug msg="completed challenge" Dec 15 20:10:04 volumio-hall volumio[23781]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:10:04 volumio-hall sudo[24067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:10:04 volumio-hall sudo[24067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:04 volumio-hall sudo[24069]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:10:04 volumio-hall sudo[24067]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:04 volumio-hall sudo[24069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:04 volumio-hall sudo[24069]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:04 volumio-hall volumio[23781]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:04 volumio-hall sudo[24072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:10:04 volumio-hall sudo[24072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:04 volumio-hall sudo[24072]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:04 volumio-hall volumio[23781]: info: Upmpdcli Daemon Started Dec 15 20:10:04 volumio-hall volumio[23781]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:10:04 volumio-hall volumio[23781]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:10:04 volumio-hall volumio[23781]: info: Discovery: Found device Volumio-Hall Dec 15 20:10:04 volumio-hall volumio[23781]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:04 volumio-hall volumio[23781]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:04 volumio-hall volumio[23781]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:10:05 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:05+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:10:05 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:10:05 volumio-hall volumio[23781]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:05 volumio-hall volumio[23781]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:06 volumio-hall go-librespot[24045]: time="2025-12-15T20:10:06+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:10:06 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:06 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:06 volumio-hall volumio[23781]: Cannot compose Albumart path Dec 15 20:10:07 volumio-hall volumio[23781]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:10:07 volumio-hall volumio[23781]: info: Discovery: Found device Volumio-Zero Dec 15 20:10:07 volumio-hall volumio[23781]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:10:07 volumio-hall volumio[23781]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:10:07 volumio-hall volumio[23781]: info: Discovery: Found device Volumio-Hall Dec 15 20:10:07 volumio-hall volumio[23781]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:07 volumio-hall volumio[23781]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:07 volumio-hall volumio[23781]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:07 volumio-hall volumio[23781]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:10:07 volumio-hall volumio[23781]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:07 volumio-hall volumio[23781]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:07 volumio-hall volumio[23781]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:10:07 volumio-hall volumio[23781]: info: Spotify Successfully logged in Dec 15 20:10:07 volumio-hall volumio[23781]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:07 volumio-hall volumio[23781]: info: [1765809607463] CoreMusicLibrary::Adding element Spotify Dec 15 20:10:07 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:07 volumio-hall volumio[23781]: Cannot find translation for source Spotify Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 20:10:08 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 20:10:09 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:10:09 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 20:10:09 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:09 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:09 volumio-hall volumio[23781]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 20:10:09 volumio-hall volumio[23781]: info: MyVolumio login type: Token Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 20:10:09 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:09 volumio-hall go-librespot[24079]: go-librespot daemon starting... Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="app state loaded" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=info msg="zeroconf server listening on port 38739" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="obtained new client token: AAAayk9b/eay2yt3lqU5bF0vwlr+ZtI4He4lP11jWH36C3m3hD4tb4Ylj10mQ22d2xRUF81pC4N8m9zU4ewnqoHvVIoWxRMjJ5F99jtMb0CfmCsc15m/zs+XSLhtAPPiBy2jWYkaJCzStkr+btHlKtQX7LccUQwv2jNeshm2HCsKQA4/5KAFo/lUe5f20ozqcVYS1RnTasDFu/UZIq3cAXDDitwNY0CK5eKJ9E/oRMTxxDFdY6DtO6zmTw==" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 20:10:09 volumio-hall volumio[23781]: info: Streaming services startup Dec 15 20:10:09 volumio-hall volumio[23781]: info: Starting Streaming Daemon Dec 15 20:10:09 volumio-hall sudo[24089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:10:09 volumio-hall sudo[24089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:09 volumio-hall volumio[23781]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 20:10:09 volumio-hall sudo[24089]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:09 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:09+05:30" level=debug msg="completed challenge" Dec 15 20:10:09 volumio-hall volumio[23781]: info: Cannot mount NAS AudioVideo at system boot, trial number 4 ,retrying in 5 seconds Dec 15 20:10:09 volumio-hall volumio[23781]: error: Cannot start Volumio Streaming Daemon Dec 15 20:10:09 volumio-hall volumio[23781]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:10:09 volumio-hall volumio[23781]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:10:10 volumio-hall go-librespot[24080]: time="2025-12-15T20:10:10+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:10 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:10 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:10 volumio-hall volumio[23781]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:10 volumio-hall volumio[23781]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:10 volumio-hall volumio[23781]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 20:10:11 volumio-hall volumio[23781]: info: MyVolumio token set successfully Dec 15 20:10:11 volumio-hall volumio[23781]: info: MYVOLUMIO: Adding device Dec 15 20:10:11 volumio-hall volumio[23781]: info: MYVOLUMIO: Evaluating Server Dec 15 20:10:11 volumio-hall volumio[23781]: info: MyVolumio status changed Dec 15 20:10:11 volumio-hall volumio[23781]: info: Streaming services startup Dec 15 20:10:11 volumio-hall volumio[23781]: info: Starting Streaming Daemon Dec 15 20:10:11 volumio-hall volumio[23781]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 20:10:11 volumio-hall volumio[23781]: info: Removing audio output: Dec 15 20:10:11 volumio-hall volumio[23781]: info: Stoppping Tunnel 1 Dec 15 20:10:11 volumio-hall sudo[24116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:10:11 volumio-hall sudo[24116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:11 volumio-hall sudo[24118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 20:10:11 volumio-hall sudo[24118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:11 volumio-hall sudo[24116]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:11 volumio-hall volumio[23781]: error: Cannot start Volumio Streaming Daemon Dec 15 20:10:11 volumio-hall volumio[23781]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:10:11 volumio-hall volumio[23781]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:10:11 volumio-hall sudo[24118]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:11 volumio-hall volumio[23781]: info: Remote SSH Stopped Dec 15 20:10:12 volumio-hall volumio[23781]: info: Setting Geolocation for MyVolumio to as2 Dec 15 20:10:12 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:12 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:12 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:13 volumio-hall volumio[23781]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:13 volumio-hall volumio[23781]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:13 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:10:13 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:13 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:13 volumio-hall go-librespot[24121]: go-librespot daemon starting... Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=debug msg="app state loaded" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=info msg="zeroconf server listening on port 44557" Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=debug msg="obtained new client token: AADBQdaF8oi3DqCTtRlzkXZksQbewp6IzNFOA2p5jxPp1ucwP1/hggPsEiIq8/RZl0fJx+vKenYESVxRnaO24JmZO4GTHukDEz3CYtK4rUJk/Vj7wRPkyOGDxGmkDoVT81GV5Mi4wInPzpwx2rgppmi7fYO/eKvmFyorg8Yy4aKvdmkUGg2PmmJECUkb6YCzLe7CVC8LOS5nbJPiR2s2gFvOAF8O+A8HgUuwNw0pQHbPRHthuCHWklAkzg==" Dec 15 20:10:13 volumio-hall volumio[23781]: info: Updating MyVolumio device info Dec 15 20:10:13 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:13 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:13 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:13 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:13+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:14 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:14+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:14 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:14+05:30" level=debug msg="completed challenge" Dec 15 20:10:14 volumio-hall volumio[23781]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 15 20:10:14 volumio-hall volumio[23781]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 15 20:10:14 volumio-hall go-librespot[24122]: time="2025-12-15T20:10:14+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:14 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:14 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:14 volumio-hall volumio[23781]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Dec 15 20:10:16 volumio-hall volumio[23781]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:16 volumio-hall volumio[23781]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:17 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 20:10:17 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:18 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:18 volumio-hall go-librespot[24143]: go-librespot daemon starting... Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="app state loaded" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:18 volumio-hall volumio[23781]: info: MYVOLUMIO: Adding device Dec 15 20:10:18 volumio-hall volumio[23781]: info: MYVOLUMIO: Evaluating Server Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=info msg="zeroconf server listening on port 45567" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="obtained new client token: AAAHpxLIMNOcPfIP9TN9jlTXVmJ99flpCCECkvbEbfaCqBfG7Dwrw+3AEb2MNtcc5t/vmnj7vAt3xjQVJnTqI9mGTdmt/LwDji6JW37oVUE3dGzz1J3hMksybhDctPTo0JQOqV1oTQNptP1P4jvNar33eo+XFJgwaeaLR6KLVTXQHFXeoZpQsYJw1qOtbKB6LVfspPtDxYzFpVVlWoimI04mHWt1esX0SFGdg10D6Mtz27ImUYS02ZI2zA==" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=debug msg="completed challenge" Dec 15 20:10:18 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:18+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:10:19 volumio-hall volumio[23781]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:19 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:19+05:30" level=debug msg="new websocket client" Dec 15 20:10:19 volumio-hall volumio[23781]: info: Connection to go-librespot Websocket established Dec 15 20:10:19 volumio-hall volumio[23781]: info: Setting Geolocation for MyVolumio to as2 Dec 15 20:10:19 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:19 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:19 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:19 volumio-hall go-librespot[24144]: time="2025-12-15T20:10:19+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:10:19 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:19 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:19 volumio-hall volumio[23781]: info: Connection to go-librespot Websocket closed Dec 15 20:10:20 volumio-hall volumio[23781]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 15 20:10:20 volumio-hall volumio[23781]: info: Updating MyVolumio device info Dec 15 20:10:20 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:20 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:20 volumio-hall volumio[23781]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:21 volumio-hall volumio[23781]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 15 20:10:22 volumio-hall volumio[23781]: info: Getting Spotify volume Dec 15 20:10:22 volumio-hall volumio[23781]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:10:22 volumio-hall volumio[23781]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:22 volumio-hall volumio[23781]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 20:10:22 volumio-hall volumio[23781]: errno: -111, Dec 15 20:10:22 volumio-hall volumio[23781]: code: 'ECONNREFUSED', Dec 15 20:10:22 volumio-hall volumio[23781]: syscall: 'connect', Dec 15 20:10:22 volumio-hall volumio[23781]: address: '127.0.0.1', Dec 15 20:10:22 volumio-hall volumio[23781]: port: 9879, Dec 15 20:10:22 volumio-hall volumio[23781]: response: undefined Dec 15 20:10:22 volumio-hall volumio[23781]: } Dec 15 20:10:22 volumio-hall volumio[23781]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:10:22 volumio-hall sudo[24186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:09' Dec 15 20:10:22 volumio-hall sudo[24186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:22 volumio-hall sudo[24186]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:22 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:22] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Dec 15 20:10:22 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:22] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Dec 15 20:10:22 volumio-hall systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:22 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 20:10:22 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:22 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:22 volumio-hall go-librespot[24191]: go-librespot daemon starting... Dec 15 20:10:22 volumio-hall systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 20:10:22 volumio-hall systemd[1]: volumio.service: Consumed 22.309s CPU time. Dec 15 20:10:22 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:10:22 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:22+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:22+05:30" level=debug msg="app state loaded" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:23 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=info msg="zeroconf server listening on port 36939" Dec 15 20:10:23 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 59. Dec 15 20:10:23 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:10:23 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:10:23 volumio-hall systemd[1]: volumio.service: Consumed 22.309s CPU time. Dec 15 20:10:23 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:10:23 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="obtained new client token: AAClftNjADG79x4Vqy19EwrPXgyBKUkvwa2S2ceLIMEgXEEbiIn5Iu26PamwnDWE3vaSPUZaB2/Co7ervHM/iI2YK/s8ziuorESxoW9Qw/jA+eaFj2fKsjAF4q0/0ZaxWoNp0Pr89kuTy4+rBil3pU7QRwNzNtXAiRRbCF0GTzP0YjcwTAdBdOIKk1La3lANvpDQOPonlMihPxfS1Uqrc8j2lsTGbMdfDy11XNFqkc9kf8QN8IbnP8qcag==" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=debug msg="completed challenge" Dec 15 20:10:23 volumio-hall go-librespot[24192]: time="2025-12-15T20:10:23+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:23 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:23 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:24 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:24 volumio-hall volumio[24206]: info: ----- Volumio3 ---- Dec 15 20:10:24 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:24 volumio-hall volumio[24206]: info: ----- System startup ---- Dec 15 20:10:24 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:24 volumio-hall volumio[24206]: info: MYVOLUMIO Environment detected Dec 15 20:10:24 volumio-hall volumio[24206]: info: Plugin folders cleanup Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category audio_interface Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category miscellanea Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category music_service Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category plugins.json Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category system_controller Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category user_interface Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning into folder /data/plugins/ Dec 15 20:10:24 volumio-hall volumio[24206]: info: Scanning category music_service Dec 15 20:10:24 volumio-hall volumio[24206]: info: Plugin folders cleanup completed Dec 15 20:10:24 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:24 volumio-hall volumio[24206]: info: ----- Core plugins startup ---- Dec 15 20:10:24 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:24 volumio-hall volumio[24206]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:10:24 volumio-hall volumio[24206]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:10:24 volumio-hall volumio[24206]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:10:24 volumio-hall volumio[24206]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:10:24 volumio-hall volumio[24206]: info: Loading plugins from folder /data/plugins/ Dec 15 20:10:24 volumio-hall volumio[24206]: info: Loading plugin "system"... Dec 15 20:10:24 volumio-hall volumio[24206]: info: Loading plugin "appearance"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "network"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Refreshing Cached IP Addresses Dec 15 20:10:25 volumio-hall sudo[24237]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:10:25 volumio-hall sudo[24237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:25 volumio-hall sudo[24239]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:10:25 volumio-hall sudo[24239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:25 volumio-hall sudo[24237]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:25 volumio-hall sudo[24239]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "services"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "alsa_controller"... Dec 15 20:10:25 volumio-hall sudo[24248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:10:25 volumio-hall sudo[24248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:25 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "wizard"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "networkfs"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:10:25 volumio-hall volumio[24206]: info: Starting Udev Watcher for removable devices Dec 15 20:10:25 volumio-hall volumio[24206]: info: Ignoring mount for partition: boot Dec 15 20:10:25 volumio-hall volumio[24206]: info: Ignoring mount for partition: volumio Dec 15 20:10:25 volumio-hall volumio[24206]: info: Ignoring mount for partition: volumio_data Dec 15 20:10:25 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "upnp"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: [1765809625542] Starting Upmpd Daemon Dec 15 20:10:25 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "my_music"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "mpd"... Dec 15 20:10:25 volumio-hall volumio[24206]: info: Loading plugin "upnp_browser"... Dec 15 20:10:26 volumio-hall volumio[24206]: info: Starting UPNP Browser Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "alarm-clock"... Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "airplay_emulation"... Dec 15 20:10:26 volumio-hall volumio[24206]: info: Starting Shairport Sync Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "last_100"... Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "webradio"... Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "i2s_dacs"... Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "volumiodiscovery"... Dec 15 20:10:26 volumio-hall volumio[24206]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:26 volumio-hall node[24206]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:26 volumio-hall volumio[24206]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:26 volumio-hall node[24206]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:26 volumio-hall volumio[24206]: *** WARNING *** For more information see Dec 15 20:10:26 volumio-hall node[24206]: *** WARNING *** For more information see Dec 15 20:10:26 volumio-hall volumio[24206]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:26 volumio-hall node[24206]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:26 volumio-hall volumio[24206]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:26 volumio-hall node[24206]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:26 volumio-hall volumio[24206]: *** WARNING *** For more information see Dec 15 20:10:26 volumio-hall node[24206]: *** WARNING *** For more information see Dec 15 20:10:26 volumio-hall volumio[24206]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:10:26 volumio-hall volumio[24206]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:10:26 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:10:26 volumio-hall volumio[24206]: info: Loading plugin "spop"... Dec 15 20:10:26 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 20:10:26 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:27 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:27 volumio-hall go-librespot[24269]: go-librespot daemon starting... Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="app state loaded" Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading plugin "outputs"... Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=info msg="zeroconf server listening on port 33955" Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading plugin "albumart"... Dec 15 20:10:27 volumio-hall volumio[24206]: info: Plugin example_plugin is not enabled Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading plugin "inputs"... Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading plugin "updater_comm"... Dec 15 20:10:27 volumio-hall volumio[24206]: info: Plugin mpdemulation is not enabled Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading plugin "rest_api"... Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading plugin "websocket"... Dec 15 20:10:27 volumio-hall volumio[24206]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:10:27 volumio-hall volumio[24206]: info: Loading i18n strings for locale en Dec 15 20:10:27 volumio-hall volumio[24206]: Updating browse sources language Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="obtained new client token: AABQd4dvlk+4uUeCGU05Olb25HkkoeXxd3l/qjlkgdUjQ9QP7PLsriTwvxNa3Cw34eE1/Skwj/78VEaa2IT1QaDKpBD4G0Pj6ckJTggCsVzU6r2zxhkUuGnEALsj+sY7nGyLw37zHP9o/leNCVCtbpgL/7zylIRsXQiMCKOwp0uk15CnqlDa0xp+SaRUXW+V/ilFWOaPtZX7nfP++AS1skYu5ir6GRkZdCYsd8Wlb1dKUvKpkyPCp3W2Ig==" Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::initPlayerControls Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: Express server listening on port 3000 Dec 15 20:10:27 volumio-hall volumio[24206]: [Metrics] WebUI: 3s 440.24ms Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::resetVolumioState Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::getcurrentVolume Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:10:27 volumio-hall volumio[24206]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:27 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:27+05:30" level=debug msg="completed challenge" Dec 15 20:10:27 volumio-hall volumio[24277]: Forking 3 albumart workers Dec 15 20:10:27 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:10:27 volumio-hall volumio[24206]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:10:27 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: Reloading queue from file Dec 15 20:10:27 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:10:27 volumio-hall volumio[24206]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::pushState Dec 15 20:10:27 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::updateTrackBlock Dec 15 20:10:27 volumio-hall volumio[24206]: info: CorePlayQueue::getTrackBlock Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::pushState Dec 15 20:10:27 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::setRandom null Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreStateMachine::pushState Dec 15 20:10:27 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:27 volumio-hall volumio[24206]: info: Setting Device type: Raspberry PI Dec 15 20:10:27 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 15 20:10:27 volumio-hall volumio[24206]: info: Completed loading Core Plugins Dec 15 20:10:27 volumio-hall volumio[24206]: info: Preparing to generate the ALSA configuration file Dec 15 20:10:27 volumio-hall volumio[24206]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:10:27 volumio-hall volumio[24206]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:10:27 volumio-hall volumio[24206]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:10:27 volumio-hall volumio[24206]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:10:27 volumio-hall volumio[24206]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:10:27 volumio-hall volumio[24206]: info: Output device has changed, restarting MPD Dec 15 20:10:27 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:27] [connect] Successful connection Dec 15 20:10:27 volumio-hall volumio[24206]: info: Output device has changed, restarting Shairport Sync Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:27 volumio-hall sudo[24335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:10:27 volumio-hall volumio[24206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:10:27 volumio-hall sudo[24337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:10:27 volumio-hall volumio[24206]: info: ___________ START PLUGINS ___________ Dec 15 20:10:27 volumio-hall sudo[24337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:27 volumio-hall sudo[24335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:27 volumio-hall sudo[24335]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:27 volumio-hall volumio[24206]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:10:27 volumio-hall volumio[24206]: info: Creating MPD Configuration file Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:27 volumio-hall volumio[24206]: info: [1765809627997] CoreMusicLibrary::Adding element Media Servers Dec 15 20:10:27 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:28 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:10:28 volumio-hall volumio[24206]: info: UPNP Browser: Client initialized successfully Dec 15 20:10:28 volumio-hall sudo[24347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:10:28 volumio-hall sudo[24347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:28 volumio-hall sudo[24345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:10:28 volumio-hall sudo[24345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:28 volumio-hall sudo[24345]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:28 volumio-hall sudo[24248]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:28 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:10:28 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:10:28 volumio-hall systemd[1]: mpd.service: Consumed 2.470s CPU time. Dec 15 20:10:28 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:10:28 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:10:28 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:10:28 volumio-hall volumio[24206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:28 volumio-hall volumio[24206]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:28 volumio-hall volumio[24206]: info: [1765809628165] CoreMusicLibrary::Adding element Last_100 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:28 volumio-hall volumio[24206]: info: [1765809628169] CoreMusicLibrary::Adding element Webradio Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:10:28 volumio-hall go-librespot[24270]: time="2025-12-15T20:10:28+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:10:28 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:10:28 volumio-hall volumio[24206]: info: Initializing BBC Radios Dec 15 20:10:28 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:10:28 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:10:28 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:10:28 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:10:28 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:10:28 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:10:28 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:10:28 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:28 volumio-hall volumio[24206]: info: Creating Spotify config file Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:28 volumio-hall sudo[24369]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:10:28 volumio-hall sudo[24369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:10:28 volumio-hall sudo[24369]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:28 volumio-hall volumio[24206]: info: Volumio Calling Home Dec 15 20:10:28 volumio-hall volumio[24292]: Starting albumart workers Dec 15 20:10:28 volumio-hall volumio[24295]: Starting albumart workers Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:10:28 volumio-hall volumio[24206]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreStateMachine::pushState Dec 15 20:10:28 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:28 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:28 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:10:28 volumio-hall volumio[24206]: info: Received Get System Info Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:10:28 volumio-hall volumio[24206]: info: Discovery: Getting this device information Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:28 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:10:28 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:28 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:28 volumio-hall volumio[24206]: info: Listing playlists Dec 15 20:10:28 volumio-hall volumio[24206]: info: MPD Permissions set Dec 15 20:10:28 volumio-hall volumio[24206]: info: MPD Permissions set Dec 15 20:10:28 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809627 101 Dec 15 20:10:28 volumio-hall volumio[24294]: Starting albumart workers Dec 15 20:10:28 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 5 Dec 15 20:10:29 volumio-hall volumio[24206]: info: Spotify config file written Dec 15 20:10:29 volumio-hall sudo[24381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:10:29 volumio-hall sudo[24381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:29 volumio-hall systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 20:10:29 volumio-hall systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 20:10:29 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:29 volumio-hall volumio[24206]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:10:29 volumio-hall volumio[24206]: info: Volumio called home Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall go-librespot[24383]: go-librespot daemon starting... Dec 15 20:10:29 volumio-hall sudo[24381]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="app state loaded" Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:29 volumio-hall volumio[24206]: info: No need to fix Spotify hosts Dec 15 20:10:29 volumio-hall volumio[24206]: info: Starting Shairport Sync Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:10:29 volumio-hall volumio[24206]: info: Starting Shairport Sync Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=info msg="zeroconf server listening on port 40907" Dec 15 20:10:29 volumio-hall volumio[24206]: info: Starting Shairport Sync Dec 15 20:10:29 volumio-hall sudo[24404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:10:29 volumio-hall sudo[24407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:10:29 volumio-hall sudo[24404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:29 volumio-hall volumio[24206]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:10:29 volumio-hall volumio[24206]: SPOTIFY: BQBCOw3x_Uoqxqu6gJxqmcfjLqRbrYo3XtHXKeXLrteNny6JdoPbtgeCaKxDquTJWlLBj9hDKsHXddgsfmj6wOj1k1q1UWjQL8mDkcMe79HAJ3uAH1gZOEBZN4miBabdX9D5QZGAzX3e_KG6ko4MuxoL1YFBuERwDTKa5FZpRhOxpLaqyMs-NEZ8pIHFNaHirLaUZnyRXmqLN2LYy2el7MIMKo0qgrBGU4B2RMPADyOMsa0PL5TXx0-SQJM9ZjQww_fuHwOyhPodehHSgj3BUP53X0pMa4bvh89-4twtge921k5rRjJmeFSWt3wO Dec 15 20:10:29 volumio-hall volumio[24206]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:10:29 volumio-hall sudo[24408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:10:29 volumio-hall volumio[24206]: info: New Spotify access token = BQBCOw3x_Uoqxqu6gJxqmcfjLqRbrYo3XtHXKeXLrteNny6JdoPbtgeCaKxDquTJWlLBj9hDKsHXddgsfmj6wOj1k1q1UWjQL8mDkcMe79HAJ3uAH1gZOEBZN4miBabdX9D5QZGAzX3e_KG6ko4MuxoL1YFBuERwDTKa5FZpRhOxpLaqyMs-NEZ8pIHFNaHirLaUZnyRXmqLN2LYy2el7MIMKo0qgrBGU4B2RMPADyOMsa0PL5TXx0-SQJM9ZjQww_fuHwOyhPodehHSgj3BUP53X0pMa4bvh89-4twtge921k5rRjJmeFSWt3wO Dec 15 20:10:29 volumio-hall volumio[24206]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:10:29 volumio-hall sudo[24407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:29 volumio-hall sudo[24408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:29 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="obtained new client token: AACU5zDqb6LJ29LXisEe5MN7ednlUpNVa9H3ckzt/fzj5AihQD/yLZzrFpjlpEnJfwEXdbQsoAsD5DDanns0rhtOGNERqlRvXRFvEYB4piYGhQ93UVqWFjXgkQVzbUwBeN8LT/O2nJ1/tIA4dpxwVcXGjFPesox7ivJ12z5L4D+bo+U8hfscymDgFMugdnViQjqXuQ8HNQq+hdE6NBVGClTGAy66dO9CPBXZSZ5dE95x7YpzMBlufGOVxQ==" Dec 15 20:10:29 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:10:29 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:10:29 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.734s CPU time. Dec 15 20:10:29 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:10:29 volumio-hall sudo[24407]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:29 volumio-hall sudo[24408]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:29 volumio-hall sudo[24404]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:29 volumio-hall volumio[24206]: info: Shairport-Sync Started Dec 15 20:10:29 volumio-hall volumio[24206]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:10:29 volumio-hall volumio[24206]: info: Shairport-Sync Started Dec 15 20:10:29 volumio-hall volumio[24206]: info: Shairport-Sync Started Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=debug msg="completed challenge" Dec 15 20:10:29 volumio-hall go-librespot[24390]: time="2025-12-15T20:10:29+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:29 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:29 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:30 volumio-hall mpd[24376]: 2025-12-15T20:10:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:10:30 volumio-hall volumio[24206]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:10:30 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:10:30 volumio-hall sudo[24337]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:30 volumio-hall sudo[24347]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:30 volumio-hall volumio[24206]: info: Completed starting Core Plugins Dec 15 20:10:30 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:30 volumio-hall volumio[24206]: info: ----- MyVolumio plugins startup ---- Dec 15 20:10:30 volumio-hall volumio[24206]: info: ------------------------------------------- Dec 15 20:10:30 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:10:30 volumio-hall volumio[24206]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:10:30 volumio-hall volumio[24206]: assert.ok(self.idling) Dec 15 20:10:30 volumio-hall volumio[24206]: error: The expression evaluated to a falsy value: Dec 15 20:10:30 volumio-hall volumio[24206]: assert.ok(self.idling) Dec 15 20:10:30 volumio-hall volumio[24206]: info: MPD running with PID24376 Dec 15 20:10:30 volumio-hall volumio[24206]: ,establishing connection Dec 15 20:10:30 volumio-hall volumio[24206]: error: updateQueue error: null Dec 15 20:10:30 volumio-hall volumio[24206]: error: updateQueue error: null Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: Found device Volumio-Zero Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: Found device Volumio-Hall Dec 15 20:10:30 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:30 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: Found device Volumio-Hall Dec 15 20:10:30 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:30 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:30 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:30 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:30 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:10:30 volumio-hall volumio[24206]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:10:30 volumio-hall volumio[24206]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:10:30 volumio-hall volumio[24206]: info: Spotify Successfully logged in Dec 15 20:10:30 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:30 volumio-hall volumio[24206]: info: [1765809630842] CoreMusicLibrary::Adding element Spotify Dec 15 20:10:30 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:30 volumio-hall volumio[24206]: Cannot find translation for source Spotify Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:31 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:31 volumio-hall volumio[24206]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:31 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:31 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:10:31 volumio-hall volumio[24206]: info: Received Get System Info Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:10:31 volumio-hall volumio[24206]: info: Discovery: Getting this device information Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:31 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:10:31 volumio-hall volumio[24206]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:31 volumio-hall volumio[24206]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:31 volumio-hall volumio[24206]: info: Listing playlists Dec 15 20:10:32 volumio-hall volumio[24206]: info: go-librespot daemon successfully initialized Dec 15 20:10:33 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:10:33 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:33 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:33 volumio-hall go-librespot[24450]: go-librespot daemon starting... Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="app state loaded" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=info msg="zeroconf server listening on port 37667" Dec 15 20:10:33 volumio-hall sudo[24459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:10:33 volumio-hall sudo[24459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:33 volumio-hall sudo[24461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:10:33 volumio-hall sudo[24461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:33 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:10:33 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:10:33 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="obtained new client token: AACx192ohKKgBK4v/roQRChBPtxkrmz8ovMDRoKv6fx5bC88SdYe392mRQr6iTXxgU+kC5Rc4ueXKW1SxOsZu2FvZ4GHZJz1Yea6wE7NGICXRlXeUW2Nv11QS/GS68wP6/xcsFtR5cGhAqZ4xYF+tmo5ysdCUgAH5vefhoN0qRB/MGGF4sjOV6RlmJ3O+N6w5oF9qOR5LDTLiJLcnJ5VQGxDAgoqCizkdzcCFMhBZbWc6mCTUejbZnVVsQ==" Dec 15 20:10:33 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:33 volumio-hall sudo[24459]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:33 volumio-hall mpd_monitor.sh[24464]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:10:33 volumio-hall volumio[24206]: info: Successfully started MPD Monitor Dec 15 20:10:33 volumio-hall sudo[24461]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:33 volumio-hall volumio[24206]: info: Successfully started MPD Monitor Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=debug msg="completed challenge" Dec 15 20:10:33 volumio-hall go-librespot[24451]: time="2025-12-15T20:10:33+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:33 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:33 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:35 volumio-hall volumio[24206]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:35 volumio-hall volumio[24206]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:10:35 volumio-hall volumio[24206]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:35 volumio-hall sudo[24483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:10:35 volumio-hall sudo[24483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:35 volumio-hall sudo[24483]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:35 volumio-hall sudo[24485]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:10:35 volumio-hall sudo[24485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:35 volumio-hall sudo[24485]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:35 volumio-hall sudo[24489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:10:35 volumio-hall sudo[24489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:35 volumio-hall sudo[24489]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:35 volumio-hall volumio[24206]: info: Upmpdcli Daemon Started Dec 15 20:10:35 volumio-hall volumio[24206]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:10:36 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:10:36 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:37 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:37 volumio-hall go-librespot[24491]: go-librespot daemon starting... Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="app state loaded" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=info msg="zeroconf server listening on port 38663" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="obtained new client token: AACGkCNiVLFaK8dRQpfw74D1TYlZcE1PGi0VqppCr5bB7J0iUGCHP5SUt6qK5Av+7uH87uH3+dSVsxVoS67QOCntYliOaSfQ8HsEGk9Pi3pR1qv1AcTLwHDxq+n+yeQJbmZJ5ytBPB21o6HLmTTDJAJsFW+n756zDccBzhMMrgNp1NGEzHlDvjXAOsJJNdhY1mxz7H6liTnIQOUOLwe3t7QYItU2c9mbls61yD8x36/B0LvjWkX9sFf5vw==" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:37 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:37+05:30" level=debug msg="completed challenge" Dec 15 20:10:37 volumio-hall volumio[24206]: Cannot compose Albumart path Dec 15 20:10:38 volumio-hall volumio[24206]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:38 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:38+05:30" level=debug msg="new websocket client" Dec 15 20:10:38 volumio-hall volumio[24206]: info: Connection to go-librespot Websocket established Dec 15 20:10:38 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:38+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 20:10:39 volumio-hall go-librespot[24492]: time="2025-12-15T20:10:39+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:10:39 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:39 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 20:10:39 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:39 volumio-hall volumio[24206]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:39 volumio-hall volumio[24206]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 20:10:39 volumio-hall volumio[24206]: info: MyVolumio login type: Token Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 20:10:39 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 20:10:40 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 20:10:40 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 20:10:40 volumio-hall volumio[24206]: info: Streaming services startup Dec 15 20:10:40 volumio-hall volumio[24206]: info: Starting Streaming Daemon Dec 15 20:10:40 volumio-hall sudo[24504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:10:40 volumio-hall sudo[24504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:40 volumio-hall volumio[24206]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 20:10:40 volumio-hall sudo[24504]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:40 volumio-hall volumio[24206]: info: Cannot mount NAS AudioVideo at system boot, trial number 4 ,retrying in 5 seconds Dec 15 20:10:40 volumio-hall volumio[24206]: info: Connection to go-librespot Websocket closed Dec 15 20:10:40 volumio-hall volumio[24206]: error: Cannot start Volumio Streaming Daemon Dec 15 20:10:40 volumio-hall volumio[24206]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:10:40 volumio-hall volumio[24206]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:10:41 volumio-hall volumio[24206]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 20:10:41 volumio-hall volumio[24206]: info: Getting Spotify volume Dec 15 20:10:41 volumio-hall volumio[24206]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:10:41 volumio-hall volumio[24206]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:10:41 volumio-hall volumio[24206]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 20:10:41 volumio-hall volumio[24206]: errno: -111, Dec 15 20:10:41 volumio-hall volumio[24206]: code: 'ECONNREFUSED', Dec 15 20:10:41 volumio-hall volumio[24206]: syscall: 'connect', Dec 15 20:10:41 volumio-hall volumio[24206]: address: '127.0.0.1', Dec 15 20:10:41 volumio-hall volumio[24206]: port: 9879, Dec 15 20:10:41 volumio-hall volumio[24206]: response: undefined Dec 15 20:10:41 volumio-hall volumio[24206]: } Dec 15 20:10:41 volumio-hall volumio[24206]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:10:41 volumio-hall sudo[24524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:09' Dec 15 20:10:41 volumio-hall sudo[24524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:42 volumio-hall sudo[24524]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:42 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:42] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 20:10:42 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:42] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 20:10:42 volumio-hall systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:42 volumio-hall systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 20:10:42 volumio-hall systemd[1]: volumio.service: Consumed 20.397s CPU time. Dec 15 20:10:42 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:10:42 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:10:42 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 60. Dec 15 20:10:42 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:10:42 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:10:42 volumio-hall systemd[1]: volumio.service: Consumed 20.397s CPU time. Dec 15 20:10:42 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:10:42 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:10:42 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:10:42 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:43 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:43 volumio-hall go-librespot[24551]: go-librespot daemon starting... Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="app state loaded" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=info msg="zeroconf server listening on port 44697" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="obtained new client token: AAAfU/yN7hLt0e6+BgJHfd3UKwZu2juJk5GXc9HYKsQaO4yRhqa7kzjOqB4jIqqX+ku4vH6dLTg2DGj45glfu+Zu8dfTNziRpPdK6XcoRZWBJygMw70ti/T5AQqW3JRg3yQkjbQk5jElEnpYBCtCKi7qZKW8Epkf0AMD5tZIGsR9f7XG8Pb8MaAgRWybCqlMk+qzNdiTfO8+WCDkj/ppAGNIxxWwK5rZkh/+fYOOjxgdiRiUmiqdkgXt3g==" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:43 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:43+05:30" level=debug msg="completed challenge" Dec 15 20:10:43 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:43 volumio-hall volumio[24536]: info: ----- Volumio3 ---- Dec 15 20:10:43 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:43 volumio-hall volumio[24536]: info: ----- System startup ---- Dec 15 20:10:43 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:44 volumio-hall volumio[24536]: info: MYVOLUMIO Environment detected Dec 15 20:10:44 volumio-hall volumio[24536]: info: Plugin folders cleanup Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category audio_interface Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category miscellanea Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category music_service Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category plugins.json Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category system_controller Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category user_interface Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning into folder /data/plugins/ Dec 15 20:10:44 volumio-hall volumio[24536]: info: Scanning category music_service Dec 15 20:10:44 volumio-hall volumio[24536]: info: Plugin folders cleanup completed Dec 15 20:10:44 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:44 volumio-hall volumio[24536]: info: ----- Core plugins startup ---- Dec 15 20:10:44 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:10:44 volumio-hall volumio[24536]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:10:44 volumio-hall volumio[24536]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:10:44 volumio-hall volumio[24536]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugins from folder /data/plugins/ Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "system"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "appearance"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "network"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Refreshing Cached IP Addresses Dec 15 20:10:44 volumio-hall sudo[24573]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:10:44 volumio-hall sudo[24573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:44 volumio-hall sudo[24575]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:10:44 volumio-hall sudo[24573]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:44 volumio-hall sudo[24575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:44 volumio-hall sudo[24575]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "services"... Dec 15 20:10:44 volumio-hall sudo[24583]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:10:44 volumio-hall sudo[24583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "alsa_controller"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "wizard"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "networkfs"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:10:44 volumio-hall volumio[24536]: info: Starting Udev Watcher for removable devices Dec 15 20:10:44 volumio-hall volumio[24536]: info: Ignoring mount for partition: boot Dec 15 20:10:44 volumio-hall volumio[24536]: info: Ignoring mount for partition: volumio Dec 15 20:10:44 volumio-hall volumio[24536]: info: Ignoring mount for partition: volumio_data Dec 15 20:10:44 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "upnp"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: [1765809644828] Starting Upmpd Daemon Dec 15 20:10:44 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "my_music"... Dec 15 20:10:44 volumio-hall volumio[24536]: info: Loading plugin "mpd"... Dec 15 20:10:44 volumio-hall go-librespot[24552]: time="2025-12-15T20:10:44+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:44 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:44 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "upnp_browser"... Dec 15 20:10:45 volumio-hall volumio[24536]: info: Starting UPNP Browser Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "alarm-clock"... Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "airplay_emulation"... Dec 15 20:10:45 volumio-hall volumio[24536]: info: Starting Shairport Sync Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "last_100"... Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "webradio"... Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "i2s_dacs"... Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "volumiodiscovery"... Dec 15 20:10:45 volumio-hall volumio[24536]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:45 volumio-hall volumio[24536]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:45 volumio-hall volumio[24536]: *** WARNING *** For more information see Dec 15 20:10:45 volumio-hall volumio[24536]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:45 volumio-hall volumio[24536]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:45 volumio-hall volumio[24536]: *** WARNING *** For more information see Dec 15 20:10:45 volumio-hall node[24536]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:45 volumio-hall node[24536]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:45 volumio-hall node[24536]: *** WARNING *** For more information see Dec 15 20:10:45 volumio-hall node[24536]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:10:45 volumio-hall node[24536]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:10:45 volumio-hall node[24536]: *** WARNING *** For more information see Dec 15 20:10:45 volumio-hall volumio[24536]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:10:45 volumio-hall volumio[24536]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:10:45 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:10:45 volumio-hall volumio[24536]: info: Loading plugin "spop"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading plugin "outputs"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading plugin "albumart"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Plugin example_plugin is not enabled Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading plugin "inputs"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading plugin "updater_comm"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Plugin mpdemulation is not enabled Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading plugin "rest_api"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading plugin "websocket"... Dec 15 20:10:46 volumio-hall volumio[24536]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:10:46 volumio-hall volumio[24536]: info: Loading i18n strings for locale en Dec 15 20:10:46 volumio-hall volumio[24536]: Updating browse sources language Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::initPlayerControls Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: Express server listening on port 3000 Dec 15 20:10:46 volumio-hall volumio[24536]: [Metrics] WebUI: 3s 411.13ms Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreStateMachine::resetVolumioState Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreStateMachine::getcurrentVolume Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:10:46 volumio-hall volumio[24536]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:10:46 volumio-hall volumio[24605]: Forking 3 albumart workers Dec 15 20:10:46 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:10:46 volumio-hall volumio[24536]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:10:46 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:46 volumio-hall volumio[24536]: info: Reloading queue from file Dec 15 20:10:46 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:10:46 volumio-hall volumio[24536]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreStateMachine::pushState Dec 15 20:10:46 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:10:46 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreStateMachine::updateTrackBlock Dec 15 20:10:47 volumio-hall volumio[24536]: info: CorePlayQueue::getTrackBlock Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreStateMachine::pushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreStateMachine::setRandom null Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreStateMachine::pushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: Setting Device type: Raspberry PI Dec 15 20:10:47 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 15 20:10:47 volumio-hall volumio[24536]: info: Completed loading Core Plugins Dec 15 20:10:47 volumio-hall volumio[24536]: info: Preparing to generate the ALSA configuration file Dec 15 20:10:47 volumio-hall volumio[24536]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:10:47 volumio-hall volumio[24536]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:10:47 volumio-hall volumio[24536]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:10:47 volumio-hall volumio[24536]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:10:47 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:47] [connect] Successful connection Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:10:47 volumio-hall volumio[24536]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreStateMachine::pushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioPushState Dec 15 20:10:47 volumio-hall volumio[24536]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:10:47 volumio-hall volumio[24536]: info: Output device has changed, restarting MPD Dec 15 20:10:47 volumio-hall volumio[24536]: info: Output device has changed, restarting Shairport Sync Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:47 volumio-hall sudo[24662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:10:47 volumio-hall sudo[24662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:47 volumio-hall sudo[24662]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:47 volumio-hall sudo[24664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:10:47 volumio-hall sudo[24664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:47 volumio-hall volumio[24536]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:10:47 volumio-hall volumio[24536]: info: ___________ START PLUGINS ___________ Dec 15 20:10:47 volumio-hall volumio[24536]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:10:47 volumio-hall volumio[24536]: info: Creating MPD Configuration file Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:47 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:10:47 volumio-hall sudo[24672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:10:47 volumio-hall volumio[24536]: info: [1765809647311] CoreMusicLibrary::Adding element Media Servers Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:47 volumio-hall sudo[24672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:47 volumio-hall sudo[24583]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:47 volumio-hall sudo[24672]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:47 volumio-hall sudo[24674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:10:47 volumio-hall sudo[24674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:47 volumio-hall volumio[24536]: info: UPNP Browser: Client initialized successfully Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:47 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:10:47 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:10:47 volumio-hall systemd[1]: mpd.service: Consumed 2.448s CPU time. Dec 15 20:10:47 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:10:47 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:10:47 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:10:47 volumio-hall volumio[24536]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:47 volumio-hall volumio[24536]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:47 volumio-hall volumio[24536]: info: [1765809647456] CoreMusicLibrary::Adding element Last_100 Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:47 volumio-hall volumio[24536]: info: [1765809647459] CoreMusicLibrary::Adding element Webradio Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:10:47 volumio-hall volumio[24536]: info: Initializing BBC Radios Dec 15 20:10:47 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:10:47 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:10:47 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:10:47 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:10:47 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:10:47 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:10:47 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:10:47 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:10:47 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:47 volumio-hall volumio[24536]: info: Creating Spotify config file Dec 15 20:10:47 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:47 volumio-hall sudo[24701]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:10:47 volumio-hall sudo[24701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:10:47 volumio-hall sudo[24701]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:47 volumio-hall volumio[24621]: Starting albumart workers Dec 15 20:10:47 volumio-hall volumio[24536]: info: Volumio Calling Home Dec 15 20:10:47 volumio-hall volumio[24619]: Starting albumart workers Dec 15 20:10:47 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 20:10:47 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:48 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:48 volumio-hall go-librespot[24707]: go-librespot daemon starting... Dec 15 20:10:48 volumio-hall go-librespot[24708]: time="2025-12-15T20:10:48+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:48 volumio-hall volumio[24622]: Starting albumart workers Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:48 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:48 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:10:48 volumio-hall volumio[24536]: info: Received Get System Info Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:10:48 volumio-hall volumio[24536]: info: Discovery: Getting this device information Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:48 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:48 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:48 volumio-hall volumio[24536]: info: Listing playlists Dec 15 20:10:48 volumio-hall go-librespot[24708]: time="2025-12-15T20:10:48+05:30" level=info msg="zeroconf server listening on port 36265" Dec 15 20:10:48 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809647 101 Dec 15 20:10:48 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 5 Dec 15 20:10:48 volumio-hall volumio[24536]: info: MPD Permissions set Dec 15 20:10:48 volumio-hall volumio[24536]: info: MPD Permissions set Dec 15 20:10:48 volumio-hall volumio[24536]: info: Spotify config file written Dec 15 20:10:48 volumio-hall volumio[24536]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall sudo[24725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:10:48 volumio-hall sudo[24725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 20:10:48 volumio-hall systemd[1]: go-librespot-daemon.service: Killing process 24715 (go-librespot) with signal SIGKILL. Dec 15 20:10:48 volumio-hall systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 20:10:48 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:10:48 volumio-hall volumio[24536]: info: No need to fix Spotify hosts Dec 15 20:10:48 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:48 volumio-hall go-librespot[24743]: go-librespot daemon starting... Dec 15 20:10:48 volumio-hall sudo[24725]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:48 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:48+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:48 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:48+05:30" level=debug msg="app state loaded" Dec 15 20:10:48 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:48+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:48 volumio-hall volumio[24536]: info: Volumio called home Dec 15 20:10:48 volumio-hall volumio[24536]: info: Starting Shairport Sync Dec 15 20:10:48 volumio-hall volumio[24536]: info: Starting Shairport Sync Dec 15 20:10:48 volumio-hall volumio[24536]: info: Starting Shairport Sync Dec 15 20:10:49 volumio-hall sudo[24761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:10:49 volumio-hall sudo[24761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:49 volumio-hall sudo[24758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:10:49 volumio-hall sudo[24758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:49 volumio-hall sudo[24762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:10:49 volumio-hall sudo[24762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:49 volumio-hall volumio[24536]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:10:49 volumio-hall volumio[24536]: SPOTIFY: BQBPTqRtdEydBHnRcuekDu3Egb_8oqXYhRXmM8LyXqm1zpLcQtDxIUqQ1fQbiE5gOdEuXn9ZbiLZmfTU_RRKgW14_hWaCcJ6mA36Dv-rDBAljkk6Uh1E1MaknQXjaabgV9dPifAAHxX18fpr5x_LnM3UmKoeOs0Uc2Kg4s3VxvoncE--ItI-2RtBrzHIJyEzV9ZcbxmsOWYrLOLtM5EytWkVZsEVbTW4l8ZPw-D7OmM3h-ijRch4Naq2kmvw4iGevp-YeKJTokgG6YtjpMCSRQT2hMi2SUDgMnms-xQtu-7bWyZdXe-CgjmI82B_ Dec 15 20:10:49 volumio-hall volumio[24536]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:10:49 volumio-hall volumio[24536]: info: New Spotify access token = BQBPTqRtdEydBHnRcuekDu3Egb_8oqXYhRXmM8LyXqm1zpLcQtDxIUqQ1fQbiE5gOdEuXn9ZbiLZmfTU_RRKgW14_hWaCcJ6mA36Dv-rDBAljkk6Uh1E1MaknQXjaabgV9dPifAAHxX18fpr5x_LnM3UmKoeOs0Uc2Kg4s3VxvoncE--ItI-2RtBrzHIJyEzV9ZcbxmsOWYrLOLtM5EytWkVZsEVbTW4l8ZPw-D7OmM3h-ijRch4Naq2kmvw4iGevp-YeKJTokgG6YtjpMCSRQT2hMi2SUDgMnms-xQtu-7bWyZdXe-CgjmI82B_ Dec 15 20:10:49 volumio-hall volumio[24536]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:10:49 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:10:49 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:10:49 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:10:49 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.665s CPU time. Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=info msg="zeroconf server listening on port 33155" Dec 15 20:10:49 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:10:49 volumio-hall sudo[24761]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:49 volumio-hall sudo[24758]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:49 volumio-hall volumio[24536]: info: Shairport-Sync Started Dec 15 20:10:49 volumio-hall sudo[24762]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:49 volumio-hall volumio[24536]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:10:49 volumio-hall volumio[24536]: info: Shairport-Sync Started Dec 15 20:10:49 volumio-hall volumio[24536]: info: Shairport-Sync Started Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="obtained new client token: AAAQkDBoHYeEGD2biJqvOvssQ91NXpyPo4ZotVVoY5HJLLVE4bsbRRdCptvofFm59ah1tXTCo8/4WpTKAooUmLe+fSupk4axFlq9Kfh9r3NpE726aiEuISiIk26VMOkZdxpf0aCDprMmPDjucQMWrtZlvaQRPCIJKZQJWszBv7fXsfxI85h/qJlOiHd0if9yEokde8XbyLxL0HzQmYra6AFUa21grrX8UpJpcFIqCX5/14ZC8XMhIdM=" Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=debug msg="completed challenge" Dec 15 20:10:49 volumio-hall mpd[24703]: 2025-12-15T20:10:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:10:49 volumio-hall go-librespot[24744]: time="2025-12-15T20:10:49+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:10:49 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:49 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:49 volumio-hall volumio[24536]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:10:49 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:10:49 volumio-hall sudo[24674]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:49 volumio-hall sudo[24664]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:49 volumio-hall volumio[24536]: info: Completed starting Core Plugins Dec 15 20:10:49 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:49 volumio-hall volumio[24536]: info: ----- MyVolumio plugins startup ---- Dec 15 20:10:49 volumio-hall volumio[24536]: info: ------------------------------------------- Dec 15 20:10:49 volumio-hall volumio[24536]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:10:49 volumio-hall volumio[24536]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:10:49 volumio-hall volumio[24536]: assert.ok(self.idling) Dec 15 20:10:49 volumio-hall volumio[24536]: error: The expression evaluated to a falsy value: Dec 15 20:10:49 volumio-hall volumio[24536]: assert.ok(self.idling) Dec 15 20:10:49 volumio-hall volumio[24536]: info: MPD running with PID24703 Dec 15 20:10:49 volumio-hall volumio[24536]: ,establishing connection Dec 15 20:10:49 volumio-hall volumio[24536]: error: updateQueue error: null Dec 15 20:10:49 volumio-hall volumio[24536]: error: updateQueue error: null Dec 15 20:10:50 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:50 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:50 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:10:50 volumio-hall volumio[24536]: info: Received Get System Info Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:10:50 volumio-hall volumio[24536]: info: Discovery: Getting this device information Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:50 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:10:50 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:50 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:50 volumio-hall volumio[24536]: info: Listing playlists Dec 15 20:10:51 volumio-hall volumio[24536]: info: go-librespot daemon successfully initialized Dec 15 20:10:52 volumio-hall sudo[24787]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:10:52 volumio-hall sudo[24787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:52 volumio-hall sudo[24790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:10:52 volumio-hall sudo[24790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:52 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:10:52 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:52 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:10:52 volumio-hall go-librespot[24792]: go-librespot daemon starting... Dec 15 20:10:52 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:10:52 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:10:52 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:52 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:52+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:10:52 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:52+05:30" level=debug msg="app state loaded" Dec 15 20:10:52 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:52+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:10:53 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:10:53 volumio-hall sudo[24787]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:53 volumio-hall mpd_monitor.sh[24799]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:10:53 volumio-hall volumio[24536]: info: Successfully started MPD Monitor Dec 15 20:10:53 volumio-hall sudo[24790]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:53 volumio-hall volumio[24536]: info: Successfully started MPD Monitor Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=info msg="zeroconf server listening on port 34195" Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="obtained new client token: AAD1kEluezLqsv4Nj9Da0ackCINawW+fA5s+WYhRSqOFBWCATfEqqnrYeEVs7Bi/1q8RyP0+ANUZvezHpZC8m9wODI7mkwdc1CY6mfsDHlgSOSFY5MIVHMMxHiU9a+XVjJfpG9nuvXAexXLjLIvpnFjSU5JXbYPnXuky+Nn1py2XEyV7tPiyn0K7AecJuHmpWthu86m8nwqJTucH2vaqAsuiXJHeQA9dmLl3QXKpwUffgPBUh2x4DaZVdA==" Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: Found device Volumio-Zero Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: Found device Volumio-Hall Dec 15 20:10:53 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:53 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: Found device Volumio-Hall Dec 15 20:10:53 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:53 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:53 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:53 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:10:53 volumio-hall volumio[24536]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="completed keyexchange" Dec 15 20:10:53 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:53+05:30" level=debug msg="completed challenge" Dec 15 20:10:53 volumio-hall volumio[24536]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:10:53 volumio-hall volumio[24536]: info: Spotify Successfully logged in Dec 15 20:10:53 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:10:53 volumio-hall volumio[24536]: info: [1765809653545] CoreMusicLibrary::Adding element Spotify Dec 15 20:10:53 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:10:53 volumio-hall volumio[24536]: Cannot find translation for source Spotify Dec 15 20:10:53 volumio-hall volumio[24536]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 15 20:10:53 volumio-hall volumio[24536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:10:54 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:54 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:54 volumio-hall volumio[24536]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:10:54 volumio-hall sudo[24819]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:10:54 volumio-hall sudo[24819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:54 volumio-hall sudo[24821]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:10:54 volumio-hall sudo[24821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:54 volumio-hall sudo[24819]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:54 volumio-hall sudo[24821]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:54 volumio-hall sudo[24824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:10:54 volumio-hall sudo[24824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:54 volumio-hall sudo[24824]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:54 volumio-hall volumio[24536]: info: Upmpdcli Daemon Started Dec 15 20:10:54 volumio-hall volumio[24536]: info: Initializing connection to go-librespot Websocket Dec 15 20:10:54 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:54+05:30" level=debug msg="new websocket client" Dec 15 20:10:54 volumio-hall volumio[24536]: info: Connection to go-librespot Websocket established Dec 15 20:10:55 volumio-hall volumio[24536]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:10:56 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:56+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:10:57 volumio-hall volumio[24536]: Cannot compose Albumart path Dec 15 20:10:57 volumio-hall volumio[24536]: info: Getting Spotify volume Dec 15 20:10:57 volumio-hall volumio[24536]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Dec 15 20:10:58 volumio-hall volumio[24536]: info: CoreCommandRouter::volumioGetState Dec 15 20:10:58 volumio-hall volumio[24536]: info: CorePlayQueue::getTrack 0 Dec 15 20:10:58 volumio-hall go-librespot[24793]: time="2025-12-15T20:10:58+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:10:58 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:58 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:10:58 volumio-hall volumio[24536]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:10:58 volumio-hall volumio[24536]: Error: socket hang up Dec 15 20:10:58 volumio-hall volumio[24536]: at connResetException (node:internal/errors:720:14) Dec 15 20:10:58 volumio-hall volumio[24536]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 20:10:58 volumio-hall volumio[24536]: at Socket.emit (node:events:526:35) Dec 15 20:10:58 volumio-hall volumio[24536]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 20:10:58 volumio-hall volumio[24536]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 20:10:58 volumio-hall volumio[24536]: code: 'ECONNRESET', Dec 15 20:10:58 volumio-hall volumio[24536]: response: undefined Dec 15 20:10:58 volumio-hall volumio[24536]: } Dec 15 20:10:58 volumio-hall volumio[24536]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:10:58 volumio-hall sudo[24841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:09' Dec 15 20:10:58 volumio-hall sudo[24841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:10:58 volumio-hall sudo[24841]: pam_unix(sudo:session): session closed for user root Dec 15 20:10:59 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 20:10:59 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:10:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 20:10:59 volumio-hall systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:10:59 volumio-hall systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 20:10:59 volumio-hall systemd[1]: volumio.service: Consumed 19.140s CPU time. Dec 15 20:10:59 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:00 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:00 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 61. Dec 15 20:11:00 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:00 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:11:00 volumio-hall systemd[1]: volumio.service: Consumed 19.140s CPU time. Dec 15 20:11:00 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:11:00 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ----- Volumio3 ---- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ----- System startup ---- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:11:01 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:01 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:01 volumio-hall go-librespot[24877]: go-librespot daemon starting... Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="app state loaded" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:01 volumio-hall volumio[24856]: info: MYVOLUMIO Environment detected Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=info msg="zeroconf server listening on port 43445" Dec 15 20:11:01 volumio-hall volumio[24856]: info: Plugin folders cleanup Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category audio_interface Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category miscellanea Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category music_service Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category plugins.json Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category system_controller Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category user_interface Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning into folder /data/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category music_service Dec 15 20:11:01 volumio-hall volumio[24856]: info: Plugin folders cleanup completed Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ----- Core plugins startup ---- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:11:01 volumio-hall volumio[24856]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:11:01 volumio-hall volumio[24856]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugins from folder /data/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugin "system"... Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugin "appearance"... Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="obtained new client token: AADO48gIuhp1KhDSGr8yo4aKSsxSkhyYNvgIt0QDGg4cC9Fkd2WuZRh5dHvA9pDOEeTDZOuUGTQGKgR82ej8nwQUo4JkNcdgg9L4zUA9mMBMqKqBqtElKQDnnMb0FH8duttI/7uEwdwRCJP64zMiyO46FDOmf+Ls53c24VO16S/nfKy8CI2lr5OMB6SAI8Z7uU5UQ+8mYjysSZcOB40I/r2xcOwLP7zBf7utRkqVR0O391yo4CjltFZKmg==" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=debug msg="completed challenge" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:02 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:02 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "network"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Refreshing Cached IP Addresses Dec 15 20:11:02 volumio-hall sudo[24893]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:02 volumio-hall sudo[24893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:02 volumio-hall sudo[24895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:02 volumio-hall sudo[24895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:02 volumio-hall sudo[24893]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "services"... Dec 15 20:11:02 volumio-hall sudo[24895]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "alsa_controller"... Dec 15 20:11:02 volumio-hall sudo[24904]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:11:02 volumio-hall sudo[24904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:02 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "wizard"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "networkfs"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:11:02 volumio-hall volumio[24856]: info: Starting Udev Watcher for removable devices Dec 15 20:11:02 volumio-hall volumio[24856]: info: Ignoring mount for partition: boot Dec 15 20:11:02 volumio-hall volumio[24856]: info: Ignoring mount for partition: volumio Dec 15 20:11:02 volumio-hall volumio[24856]: info: Ignoring mount for partition: volumio_data Dec 15 20:11:02 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "upnp"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: [1765809662546] Starting Upmpd Daemon Dec 15 20:11:02 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "my_music"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "mpd"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "upnp_browser"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Starting UPNP Browser Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "alarm-clock"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "airplay_emulation"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "last_100"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "webradio"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "i2s_dacs"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "volumiodiscovery"... Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall volumio[24856]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall volumio[24856]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:11:03 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "spop"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "outputs"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "albumart"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Plugin example_plugin is not enabled Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "inputs"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "updater_comm"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Plugin mpdemulation is not enabled Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "rest_api"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "websocket"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading i18n strings for locale en Dec 15 20:11:04 volumio-hall volumio[24856]: Updating browse sources language Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::initPlayerControls Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: Express server listening on port 3000 Dec 15 20:11:04 volumio-hall volumio[24856]: [Metrics] WebUI: 3s 423.71ms Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::resetVolumioState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::getcurrentVolume Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:04 volumio-hall volumio[24856]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:11:04 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:11:04 volumio-hall volumio[24856]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:04 volumio-hall volumio[24925]: Forking 3 albumart workers Dec 15 20:11:04 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: Reloading queue from file Dec 15 20:11:04 volumio-hall volumio[24856]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::updateTrackBlock Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrackBlock Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::setRandom null Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: Setting Device type: Raspberry PI Dec 15 20:11:04 volumio-hall volumio[24856]: info: Completed loading Core Plugins Dec 15 20:11:04 volumio-hall volumio[24856]: info: Preparing to generate the ALSA configuration file Dec 15 20:11:04 volumio-hall volumio[24856]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:11:04 volumio-hall volumio[24856]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:11:04 volumio-hall volumio[24856]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:11:04 volumio-hall volumio[24856]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:11:04 volumio-hall volumio[24856]: info: Output device has changed, restarting MPD Dec 15 20:11:04 volumio-hall volumio[24856]: info: Output device has changed, restarting Shairport Sync Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall sudo[24982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:04 volumio-hall sudo[24981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:04 volumio-hall sudo[24982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall volumio[24856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:04 volumio-hall sudo[24981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall volumio[24856]: info: ___________ START PLUGINS ___________ Dec 15 20:11:04 volumio-hall volumio[24856]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:11:04 volumio-hall volumio[24856]: info: Creating MPD Configuration file Dec 15 20:11:04 volumio-hall sudo[24981]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:04 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:04 volumio-hall volumio[24856]: info: [1765809664835] CoreMusicLibrary::Adding element Media Servers Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio[24856]: info: UPNP Browser: Client initialized successfully Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall sudo[24992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:04 volumio-hall sudo[24992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall sudo[24994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:04 volumio-hall sudo[24994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall sudo[24992]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:04 volumio-hall volumio[24856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:11:04 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:11:04 volumio-hall systemd[1]: mpd.service: Consumed 2.426s CPU time. Dec 15 20:11:04 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:11:04 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:11:04 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:04 volumio-hall volumio[24856]: info: [1765809664926] CoreMusicLibrary::Adding element Last_100 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:04 volumio-hall volumio[24856]: info: [1765809664929] CoreMusicLibrary::Adding element Webradio Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:04] [connect] Successful connection Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:04 volumio-hall volumio[24856]: info: Initializing BBC Radios Dec 15 20:11:04 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:11:04 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:05 volumio-hall volumio[24856]: info: Creating Spotify config file Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:05 volumio-hall sudo[25019]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:11:05 volumio-hall sudo[25019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:11:05 volumio-hall sudo[25019]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:05 volumio-hall sudo[24904]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:05 volumio-hall volumio[24856]: info: Volumio Calling Home Dec 15 20:11:05 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:11:05 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:05 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:05 volumio-hall go-librespot[25025]: go-librespot daemon starting... Dec 15 20:11:05 volumio-hall go-librespot[25027]: time="2025-12-15T20:11:05+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:05 volumio-hall volumio[24856]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:05 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:05 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:11:05 volumio-hall volumio[24945]: Starting albumart workers Dec 15 20:11:05 volumio-hall volumio[24947]: Starting albumart workers Dec 15 20:11:05 volumio-hall volumio[24856]: info: MPD Permissions set Dec 15 20:11:05 volumio-hall volumio[24856]: info: MPD Permissions set Dec 15 20:11:05 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809664 101 Dec 15 20:11:05 volumio-hall volumio[24942]: Starting albumart workers Dec 15 20:11:05 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Dec 15 20:11:06 volumio-hall go-librespot[25027]: time="2025-12-15T20:11:06+05:30" level=info msg="zeroconf server listening on port 36305" Dec 15 20:11:06 volumio-hall volumio[24856]: info: Spotify config file written Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:06 volumio-hall volumio[24856]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall sudo[25036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall sudo[25036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 20:11:06 volumio-hall systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 20:11:06 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: No need to fix Spotify hosts Dec 15 20:11:06 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:06 volumio-hall go-librespot[25045]: go-librespot daemon starting... Dec 15 20:11:06 volumio-hall sudo[25036]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="app state loaded" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:06 volumio-hall volumio[24856]: info: Received Get System Info Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:06 volumio-hall volumio[24856]: info: Discovery: Getting this device information Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: Listing playlists Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=info msg="zeroconf server listening on port 46397" Dec 15 20:11:06 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="obtained new client token: AADuPDfVGbIDaqhZsHJLWzJRfJhzdp9E/Kudy/Q8GJfzKgL5mqoJiCGnoOxgmdIXGwDF696gptlgQgU4iughj+YWg5yd+FLsljIAekaCy7b/oYXK1lvaVwHJv5zaxnxtWLkPGW87jKP3Y+cE2gWV7ASStG5zMLrWayUvrEajqcnk7B4QMw7/9jvT40ibIaAFLzYTTfRE0hpELznAJfYRZGPzt0d43ZjVFVM7L8nPaHma0/iSQ4eLzqENGA==" Dec 15 20:11:06 volumio-hall volumio[24856]: info: Volumio called home Dec 15 20:11:06 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:06 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:06 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:06 volumio-hall sudo[25072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:06 volumio-hall sudo[25072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall sudo[25074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:06 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:06 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:06 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:06 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.660s CPU time. Dec 15 20:11:06 volumio-hall sudo[25074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall sudo[25078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:06 volumio-hall sudo[25078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="completed challenge" Dec 15 20:11:06 volumio-hall sudo[25072]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:06 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:06 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:06 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:07 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:07 volumio-hall sudo[25074]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall sudo[25078]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:07 volumio-hall volumio[24856]: info: Received Get System Info Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:07 volumio-hall volumio[24856]: info: Discovery: Getting this device information Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: Listing playlists Dec 15 20:11:07 volumio-hall volumio[24856]: info: Shairport-Sync Started Dec 15 20:11:07 volumio-hall volumio[24856]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:11:07 volumio-hall volumio[24856]: info: Shairport-Sync Started Dec 15 20:11:07 volumio-hall volumio[24856]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:07 volumio-hall volumio[24856]: SPOTIFY: BQDysc9y-xYvE6VoB9ZFhe-7tuxU30w0tTM9HTSsPxr23btAg1YWr2gQ0HH0X4rwQdyhHLaqO-POwi36p1w7AxiKPCX-y8uz9yKG24THgnyPVNI9PVXC721LChF7OfmGFuN5XGcUMyEY1LLfVg9-T2XiasPaG4vsYvB8TmdbLAqKCXgRJvp-9lrPw7mdpAy9gmQlmz5ucdwPRYwj5tGsk-a6cfGGQ-BfaRPbVKnGd6XvHW9JX7IKiCjxdWKaTtO0PJG6z9RztvP2NH8r56vAwdAoGiDuGufR2m_J16njzerLDoSWkKjZeZx4HFke Dec 15 20:11:07 volumio-hall volumio[24856]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:07 volumio-hall volumio[24856]: info: New Spotify access token = BQDysc9y-xYvE6VoB9ZFhe-7tuxU30w0tTM9HTSsPxr23btAg1YWr2gQ0HH0X4rwQdyhHLaqO-POwi36p1w7AxiKPCX-y8uz9yKG24THgnyPVNI9PVXC721LChF7OfmGFuN5XGcUMyEY1LLfVg9-T2XiasPaG4vsYvB8TmdbLAqKCXgRJvp-9lrPw7mdpAy9gmQlmz5ucdwPRYwj5tGsk-a6cfGGQ-BfaRPbVKnGd6XvHW9JX7IKiCjxdWKaTtO0PJG6z9RztvP2NH8r56vAwdAoGiDuGufR2m_J16njzerLDoSWkKjZeZx4HFke Dec 15 20:11:07 volumio-hall volumio[24856]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:11:07 volumio-hall volumio[24856]: info: Shairport-Sync Started Dec 15 20:11:07 volumio-hall mpd[25022]: 2025-12-15T20:11:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:11:07 volumio-hall volumio[24856]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:11:07 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:11:07 volumio-hall sudo[24994]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall sudo[24982]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall volumio[24856]: info: Completed starting Core Plugins Dec 15 20:11:07 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:07 volumio-hall volumio[24856]: info: ----- MyVolumio plugins startup ---- Dec 15 20:11:07 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:07 volumio-hall volumio[24856]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:11:07 volumio-hall volumio[24856]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:11:07 volumio-hall volumio[24856]: assert.ok(self.idling) Dec 15 20:11:07 volumio-hall volumio[24856]: error: The expression evaluated to a falsy value: Dec 15 20:11:07 volumio-hall volumio[24856]: assert.ok(self.idling) Dec 15 20:11:07 volumio-hall volumio[24856]: info: MPD running with PID25022 Dec 15 20:11:07 volumio-hall volumio[24856]: ,establishing connection Dec 15 20:11:07 volumio-hall volumio[24856]: error: updateQueue error: null Dec 15 20:11:07 volumio-hall volumio[24856]: error: updateQueue error: null Dec 15 20:11:09 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:09+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:11:09 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:09+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:11:09 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:09 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Found device Volumio-Zero Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:09 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:09 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:09 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:11:09 volumio-hall volumio[24856]: info: go-librespot daemon successfully initialized Dec 15 20:11:09 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:11:09 volumio-hall volumio[24856]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:11:09 volumio-hall volumio[24856]: info: Spotify Successfully logged in Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:09 volumio-hall volumio[24856]: info: [1765809669896] CoreMusicLibrary::Adding element Spotify Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:09 volumio-hall volumio[24856]: Cannot find translation for source Spotify Dec 15 20:11:10 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:11:10 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:10 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:10 volumio-hall sudo[25109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:10 volumio-hall sudo[25109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:10 volumio-hall sudo[25112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:10 volumio-hall sudo[25112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:10 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:10 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:10 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall sudo[25109]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:10 volumio-hall mpd_monitor.sh[25114]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:10 volumio-hall volumio[24856]: info: Successfully started MPD Monitor Dec 15 20:11:10 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:10 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:10 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall sudo[25112]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:10 volumio-hall volumio[24856]: info: Successfully started MPD Monitor Dec 15 20:11:10 volumio-hall mpd_monitor.sh[25116]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:12 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:11:12 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:12 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:12 volumio-hall go-librespot[25120]: go-librespot daemon starting... Dec 15 20:11:12 volumio-hall volumio[24856]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="app state loaded" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:12 volumio-hall sudo[25142]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:12 volumio-hall sudo[25142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:12 volumio-hall sudo[25142]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:12 volumio-hall sudo[25144]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:12 volumio-hall sudo[25144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:12 volumio-hall sudo[25144]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:12 volumio-hall sudo[25148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:11:12 volumio-hall sudo[25148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:12 volumio-hall sudo[25148]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:12 volumio-hall volumio[24856]: info: Upmpdcli Daemon Started Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=info msg="zeroconf server listening on port 33335" Dec 15 20:11:12 volumio-hall volumio[24856]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="new websocket client" Dec 15 20:11:12 volumio-hall volumio[24856]: info: Connection to go-librespot Websocket established Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="obtained new client token: AAC5J0ExEngjdGMrA1vIEha1DqlVYV2LdH/cFs9tOAgic4PimJ/bC/R45Vwf+6aOthb9IsXaaYkWYlp6xvt16TPYz2dNlVBoEtforzBUv+OZXd8KOqgYf8g8q02nFBVBuxyGfq+nXG5TuJso8ihgyf4fxE9h5gf3IhB56v2z3jiH5rwbctOZX0Zj2yNlpp01rKbKisyYVj12YZSNTMiKYY1ewq1qQWikmXA572vimwNnIiO94HbjdYumVQ==" Dec 15 20:11:12 volumio-hall volumio[24856]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:13 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:13+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:13 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:13+05:30" level=debug msg="completed challenge" Dec 15 20:11:13 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:13+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:13 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:13 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:13 volumio-hall volumio[24856]: info: Connection to go-librespot Websocket closed Dec 15 20:11:15 volumio-hall volumio[24856]: Cannot compose Albumart path Dec 15 20:11:15 volumio-hall volumio[24856]: info: Getting Spotify volume Dec 15 20:11:15 volumio-hall volumio[24856]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:11:15 volumio-hall volumio[24856]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:15 volumio-hall volumio[24856]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 20:11:15 volumio-hall volumio[24856]: errno: -111, Dec 15 20:11:15 volumio-hall volumio[24856]: code: 'ECONNREFUSED', Dec 15 20:11:15 volumio-hall volumio[24856]: syscall: 'connect', Dec 15 20:11:15 volumio-hall volumio[24856]: address: '127.0.0.1', Dec 15 20:11:15 volumio-hall volumio[24856]: port: 9879, Dec 15 20:11:15 volumio-hall volumio[24856]: response: undefined Dec 15 20:11:15 volumio-hall volumio[24856]: } Dec 15 20:11:15 volumio-hall volumio[24856]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:11:16 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:11:16 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:16 volumio-hall sudo[25166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:10' Dec 15 20:11:16 volumio-hall sudo[25166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:16 volumio-hall nmbd[1099]: [2025/12/15 20:11:16.269508, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Dec 15 20:11:16 volumio-hall nmbd[1099]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.144 for name WORKGROUP<1d>. Dec 15 20:11:16 volumio-hall nmbd[1099]: This response was from IP 192.168.0.110, reporting an IP address of 192.168.0.110. Dec 15 20:11:16 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:16 volumio-hall go-librespot[25165]: go-librespot daemon starting... Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="app state loaded" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=info msg="api server listening on 127.0.0.1:9879" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"