Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="completed challenge" Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:00 volumio volumio[4332]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 19:21:00 volumio volumio[4332]: info: Initializing connection to go-librespot Websocket Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="new websocket client" Apr 14 19:21:00 volumio volumio[4332]: info: Connection to go-librespot Websocket established Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=debug msg="completed challenge" Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:01 volumio volumio[4332]: info: Connection to go-librespot Websocket closed Apr 14 19:21:03 volumio volumio[4332]: info: Getting Spotify volume Apr 14 19:21:03 volumio volumio[4332]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:03 volumio volumio[4332]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 19:21:03 volumio volumio[4332]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 19:21:03 volumio volumio[4332]: errno: -111, Apr 14 19:21:03 volumio volumio[4332]: code: 'ECONNREFUSED', Apr 14 19:21:03 volumio volumio[4332]: syscall: 'connect', Apr 14 19:21:03 volumio volumio[4332]: address: '127.0.0.1', Apr 14 19:21:03 volumio volumio[4332]: port: 9879, Apr 14 19:21:03 volumio volumio[4332]: response: undefined Apr 14 19:21:03 volumio volumio[4332]: } Apr 14 19:21:03 volumio volumio[4332]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:04 volumio sudo[4651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 19:20' Apr 14 19:21:04 volumio sudo[4651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:04 volumio sudo[4651]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 14 19:21:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:04 volumio go-librespot[4660]: go-librespot daemon starting... Apr 14 19:21:04 volumio go-librespot[4661]: time="2026-04-14T19:21:04+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:21:04 volumio go-librespot[4661]: time="2026-04-14T19:21:04+07:00" level=debug msg="app state loaded" Apr 14 19:21:04 volumio go-librespot[4661]: time="2026-04-14T19:21:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:21:05 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:05.598+07:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Apr 14 19:21:05 volumio volumio-remote-updater[827]: [2026-04-14 19:21:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 19:21:05 volumio volumio-remote-updater[827]: [2026-04-14 19:21:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 19:21:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:05 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:05.600+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 14 19:21:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 19:21:05 volumio systemd[1]: volumio.service: Consumed 17.583s CPU time. Apr 14 19:21:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:21:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:21:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Apr 14 19:21:05 volumio go-librespot[4661]: time="2026-04-14T19:21:05+07:00" 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]" Apr 14 19:21:05 volumio go-librespot[4661]: time="2026-04-14T19:21:05+07:00" 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]" Apr 14 19:21:05 volumio go-librespot[4661]: time="2026-04-14T19:21:05+07:00" 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]" Apr 14 19:21:05 volumio go-librespot[4661]: time="2026-04-14T19:21:05+07:00" level=info msg="zeroconf server listening on port 35029" Apr 14 19:21:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:21:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 19:21:05 volumio systemd[1]: volumio.service: Consumed 17.583s CPU time. Apr 14 19:21:05 volumio go-librespot[4661]: time="2026-04-14T19:21:05+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:21:05 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 19:21:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:21:06 volumio go-librespot[4661]: time="2026-04-14T19:21:06+07:00" level=debug msg="obtained new client token: AAAoIZTV4/S7QcjS36HWKdNp1QXuO9Q+SyJBsMsu7m/T353Sy1jjto3n8RQtDTJnzQTIZDuY1o7vFE4IozumTx7Xc+I+1csskTxtqemjR/EBsCeTxVt87xxGuAviCod0zg72uIlKJ7Igy/OrhBf88x6zArbkfZacvvxregHSlS/ojmc0qaTdEFtxNIc8hvKyFYFxHu8UqupBPo1b2RcLFdzmIlZeeWw1ABYeEnL6GlIgeZgTndOO/g==" Apr 14 19:21:06 volumio go-librespot[4661]: time="2026-04-14T19:21:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:06 volumio go-librespot[4661]: time="2026-04-14T19:21:06+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:06 volumio go-librespot[4661]: time="2026-04-14T19:21:06+07:00" level=debug msg="completed challenge" Apr 14 19:21:06 volumio go-librespot[4661]: time="2026-04-14T19:21:06+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:06 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:06.604+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 14 19:21:07 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:07 volumio volumio[4680]: info: ----- Volumio3 ---- Apr 14 19:21:07 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:07 volumio volumio[4680]: info: ----- System startup ---- Apr 14 19:21:07 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:07 volumio go-librespot[4661]: time="2026-04-14T19:21:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Apr 14 19:21:07 volumio go-librespot[4661]: time="2026-04-14T19:21:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Apr 14 19:21:07 volumio volumio[4680]: info: MYVOLUMIO Environment detected Apr 14 19:21:07 volumio go-librespot[4661]: time="2026-04-14T19:21:07+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 19:21:07 volumio volumio[4680]: info: Plugin folders cleanup Apr 14 19:21:07 volumio volumio[4680]: info: Scanning into folder /volumio/app/plugins/ Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category audio_interface Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category miscellanea Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category music_service Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category plugins.json Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category system_controller Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category user_interface Apr 14 19:21:07 volumio volumio[4680]: info: Scanning into folder /data/plugins/ Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category music_service Apr 14 19:21:07 volumio volumio[4680]: info: Scanning category system_hardware Apr 14 19:21:07 volumio volumio[4680]: info: Plugin folders cleanup completed Apr 14 19:21:07 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:07 volumio volumio[4680]: info: ----- Core plugins startup ---- Apr 14 19:21:07 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:07 volumio volumio[4680]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 19:21:07 volumio volumio[4680]: info: Adding plugin upnp to MyMusic Plugins Apr 14 19:21:07 volumio volumio[4680]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 19:21:07 volumio volumio[4680]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 19:21:07 volumio volumio[4680]: info: Loading plugins from folder /data/plugins/ Apr 14 19:21:07 volumio volumio[4680]: info: Loading plugin "system"... Apr 14 19:21:07 volumio volumio[4680]: info: Loading plugin "appearance"... Apr 14 19:21:07 volumio go-librespot[4661]: time="2026-04-14T19:21:07+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:07 volumio go-librespot[4661]: time="2026-04-14T19:21:07+07:00" level=debug msg="completed challenge" Apr 14 19:21:07 volumio go-librespot[4661]: time="2026-04-14T19:21:07+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "network"... Apr 14 19:21:08 volumio volumio[4680]: info: Refreshing Cached IP Addresses Apr 14 19:21:08 volumio sudo[4711]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:21:08 volumio sudo[4711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:08 volumio sudo[4713]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "services"... Apr 14 19:21:08 volumio sudo[4713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "volumio5onboarding"... Apr 14 19:21:08 volumio sudo[4711]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "alsa_controller"... Apr 14 19:21:08 volumio sudo[4725]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 19:21:08 volumio sudo[4725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:08 volumio sudo[4713]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:08 volumio sudo[4725]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:08 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "wizard"... Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "networkfs"... Apr 14 19:21:08 volumio volumio[4680]: info: Starting Udev Watcher for removable devices Apr 14 19:21:08 volumio volumio[4680]: info: Ignoring mount for partition: boot Apr 14 19:21:08 volumio volumio[4680]: info: Ignoring mount for partition: volumio Apr 14 19:21:08 volumio volumio[4680]: info: Ignoring mount for partition: volumio_data Apr 14 19:21:08 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "volumio_command_line_client"... Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "upnp"... Apr 14 19:21:08 volumio volumio[4680]: info: [1776169268483] Starting Upmpd Daemon Apr 14 19:21:08 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "my_music"... Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "mpd"... Apr 14 19:21:08 volumio volumio[4680]: info: Loading plugin "upnp_browser"... Apr 14 19:21:08 volumio go-librespot[4661]: time="2026-04-14T19:21:08+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 19:21:09 volumio go-librespot[4661]: time="2026-04-14T19:21:09+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:09 volumio go-librespot[4661]: time="2026-04-14T19:21:09+07:00" level=debug msg="completed challenge" Apr 14 19:21:09 volumio go-librespot[4661]: time="2026-04-14T19:21:09+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:09 volumio volumio[4680]: info: Starting UPNP Browser Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "alarm-clock"... Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "airplay_emulation"... Apr 14 19:21:09 volumio volumio[4680]: info: Starting Shairport Sync Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "last_100"... Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "webradio"... Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "i2s_dacs"... Apr 14 19:21:09 volumio volumio[4680]: info: I2S DAC not set, start Auto-detection Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "volumiodiscovery"... Apr 14 19:21:09 volumio volumio[4680]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:09 volumio volumio[4680]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:09 volumio volumio[4680]: *** WARNING *** For more information see Apr 14 19:21:09 volumio volumio[4680]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:09 volumio volumio[4680]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:09 volumio node[4680]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:09 volumio volumio[4680]: *** WARNING *** For more information see Apr 14 19:21:09 volumio node[4680]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:09 volumio node[4680]: *** WARNING *** For more information see Apr 14 19:21:09 volumio node[4680]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:09 volumio volumio[4680]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 19:21:09 volumio node[4680]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:09 volumio node[4680]: *** WARNING *** For more information see Apr 14 19:21:09 volumio volumio[4680]: info: Discovery: Started advertising with name: Volumio Apr 14 19:21:09 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:21:09 volumio volumio[4680]: info: Loading plugin "mixcloud"... Apr 14 19:21:10 volumio go-librespot[4661]: time="2026-04-14T19:21:10+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:21:10 volumio volumio[4680]: info: Plugin soundcloud is not enabled Apr 14 19:21:10 volumio volumio[4680]: info: Loading plugin "spop"... Apr 14 19:21:10 volumio go-librespot[4661]: time="2026-04-14T19:21:10+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Apr 14 19:21:10 volumio volumio-remote-updater[827]: [2026-04-14 19:21:10] [connect] Successful connection Apr 14 19:21:10 volumio volumio[4680]: info: Loading plugin "youtube2"... Apr 14 19:21:11 volumio go-librespot[4661]: time="2026-04-14T19:21:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:11 volumio go-librespot[4661]: time="2026-04-14T19:21:11+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:11 volumio go-librespot[4661]: time="2026-04-14T19:21:11+07:00" level=debug msg="completed challenge" Apr 14 19:21:11 volumio go-librespot[4661]: time="2026-04-14T19:21:11+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:11 volumio volumio[4680]: info: Loading plugin "ytcr"... Apr 14 19:21:11 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:11.639+07:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=10.0.1.104:43326 Apr 14 19:21:11 volumio go-librespot[4661]: time="2026-04-14T19:21:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:12 volumio go-librespot[4661]: time="2026-04-14T19:21:12+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:12 volumio go-librespot[4661]: time="2026-04-14T19:21:12+07:00" level=debug msg="completed challenge" Apr 14 19:21:12 volumio go-librespot[4661]: time="2026-04-14T19:21:12+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:12 volumio go-librespot[4661]: time="2026-04-14T19:21:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "outputs"... Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "albumart"... Apr 14 19:21:12 volumio volumio[4680]: info: Plugin example_plugin is not enabled Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "inputs"... Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "updater_comm"... Apr 14 19:21:12 volumio volumio[4680]: info: Plugin mpdemulation is not enabled Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "rest_api"... Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "websocket"... Apr 14 19:21:12 volumio volumio[4753]: Forking 3 albumart workers Apr 14 19:21:12 volumio volumio[4680]: info: Starting Socket.io Server version 1.7.4 Apr 14 19:21:12 volumio volumio[4680]: info: Loading plugin "storage_manager"... Apr 14 19:21:12 volumio volumio[4680]: info: Loading i18n strings for locale vi Apr 14 19:21:12 volumio volumio[4680]: Updating browse sources language Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::initPlayerControls Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: Express server listening on port 3000 Apr 14 19:21:12 volumio volumio[4680]: [Metrics] WebUI: 6s 39.68ms Apr 14 19:21:12 volumio volumio[4680]: info: Setting Device type: x86 Apr 14 19:21:12 volumio volumio[4680]: info: CoreStateMachine::resetVolumioState Apr 14 19:21:12 volumio volumio[4680]: info: CoreStateMachine::getcurrentVolume Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:21:12 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:12 volumio volumio[4680]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 14 19:21:12 volumio volumio[4680]: info: Completed loading Core Plugins Apr 14 19:21:12 volumio volumio[4680]: info: Preparing to generate the ALSA configuration file Apr 14 19:21:12 volumio volumio[4680]: info: Volumio Network Manager: Network status updated: 1 Apr 14 19:21:12 volumio volumio[4680]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 14 19:21:12 volumio volumio[4680]: wlan0 Interface doesn't support scanning. Apr 14 19:21:12 volumio volumio[4680]: info: Cannot use regular scanning, forcing with ap-force Apr 14 19:21:12 volumio sudo[4798]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 14 19:21:12 volumio sudo[4798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:12 volumio sudo[4798]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:12 volumio volumio[4680]: command failed: No such device (-19) Apr 14 19:21:12 volumio volumio[4680]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 14 19:21:12 volumio volumio[4680]: command failed: No such device (-19) Apr 14 19:21:12 volumio volumio[4764]: Starting albumart workers Apr 14 19:21:12 volumio volumio[4680]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 14 19:21:12 volumio volumio[4766]: Starting albumart workers Apr 14 19:21:13 volumio volumio[4765]: Starting albumart workers Apr 14 19:21:13 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Apr 14 19:21:13 volumio volumio[4680]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:21:13 volumio volumio[4680]: info: CoreStateMachine::pushState Apr 14 19:21:13 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:13 volumio volumio[4680]: info: CoreStateMachine::updateTrackBlock Apr 14 19:21:13 volumio volumio[4680]: info: CorePlayQueue::getTrackBlock Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:21:13 volumio volumio-remote-updater[827]: [2026-04-14 19:21:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776169270 101 Apr 14 19:21:13 volumio volumio[4680]: 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: 1 Apr 14 19:21:13 volumio volumio[4680]: info: Reloading queue from file Apr 14 19:21:13 volumio volumio[4680]: verbose: New Socket.io Connection to 10.0.1.110 from 10.0.1.104 UA: Mozilla/5.0 (Linux; Android 16; SM-S901E Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Apr 14 19:21:13 volumio volumio[4680]: info: Asound.conf file unchanged, so no further update is needed Apr 14 19:21:13 volumio volumio[4680]: info: Output device has changed, restarting MPD Apr 14 19:21:13 volumio volumio[4680]: info: Output device has changed, restarting Shairport Sync Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:13 volumio sudo[4809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:21:13 volumio sudo[4809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:13 volumio sudo[4809]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:13 volumio sudo[4811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:21:13 volumio sudo[4811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:13 volumio volumio[4680]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:21:13 volumio volumio[4680]: info: ___________ START PLUGINS ___________ Apr 14 19:21:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 19:21:13 volumio volumio[4680]: info: ControllerMpd::onStart: Initializing MPD Apr 14 19:21:13 volumio volumio[4680]: info: Creating MPD Configuration file Apr 14 19:21:13 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:21:13 volumio sudo[4820]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 14 19:21:13 volumio sudo[4820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:21:13 volumio systemd[1]: mpd.service: Consumed 1.511s CPU time. Apr 14 19:21:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:21:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:21:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:13 volumio volumio[4680]: info: [1776169273377] CoreMusicLibrary::Adding element Máy chủ Media Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:13 volumio sudo[4822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:21:13 volumio sudo[4822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:13 volumio sudo[4822]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:13 volumio volumio[4680]: info: UPNP Browser: Client initialized successfully Apr 14 19:21:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:21:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:21:13 volumio sudo[4825]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:21:13 volumio sudo[4825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:13 volumio sudo[4820]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:13 volumio volumio[4680]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:13 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:21:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:21:13 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:21:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:21:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:21:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:21:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:21:13 volumio volumio[4680]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:13 volumio volumio[4680]: info: [1776169273528] CoreMusicLibrary::Adding element Last_100 Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:13 volumio volumio[4680]: info: [1776169273540] CoreMusicLibrary::Adding element Webradio Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:13 volumio volumio[4680]: info: Initializing BBC Radios Apr 14 19:21:13 volumio sudo[4839]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 19:21:13 volumio sudo[4839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 19:21:13 volumio sudo[4839]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:13 volumio volumio[4680]: info: [1776169273674] CoreMusicLibrary::Adding element Mixcloud Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:13 volumio volumio[4680]: Cannot find translation for source Mixcloud Apr 14 19:21:13 volumio volumio[4680]: info: Creating Spotify config file Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:13 volumio volumio[4680]: info: [1776169273874] CoreMusicLibrary::Adding element YouTube2 Apr 14 19:21:13 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:13 volumio volumio[4680]: Cannot find translation for source Mixcloud Apr 14 19:21:13 volumio volumio[4680]: Cannot find translation for source YouTube2 Apr 14 19:21:13 volumio volumio[4680]: info: Volumio Calling Home Apr 14 19:21:14 volumio volumio[4680]: info: CoreStateMachine::setRepeat null single undefined Apr 14 19:21:14 volumio volumio[4680]: info: CoreStateMachine::pushState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:14 volumio volumio[4680]: info: CoreStateMachine::setRandom false Apr 14 19:21:14 volumio volumio[4680]: info: CoreStateMachine::pushState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Apr 14 19:21:14 volumio volumio[4680]: info: MPD Permissions set Apr 14 19:21:14 volumio volumio[4680]: info: MPD Permissions set Apr 14 19:21:14 volumio volumio[4680]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:14 volumio volumio[4680]: info: CoreStateMachine::pushState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:14 volumio volumio[4680]: info: Spotify config file written Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio sudo[4879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 19:21:14 volumio sudo[4879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:21:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:14 volumio go-librespot[4889]: go-librespot daemon starting... Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:21:14 volumio sudo[4879]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:14 volumio volumio[4680]: info: No need to fix Spotify hosts Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" level=debug msg="app state loaded" Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 19:21:14 volumio volumio[4680]: info: Discovery: adding aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:21:14 volumio volumio[4680]: info: Discovery: Found device Volumio Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:14 volumio volumio[4680]: info: Discovery: this is already registered, aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:21:14 volumio volumio[4680]: info: Discovery: Found device Volumio Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 19:21:14 volumio volumio[4680]: info: Starting Shairport Sync Apr 14 19:21:14 volumio volumio[4680]: info: Starting Shairport Sync Apr 14 19:21:14 volumio volumio[4680]: info: Starting Shairport Sync Apr 14 19:21:14 volumio sudo[4908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:21:14 volumio sudo[4908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:14 volumio sudo[4911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:21:14 volumio sudo[4911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:14 volumio sudo[4915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:21:14 volumio sudo[4915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:21:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:21:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:21:14 volumio systemd[1]: shairport-sync.service: Consumed 1.865s CPU time. Apr 14 19:21:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:21:14 volumio sudo[4911]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:14 volumio sudo[4908]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:21:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:21:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:21:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:21:14 volumio sudo[4915]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" 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]" Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" 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]" Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" 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]" Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" level=info msg="zeroconf server listening on port 44073" Apr 14 19:21:14 volumio volumio[4680]: info: Volumio called home Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 19:21:14 volumio volumio[4680]: info: Shairport-Sync Started Apr 14 19:21:14 volumio volumio[4680]: Error adding Membership: Error: addMembership EINVAL Apr 14 19:21:14 volumio volumio[4680]: info: Shairport-Sync Started Apr 14 19:21:14 volumio volumio[4680]: info: Shairport-Sync Started Apr 14 19:21:14 volumio go-librespot[4895]: time="2026-04-14T19:21:14+07:00" level=debug msg="obtained new client token: AADt90B3SdRp5A/JnW7rjCXw9s0/fn6YcHw4oRW60gGm2gGkL/rtbzMIivkZc6vdmiR9Fq1i9E/devzi40XaIitKVI4ihKKknYfUtSJRK8606IsuKIOJlnSuEiLnQXt+6bptzXOVuz1mFDBCICY/3aTUOO6FbpqK55Kex2aowFPVq/uoAgEO0p0IhiQPRrp0sw0tHH3zgfZdPoLVwfN+xxlEvrqsCGOVb6EplefLh7qcmevSnvSA85h0" Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 19:21:14 volumio volumio[4680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 19:21:14 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:14 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:15 volumio mpd[4866]: 2026-04-14T19:21:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 19:21:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 19:21:15 volumio sudo[4811]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:15 volumio sudo[4825]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=debug msg="completed challenge" Apr 14 19:21:15 volumio volumio[4680]: error: MPD error: The expression evaluated to a falsy value: Apr 14 19:21:15 volumio volumio[4680]: assert.ok(self.idling) Apr 14 19:21:15 volumio volumio[4680]: error: The expression evaluated to a falsy value: Apr 14 19:21:15 volumio volumio[4680]: assert.ok(self.idling) Apr 14 19:21:15 volumio volumio[4680]: info: MPD running with PID4866 Apr 14 19:21:15 volumio volumio[4680]: ,establishing connection Apr 14 19:21:15 volumio volumio[4680]: error: updateQueue error: null Apr 14 19:21:15 volumio volumio[4680]: error: updateQueue error: null Apr 14 19:21:15 volumio volumio[4680]: info: New Spotify access tokenBQAUNMHP6h... Apr 14 19:21:15 volumio volumio[4680]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:15 volumio volumio[4680]: SPOTIFY: User informations: {"country":"GB","display_name":"Kenky Cool","email":"kenkycool97@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/42j4swbhr91mth0xx3exmu8s0"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/42j4swbhr91mth0xx3exmu8s0","id":"42j4swbhr91mth0xx3exmu8s0","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=300&width=300&ext=1778753480&hash=AT8-KOYVDV5N6LlcBEJhd_qw","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=50&width=50&ext=1778753480&hash=AT-KltT7sc5TFuHT3APbyHTf","width":64}],"product":"free","type":"user","uri":"spotify:user:42j4swbhr91mth0xx3exmu8s0"} Apr 14 19:21:15 volumio volumio[4680]: info: Spotify Successfully logged in Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:15 volumio volumio[4680]: info: [1776169275452] CoreMusicLibrary::Adding element Spotify Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:15 volumio volumio[4680]: Cannot find translation for source Mixcloud Apr 14 19:21:15 volumio volumio[4680]: Cannot find translation for source YouTube2 Apr 14 19:21:15 volumio volumio[4680]: Cannot find translation for source Spotify Apr 14 19:21:15 volumio volumio[4680]: info: [yt-cast-receiver] DIAL server listening on port 8098 Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:15 volumio volumio[4680]: info: Completed starting Core Plugins Apr 14 19:21:15 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:15 volumio volumio[4680]: info: ----- MyVolumio plugins startup ---- Apr 14 19:21:15 volumio volumio[4680]: info: ------------------------------------------- Apr 14 19:21:15 volumio volumio[4680]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.871+07:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="10.0.1.104:43326 @ 0xc00041d8c0" latency=183.771078ms timeout=10s Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.871+07:00 level=INFO msg="emitting device capabilities changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.872+07:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="10.0.1.104:43326 @ 0xc00041d8c0" latency=186.242197ms platform=PLATFORM_ANDROID version=5.260331.0 Apr 14 19:21:15 volumio volumio[4680]: info: Received Get System Info Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:15 volumio volumio[4680]: info: Discovery: Getting this device information Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:15 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.882+07:00 level=INFO msg="emitting device name changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" name=Volumio Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.883+07:00 level=INFO msg="emitting device language changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" language=vi Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.888+07:00 level=INFO msg="emitting device timezone changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" timezone=Asia/Ho_Chi_Minh Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.890+07:00 level=INFO msg="emitting ethernet info changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" available=true connected=true macAddress=6c:2b:59:48:cb:cb ip4Address=10.0.1.110/24 ip6Address= Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.891+07:00 level=INFO msg="emitting wifi info changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" available=false connected=false macAddress= ip4Address= ip6Address= ssid= Apr 14 19:21:15 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:15.891+07:00 level=INFO msg="emitting device setup status changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" setupComplete=true Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=debug msg="completed challenge" Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:15 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 14 19:21:15 volumio volumio[4680]: amixer -c 1 info | grep "bytcr-rt5640" Apr 14 19:21:15 volumio volumio[4680]: amixer -c 1 info | grep "bytcr-rt5640" Apr 14 19:21:15 volumio go-librespot[4895]: time="2026-04-14T19:21:15+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:16 volumio volumio[4680]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 2 Apr 14 19:21:16 volumio volumio[4680]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 14 19:21:16 volumio volumio[4680]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 2\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 14 19:21:16 volumio volumio[4680]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 1 Apr 14 19:21:16 volumio volumio[4680]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 14 19:21:16 volumio volumio[4680]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 1","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 1\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 14 19:21:16 volumio volumio[4680]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 0 -D 0 Apr 14 19:21:16 volumio volumio[4680]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 14 19:21:16 volumio volumio[4680]: {"cmd":"/usr/local/bin/alsacap -C 0 -D 0","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 0 -D 0\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.032+07:00 level=INFO msg="emitting audio outputs changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" selectedOutputId=1 Apr 14 19:21:16 volumio volumio[4680]: info: Received Get System Info Apr 14 19:21:16 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:16 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:16 volumio volumio[4680]: info: Discovery: Getting this device information Apr 14 19:21:16 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:16 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:16 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.083+07:00 level=INFO msg="emitting software info changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" currentVersion=4.119 latestVersion=4.119 Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.084+07:00 level=INFO msg="emitting software update progress event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" status=UPDATE_STATUS_NONE progress=0 Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.084+07:00 level=INFO msg="emitting user changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" userId=UWS46gyUKeg6VaOp9Gke3f10vBm2 Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.084+07:00 level=INFO msg="emitting music providers changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" providers=9 Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.084+07:00 level=INFO msg="emitting plugins changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" plugins=51 Apr 14 19:21:16 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:16 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.090+07:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" state=STATUS_STOPPED positionMs=0 volume=30 Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.090+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.1.104:43326 @ 0xc00041d8c0" id="youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22SAU%20L%E1%BB%9CI%20T%E1%BB%AA%20KH%C6%AF%E1%BB%9AC%20-%20PHAN%20M%E1%BA%A0NH%20QU%E1%BB%B2NH%20%7C%20OFFICIAL%20MV%20(OST%20phim%20MAI%2C%20%C4%90%E1%BA%A1o%20Di%E1%BB%85n%20Tr%E1%BA%A5n%20Th%C3%A0nh)%22%2C%22artist%22%3A%22TR%E1%BA%A4N%20TH%C3%80NH%20TOWN%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fh_1t3-6oWz4%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLDqYqZEDhm8ALmDhRBLfHct9dZa6A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D" title="SAU LỜI TỪ KHƯỚC - PHAN MẠNH QUỲNH | OFFICIAL MV (OST phim MAI, Đạo Diễn Trấn Thành)" Apr 14 19:21:16 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:16.141+07:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="10.0.1.104:43326 @ 0xc00041d8c0" latency=171.358067ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 14 19:21:16 volumio go-librespot[4895]: time="2026-04-14T19:21:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:21:16 volumio go-librespot[4895]: time="2026-04-14T19:21:16+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:16 volumio go-librespot[4895]: time="2026-04-14T19:21:16+07:00" level=debug msg="completed challenge" Apr 14 19:21:16 volumio go-librespot[4895]: time="2026-04-14T19:21:16+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:17 volumio sudo[4962]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:21:17 volumio sudo[4962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:17 volumio sudo[4962]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:17 volumio sudo[4965]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:21:17 volumio sudo[4965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:17 volumio sudo[4965]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:17 volumio volumio[4680]: verbose: New Socket.io Connection to 10.0.1.110 from 10.0.1.104 UA: Mozilla/5.0 (Linux; Android 16; SM-S901E Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Apr 14 19:21:17 volumio volumio[4680]: info: go-librespot daemon successfully initialized Apr 14 19:21:17 volumio sudo[4973]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:21:17 volumio sudo[4973]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:17 volumio sudo[4975]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:21:17 volumio sudo[4975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:17 volumio sudo[4973]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:17 volumio sudo[4975]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:17 volumio volumio[4680]: verbose: New Socket.io Connection to 10.0.1.110 from 10.0.1.104 UA: Mozilla/5.0 (Linux; Android 16; SM-S901E Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 14 19:21:17 volumio go-librespot[4895]: time="2026-04-14T19:21:17+07:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:17 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::volumioGetQueue Apr 14 19:21:17 volumio volumio[4680]: info: CoreStateMachine::getQueue Apr 14 19:21:17 volumio volumio[4680]: info: CorePlayQueue::getQueue Apr 14 19:21:17 volumio volumio[4680]: info: Listing playlists Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 19:21:17 volumio volumio[4680]: info: Received Get System Info Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:17 volumio volumio[4680]: info: Discovery: Getting this device information Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:17 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:17 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 14 19:21:17 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 19:21:17 volumio go-librespot[4895]: time="2026-04-14T19:21:17+07:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 19:21:18 volumio go-librespot[4895]: time="2026-04-14T19:21:18+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:18 volumio go-librespot[4895]: time="2026-04-14T19:21:18+07:00" level=debug msg="completed challenge" Apr 14 19:21:18 volumio go-librespot[4895]: time="2026-04-14T19:21:18+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:18 volumio sudo[4996]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:21:18 volumio sudo[4996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:18 volumio sudo[4996]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:18 volumio sudo[4999]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:21:18 volumio sudo[4999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:18 volumio sudo[5001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 19:21:18 volumio sudo[5001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:18 volumio sudo[4999]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:18 volumio sudo[5001]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:18 volumio volumio[4680]: info: Upmpdcli Daemon Started Apr 14 19:21:19 volumio go-librespot[4895]: time="2026-04-14T19:21:19+07:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Apr 14 19:21:19 volumio go-librespot[4895]: time="2026-04-14T19:21:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:19 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 14 19:21:19 volumio go-librespot[4895]: time="2026-04-14T19:21:19+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:19 volumio go-librespot[4895]: time="2026-04-14T19:21:19+07:00" level=debug msg="completed challenge" Apr 14 19:21:19 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 19:21:19 volumio volumio[4680]: info: Received Get System Info Apr 14 19:21:19 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:19 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:19 volumio volumio[4680]: info: Discovery: Getting this device information Apr 14 19:21:19 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:19 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:19 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:19 volumio go-librespot[4895]: time="2026-04-14T19:21:19+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:20 volumio go-librespot[4895]: time="2026-04-14T19:21:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::volumioPlay Apr 14 19:21:20 volumio volumio[4680]: info: CoreStateMachine::play index undefined Apr 14 19:21:20 volumio volumio[4680]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 19:21:20 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:20 volumio volumio[4680]: info: CoreStateMachine::startPlaybackTimer Apr 14 19:21:20 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:20 volumio volumio[4680]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22SAU%20L%E1%BB%9CI%20T%E1%BB%AA%20KH%C6%AF%E1%BB%9AC%20-%20PHAN%20M%E1%BA%A0NH%20QU%E1%BB%B2NH%20%7C%20OFFICIAL%20MV%20(OST%20phim%20MAI%2C%20%C4%90%E1%BA%A1o%20Di%E1%BB%85n%20Tr%E1%BA%A5n%20Th%C3%A0nh)%22%2C%22artist%22%3A%22TR%E1%BA%A4N%20TH%C3%80NH%20TOWN%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fh_1t3-6oWz4%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLDqYqZEDhm8ALmDhRBLfHct9dZa6A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D Apr 14 19:21:20 volumio go-librespot[4895]: time="2026-04-14T19:21:20+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:20 volumio go-librespot[4895]: time="2026-04-14T19:21:20+07:00" level=debug msg="completed challenge" Apr 14 19:21:20 volumio volumio[4680]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 19:21:20 volumio go-librespot[4895]: time="2026-04-14T19:21:20+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:20 volumio go-librespot[4895]: time="2026-04-14T19:21:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:20 volumio volumio[4680]: info: Initializing connection to go-librespot Websocket Apr 14 19:21:20 volumio volumio[4680]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 19:21:20 volumio volumio[4680]: info: Received Get System Info Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:20 volumio volumio[4680]: info: Discovery: Getting this device information Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:20 volumio volumio[4680]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:20 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Apr 14 19:21:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:23 volumio go-librespot[5011]: go-librespot daemon starting... Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" level=debug msg="app state loaded" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" 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]" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" 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]" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" 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]" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" level=info msg="zeroconf server listening on port 46779" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:21:23 volumio go-librespot[5012]: time="2026-04-14T19:21:23+07:00" level=debug msg="obtained new client token: AADu475Hctsq7k/fXZAfev+dW1wdYgB3yDxzuCeuAAFYoKtu4E9FctlXzzMWAPEFbGlu+OyDCPtAc2VkoOeDg2WiUExB7C3aRF6GKzSPoTDySKmHzUI91WFOrwh2PkPMY+EJqt0mS2DHppN+dSeiVJ+3Qbk94L93JZjfDSRPkY06auEchWEH+0h3qN1E1mw5z3b6oLT7pnfJHtWmXIFz+Vdcb1Xtw6Nh/3tblkbpVgeNUwyFA6t5nIfl" Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=debug msg="completed challenge" Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:24 volumio go-librespot[5012]: time="2026-04-14T19:21:24+07:00" level=debug msg="completed challenge" Apr 14 19:21:25 volumio go-librespot[5012]: time="2026-04-14T19:21:25+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:25 volumio go-librespot[5012]: time="2026-04-14T19:21:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:21:25 volumio go-librespot[5012]: time="2026-04-14T19:21:25+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:25 volumio go-librespot[5012]: time="2026-04-14T19:21:25+07:00" level=debug msg="completed challenge" Apr 14 19:21:25 volumio go-librespot[5012]: time="2026-04-14T19:21:25+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:26 volumio volumio[4680]: info: Initializing connection to go-librespot Websocket Apr 14 19:21:26 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 14 19:21:26 volumio go-librespot[5012]: time="2026-04-14T19:21:26+07:00" level=debug msg="new websocket client" Apr 14 19:21:26 volumio volumio[4680]: info: Connection to go-librespot Websocket established Apr 14 19:21:26 volumio go-librespot[5012]: time="2026-04-14T19:21:26+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 19:21:26 volumio go-librespot[5012]: time="2026-04-14T19:21:26+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:26 volumio go-librespot[5012]: time="2026-04-14T19:21:26+07:00" level=debug msg="completed challenge" Apr 14 19:21:27 volumio go-librespot[5012]: time="2026-04-14T19:21:27+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:27 volumio go-librespot[5012]: time="2026-04-14T19:21:27+07:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 19:21:28 volumio go-librespot[5012]: time="2026-04-14T19:21:28+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:28 volumio go-librespot[5012]: time="2026-04-14T19:21:28+07:00" level=debug msg="completed challenge" Apr 14 19:21:28 volumio go-librespot[5012]: time="2026-04-14T19:21:28+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:29 volumio go-librespot[5012]: time="2026-04-14T19:21:29+07:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 19:21:29 volumio go-librespot[5012]: time="2026-04-14T19:21:29+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:29 volumio go-librespot[5012]: time="2026-04-14T19:21:29+07:00" level=debug msg="completed challenge" Apr 14 19:21:29 volumio go-librespot[5012]: time="2026-04-14T19:21:29+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:29 volumio go-librespot[5012]: time="2026-04-14T19:21:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:31 volumio volumio[4680]: npm ERR! code ENOTEMPTY Apr 14 19:21:31 volumio volumio[4680]: npm ERR! syscall rename Apr 14 19:21:31 volumio volumio[4680]: npm ERR! path /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno Apr 14 19:21:31 volumio volumio[4680]: npm ERR! dest /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv Apr 14 19:21:31 volumio volumio[4680]: npm ERR! errno -39 Apr 14 19:21:31 volumio volumio[4680]: npm ERR! ENOTEMPTY: directory not empty, rename '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno' -> '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv' Apr 14 19:21:31 volumio volumio[4680]: npm ERR! A complete log of this run can be found in: /home/volumio/.npm/_logs/2026-04-14T12_21_27_542Z-debug-0.log Apr 14 19:21:31 volumio volumio[4680]: info: [youtube2] Innertube support service: Deno not installed or otherwise failed to start: Command failed: npx --no-install --yes deno --version Apr 14 19:21:31 volumio volumio[4680]: npm ERR! code ENOTEMPTY Apr 14 19:21:31 volumio volumio[4680]: npm ERR! syscall rename Apr 14 19:21:31 volumio volumio[4680]: npm ERR! path /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno Apr 14 19:21:31 volumio volumio[4680]: npm ERR! dest /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv Apr 14 19:21:31 volumio volumio[4680]: npm ERR! errno -39 Apr 14 19:21:31 volumio volumio[4680]: npm ERR! ENOTEMPTY: directory not empty, rename '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno' -> '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv' Apr 14 19:21:31 volumio volumio[4680]: npm ERR! A complete log of this run can be found in: /home/volumio/.npm/_logs/2026-04-14T12_21_27_542Z-debug-0.log Apr 14 19:21:31 volumio volumio[4680]: info: [youtube2] Innertube support service: Start service with Node Apr 14 19:21:31 volumio volumio[4680]: info: Getting Spotify volume Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 19:21:31 volumio volumio[4680]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 19:21:31 volumio ntpd[1029]: PROTO: 85.121.244.101 unlink local addr 10.0.1.110 -> Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 19:21:32 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:32 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:32 volumio volumio[4680]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 19:21:32 volumio volumio[4680]: info: MyVolumio login type: Token Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 19:21:32 volumio volumio[4680]: info: Streaming services startup Apr 14 19:21:32 volumio volumio[4680]: info: Starting Streaming Daemon Apr 14 19:21:32 volumio sudo[5079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 19:21:32 volumio sudo[5079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:32 volumio volumio[4680]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 19:21:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Apr 14 19:21:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:32 volumio volumio[4680]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 14 19:21:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:32 volumio go-librespot[5085]: go-librespot daemon starting... Apr 14 19:21:32 volumio sudo[5079]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:32 volumio volumio[4680]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:32 volumio volumio[4680]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 19:21:32 volumio volumio[4680]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 19:21:32 volumio volumio[4680]: errno: -111, Apr 14 19:21:32 volumio volumio[4680]: code: 'ECONNREFUSED', Apr 14 19:21:32 volumio volumio[4680]: syscall: 'connect', Apr 14 19:21:32 volumio volumio[4680]: address: '127.0.0.1', Apr 14 19:21:32 volumio volumio[4680]: port: 9879, Apr 14 19:21:32 volumio volumio[4680]: response: undefined Apr 14 19:21:32 volumio volumio[4680]: } Apr 14 19:21:32 volumio volumio[4680]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:32 volumio go-librespot[5086]: time="2026-04-14T19:21:32+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:21:32 volumio go-librespot[5086]: time="2026-04-14T19:21:32+07:00" level=debug msg="app state loaded" Apr 14 19:21:32 volumio go-librespot[5086]: time="2026-04-14T19:21:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:21:33 volumio sudo[5109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 19:20' Apr 14 19:21:33 volumio sudo[5109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" 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]" Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" 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]" Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" 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]" Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=info msg="zeroconf server listening on port 43245" Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:21:33 volumio sudo[5109]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:33 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:33.364+07:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Apr 14 19:21:33 volumio volumio-remote-updater[827]: [2026-04-14 19:21:33] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 19:21:33 volumio volumio-remote-updater[827]: [2026-04-14 19:21:33] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 19:21:33 volumio volumio5-onboarding[1406]: time=2026-04-14T19:21:33.366+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 14 19:21:33 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:33 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 19:21:33 volumio systemd[1]: volumio.service: Consumed 38.977s CPU time. Apr 14 19:21:33 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=debug msg="obtained new client token: AAAMmaLLNUBxK+huYWiH+ACRahVsyyr3V1D7D7IUsiRshFF7syZypQ3BrGI/kvFdBy8QUQv1bWnTbtHr8+c2YdiRueRVWvVR7uvnv7K7uLTyPIniZkSGESjuqsF1IltFeBagcw2C0x5myWHbPQHdgtu84/U6cHs4WztHnVkWaWFp+T4AH6AMTgeAq7TEzc5Kj4LHBejjLTq8110+MxD0hBhCAAGjNmnVEHNIW1i8tMDNJMuivJOIS+VL" Apr 14 19:21:33 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:33 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=debug msg="completed challenge" Apr 14 19:21:33 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:21:33 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 19:21:33 volumio systemd[1]: volumio.service: Consumed 38.977s CPU time. Apr 14 19:21:33 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 19:21:33 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:21:33 volumio go-librespot[5086]: time="2026-04-14T19:21:33+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:34 volumio go-librespot[5086]: time="2026-04-14T19:21:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:34 volumio go-librespot[5086]: time="2026-04-14T19:21:34+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:34 volumio go-librespot[5086]: time="2026-04-14T19:21:34+07:00" level=debug msg="completed challenge" Apr 14 19:21:34 volumio go-librespot[5086]: time="2026-04-14T19:21:34+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:34 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:34 volumio volumio[5122]: info: ----- Volumio3 ---- Apr 14 19:21:34 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:34 volumio volumio[5122]: info: ----- System startup ---- Apr 14 19:21:34 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:35 volumio go-librespot[5086]: time="2026-04-14T19:21:35+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Apr 14 19:21:35 volumio volumio[5122]: info: MYVOLUMIO Environment detected Apr 14 19:21:35 volumio volumio[5122]: info: Plugin folders cleanup Apr 14 19:21:35 volumio volumio[5122]: info: Scanning into folder /volumio/app/plugins/ Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category audio_interface Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category miscellanea Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category music_service Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category plugins.json Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category system_controller Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category user_interface Apr 14 19:21:35 volumio volumio[5122]: info: Scanning into folder /data/plugins/ Apr 14 19:21:35 volumio volumio[5122]: info: Scanning into folder /data/plugins/ Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category music_service Apr 14 19:21:35 volumio volumio[5122]: info: Scanning category system_hardware Apr 14 19:21:35 volumio volumio[5122]: info: Plugin folders cleanup completed Apr 14 19:21:35 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:35 volumio volumio[5122]: info: ----- Core plugins startup ---- Apr 14 19:21:35 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:35 volumio volumio[5122]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 19:21:35 volumio volumio[5122]: info: Adding plugin upnp to MyMusic Plugins Apr 14 19:21:35 volumio volumio[5122]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 19:21:35 volumio volumio[5122]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 19:21:35 volumio volumio[5122]: info: Loading plugins from folder /data/plugins/ Apr 14 19:21:35 volumio volumio[5122]: info: Loading plugin "system"... Apr 14 19:21:35 volumio volumio[5122]: info: Loading plugin "appearance"... Apr 14 19:21:35 volumio go-librespot[5086]: time="2026-04-14T19:21:35+07:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Apr 14 19:21:35 volumio go-librespot[5086]: time="2026-04-14T19:21:35+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 19:21:35 volumio volumio[5122]: info: Loading plugin "network"... Apr 14 19:21:35 volumio volumio[5122]: info: Refreshing Cached IP Addresses Apr 14 19:21:36 volumio sudo[5153]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:21:36 volumio sudo[5153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:36 volumio sudo[5155]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:21:36 volumio sudo[5155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:36 volumio sudo[5153]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "services"... Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "volumio5onboarding"... Apr 14 19:21:36 volumio go-librespot[5086]: time="2026-04-14T19:21:36+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:36 volumio go-librespot[5086]: time="2026-04-14T19:21:36+07:00" level=debug msg="completed challenge" Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "alsa_controller"... Apr 14 19:21:36 volumio sudo[5163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 19:21:36 volumio sudo[5155]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:36 volumio sudo[5163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:36 volumio sudo[5163]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:36 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "wizard"... Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "networkfs"... Apr 14 19:21:36 volumio volumio[5122]: info: Starting Udev Watcher for removable devices Apr 14 19:21:36 volumio volumio[5122]: info: Ignoring mount for partition: boot Apr 14 19:21:36 volumio volumio[5122]: info: Ignoring mount for partition: volumio Apr 14 19:21:36 volumio volumio[5122]: info: Ignoring mount for partition: volumio_data Apr 14 19:21:36 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "volumio_command_line_client"... Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "upnp"... Apr 14 19:21:36 volumio volumio[5122]: info: [1776169296189] Starting Upmpd Daemon Apr 14 19:21:36 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "my_music"... Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "mpd"... Apr 14 19:21:36 volumio go-librespot[5086]: time="2026-04-14T19:21:36+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:36 volumio volumio[5122]: info: Loading plugin "upnp_browser"... Apr 14 19:21:37 volumio go-librespot[5086]: time="2026-04-14T19:21:37+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:21:37 volumio volumio[5122]: info: Starting UPNP Browser Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "alarm-clock"... Apr 14 19:21:37 volumio ntpd[1029]: PROTO: 118.143.17.82 unlink local addr 10.0.1.110 -> Apr 14 19:21:37 volumio go-librespot[5086]: time="2026-04-14T19:21:37+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:37 volumio go-librespot[5086]: time="2026-04-14T19:21:37+07:00" level=debug msg="completed challenge" Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "airplay_emulation"... Apr 14 19:21:37 volumio volumio[5122]: info: Starting Shairport Sync Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "last_100"... Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "webradio"... Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "i2s_dacs"... Apr 14 19:21:37 volumio volumio[5122]: info: I2S DAC not set, start Auto-detection Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "volumiodiscovery"... Apr 14 19:21:37 volumio volumio[5122]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:37 volumio volumio[5122]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:37 volumio volumio[5122]: *** WARNING *** For more information see Apr 14 19:21:37 volumio volumio[5122]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:37 volumio volumio[5122]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:37 volumio volumio[5122]: *** WARNING *** For more information see Apr 14 19:21:37 volumio node[5122]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:37 volumio node[5122]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:37 volumio node[5122]: *** WARNING *** For more information see Apr 14 19:21:37 volumio node[5122]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:21:37 volumio volumio[5122]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 19:21:37 volumio node[5122]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:21:37 volumio node[5122]: *** WARNING *** For more information see Apr 14 19:21:37 volumio volumio[5122]: info: Discovery: Started advertising with name: Volumio Apr 14 19:21:37 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "mixcloud"... Apr 14 19:21:37 volumio go-librespot[5086]: time="2026-04-14T19:21:37+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:37 volumio volumio[5122]: info: Plugin soundcloud is not enabled Apr 14 19:21:37 volumio volumio[5122]: info: Loading plugin "spop"... Apr 14 19:21:38 volumio go-librespot[5086]: time="2026-04-14T19:21:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:38 volumio volumio-remote-updater[827]: [2026-04-14 19:21:38] [connect] Successful connection Apr 14 19:21:38 volumio go-librespot[5086]: time="2026-04-14T19:21:38+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:38 volumio go-librespot[5086]: time="2026-04-14T19:21:38+07:00" level=debug msg="completed challenge" Apr 14 19:21:38 volumio go-librespot[5086]: time="2026-04-14T19:21:38+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:38 volumio volumio[5122]: info: Loading plugin "youtube2"... Apr 14 19:21:39 volumio volumio[5122]: info: Loading plugin "ytcr"... Apr 14 19:21:39 volumio go-librespot[5086]: time="2026-04-14T19:21:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:39 volumio go-librespot[5086]: time="2026-04-14T19:21:39+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:39 volumio go-librespot[5086]: time="2026-04-14T19:21:39+07:00" level=debug msg="completed challenge" Apr 14 19:21:39 volumio go-librespot[5086]: time="2026-04-14T19:21:39+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:39 volumio go-librespot[5086]: time="2026-04-14T19:21:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:39 volumio volumio[5122]: info: Loading plugin "outputs"... Apr 14 19:21:39 volumio volumio[5122]: info: Loading plugin "albumart"... Apr 14 19:21:39 volumio volumio[5122]: info: Plugin example_plugin is not enabled Apr 14 19:21:39 volumio volumio[5122]: info: Loading plugin "inputs"... Apr 14 19:21:40 volumio volumio[5122]: info: Loading plugin "updater_comm"... Apr 14 19:21:40 volumio volumio[5122]: info: Plugin mpdemulation is not enabled Apr 14 19:21:40 volumio volumio[5122]: info: Loading plugin "rest_api"... Apr 14 19:21:40 volumio volumio[5122]: info: Loading plugin "websocket"... Apr 14 19:21:40 volumio volumio[5196]: Forking 3 albumart workers Apr 14 19:21:40 volumio volumio[5122]: info: Starting Socket.io Server version 1.7.4 Apr 14 19:21:40 volumio volumio[5122]: info: Loading plugin "storage_manager"... Apr 14 19:21:40 volumio volumio[5122]: info: Loading i18n strings for locale vi Apr 14 19:21:40 volumio volumio[5122]: Updating browse sources language Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::initPlayerControls Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: Express server listening on port 3000 Apr 14 19:21:40 volumio volumio[5122]: [Metrics] WebUI: 6s 12.13ms Apr 14 19:21:40 volumio volumio[5122]: info: Setting Device type: x86 Apr 14 19:21:40 volumio volumio[5122]: info: CoreStateMachine::resetVolumioState Apr 14 19:21:40 volumio volumio[5122]: info: CoreStateMachine::getcurrentVolume Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 14 19:21:40 volumio volumio[5122]: info: Completed loading Core Plugins Apr 14 19:21:40 volumio volumio[5122]: info: Preparing to generate the ALSA configuration file Apr 14 19:21:40 volumio volumio[5122]: info: Volumio Network Manager: Network status updated: 1 Apr 14 19:21:40 volumio volumio[5122]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 14 19:21:40 volumio volumio[5122]: wlan0 Interface doesn't support scanning. Apr 14 19:21:40 volumio volumio[5122]: info: Cannot use regular scanning, forcing with ap-force Apr 14 19:21:40 volumio sudo[5241]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 14 19:21:40 volumio sudo[5241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:40 volumio sudo[5241]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:40 volumio volumio[5122]: command failed: No such device (-19) Apr 14 19:21:40 volumio volumio[5122]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 14 19:21:40 volumio volumio[5122]: command failed: No such device (-19) Apr 14 19:21:40 volumio volumio[5122]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 14 19:21:40 volumio volumio[5122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Apr 14 19:21:40 volumio volumio[5207]: Starting albumart workers Apr 14 19:21:40 volumio volumio[5122]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:21:40 volumio volumio[5122]: info: CoreStateMachine::pushState Apr 14 19:21:40 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:40 volumio volumio[5208]: Starting albumart workers Apr 14 19:21:40 volumio volumio[5122]: info: CoreStateMachine::updateTrackBlock Apr 14 19:21:40 volumio volumio[5122]: info: CorePlayQueue::getTrackBlock Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:21:40 volumio volumio[5206]: Starting albumart workers Apr 14 19:21:40 volumio volumio[5122]: verbose: New Socket.io Connection to 10.0.1.110 from 10.0.1.104 UA: Mozilla/5.0 (Linux; Android 16; SM-S901E Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 14 19:21:40 volumio volumio[5122]: info: Reloading queue from file Apr 14 19:21:40 volumio volumio-remote-updater[827]: [2026-04-14 19:21:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776169298 101 Apr 14 19:21:40 volumio volumio[5122]: 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: 2 Apr 14 19:21:40 volumio volumio[5122]: info: Asound.conf file unchanged, so no further update is needed Apr 14 19:21:40 volumio volumio[5122]: info: Output device has changed, restarting MPD Apr 14 19:21:40 volumio volumio[5122]: info: Output device has changed, restarting Shairport Sync Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:40 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:40 volumio sudo[5254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:21:40 volumio sudo[5254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:40 volumio sudo[5252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:21:40 volumio sudo[5252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:40 volumio volumio[5122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:21:40 volumio volumio[5122]: info: ___________ START PLUGINS ___________ Apr 14 19:21:40 volumio sudo[5252]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 19:21:40 volumio volumio[5122]: info: ControllerMpd::onStart: Initializing MPD Apr 14 19:21:40 volumio volumio[5122]: info: Creating MPD Configuration file Apr 14 19:21:40 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:21:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:21:40 volumio systemd[1]: mpd.service: Consumed 1.538s CPU time. Apr 14 19:21:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:21:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:21:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:21:41 volumio sudo[5262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 14 19:21:41 volumio sudo[5262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:21:41 volumio sudo[5265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:21:41 volumio sudo[5265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:41 volumio volumio[5122]: info: [1776169301036] CoreMusicLibrary::Adding element Máy chủ Media Apr 14 19:21:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:21:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:41 volumio sudo[5265]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:41 volumio volumio[5122]: info: UPNP Browser: Client initialized successfully Apr 14 19:21:41 volumio sudo[5262]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:41 volumio sudo[5268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:21:41 volumio sudo[5268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:41 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:21:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:21:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:21:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:21:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:21:41 volumio volumio[5122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:21:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:21:41 volumio volumio[5122]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:41 volumio volumio[5122]: info: [1776169301167] CoreMusicLibrary::Adding element Last_100 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:41 volumio volumio[5122]: info: [1776169301175] CoreMusicLibrary::Adding element Webradio Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:41 volumio volumio[5122]: info: Initializing BBC Radios Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:41 volumio volumio[5122]: info: [1776169301273] CoreMusicLibrary::Adding element Mixcloud Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:41 volumio volumio[5122]: Cannot find translation for source Mixcloud Apr 14 19:21:41 volumio sudo[5281]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 19:21:41 volumio sudo[5281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 19:21:41 volumio sudo[5281]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:41 volumio volumio[5122]: info: Creating Spotify config file Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:41 volumio volumio[5122]: info: [1776169301562] CoreMusicLibrary::Adding element YouTube2 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:41 volumio volumio[5122]: Cannot find translation for source Mixcloud Apr 14 19:21:41 volumio volumio[5122]: Cannot find translation for source YouTube2 Apr 14 19:21:41 volumio volumio[5122]: info: Volumio Calling Home Apr 14 19:21:41 volumio volumio[5122]: info: CoreStateMachine::setRepeat null single undefined Apr 14 19:21:41 volumio volumio[5122]: info: CoreStateMachine::pushState Apr 14 19:21:41 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:41 volumio volumio[5122]: info: CoreStateMachine::setRandom false Apr 14 19:21:41 volumio volumio[5122]: info: CoreStateMachine::pushState Apr 14 19:21:41 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:41 volumio volumio[5122]: verbose: New Socket.io Connection to 10.0.1.110 from 10.0.1.104 UA: Mozilla/5.0 (Linux; Android 16; SM-S901E Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Apr 14 19:21:41 volumio volumio[5122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Apr 14 19:21:41 volumio volumio[5122]: info: MPD Permissions set Apr 14 19:21:41 volumio volumio[5122]: info: MPD Permissions set Apr 14 19:21:41 volumio volumio[5122]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:41 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:41 volumio volumio[5122]: info: CoreStateMachine::pushState Apr 14 19:21:41 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::volumioPushState Apr 14 19:21:41 volumio volumio[5122]: info: Spotify config file written Apr 14 19:21:41 volumio volumio[5122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio sudo[5323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio sudo[5323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:21:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:41 volumio go-librespot[5333]: go-librespot daemon starting... Apr 14 19:21:41 volumio sudo[5323]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:21:41 volumio go-librespot[5339]: time="2026-04-14T19:21:41+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:21:41 volumio go-librespot[5339]: time="2026-04-14T19:21:41+07:00" level=debug msg="app state loaded" Apr 14 19:21:41 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:21:41 volumio volumio[5122]: info: No need to fix Spotify hosts Apr 14 19:21:41 volumio go-librespot[5339]: time="2026-04-14T19:21:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:21:41 volumio volumio[5122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Apr 14 19:21:42 volumio volumio[5122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Apr 14 19:21:42 volumio volumio[5122]: info: Discovery: adding aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:21:42 volumio volumio[5122]: info: Discovery: Found device Volumio Apr 14 19:21:42 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:42 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:42 volumio volumio[5122]: info: Starting Shairport Sync Apr 14 19:21:42 volumio volumio[5122]: info: Starting Shairport Sync Apr 14 19:21:42 volumio volumio[5122]: info: Starting Shairport Sync Apr 14 19:21:42 volumio sudo[5352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:21:42 volumio sudo[5352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:42 volumio sudo[5356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:21:42 volumio sudo[5356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:42 volumio sudo[5355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:21:42 volumio sudo[5355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:42 volumio volumio[5122]: info: Volumio called home Apr 14 19:21:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:21:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:21:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:21:42 volumio systemd[1]: shairport-sync.service: Consumed 1.954s CPU time. Apr 14 19:21:42 volumio volumio[5122]: info: Discovery: this is already registered, aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:21:42 volumio volumio[5122]: info: Discovery: Found device Volumio Apr 14 19:21:42 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:42 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:21:42 volumio sudo[5352]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:42 volumio sudo[5356]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:42 volumio sudo[5355]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:42 volumio volumio[5122]: info: Shairport-Sync Started Apr 14 19:21:42 volumio volumio[5122]: Error adding Membership: Error: addMembership EINVAL Apr 14 19:21:42 volumio volumio[5122]: info: Shairport-Sync Started Apr 14 19:21:42 volumio volumio[5122]: info: Shairport-Sync Started Apr 14 19:21:42 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:42 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" 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]" Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" 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]" Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" 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]" Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" level=info msg="zeroconf server listening on port 45231" Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:21:42 volumio mpd[5296]: 2026-04-14T19:21:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" level=debug msg="obtained new client token: AADJ6IA+1Smb8P8okyIvlZs9zwAAS93NsUL+sggRdyMfuCM9gIsu75LtubsQAEO1aYBo+KMUxRFPON6V1cuCFw4a1/MB2ctqHAsnnZibDZXQloNySdDmvNEAv/Da3Qdn6md10hN4DdEgFQmRKSspTK2EC2zqEM9cS9PAPB4B07U1PniOr5ZLMBKmuUUzxk2r80bE6lPCN7hNBKuzyOHdtgnsBUI5itniSkYX+zqHBTDWRHBAjStaMwwp" Apr 14 19:21:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 19:21:42 volumio sudo[5268]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:42 volumio sudo[5254]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:42 volumio volumio[5122]: error: MPD error: The expression evaluated to a falsy value: Apr 14 19:21:42 volumio volumio[5122]: assert.ok(self.idling) Apr 14 19:21:42 volumio volumio[5122]: error: The expression evaluated to a falsy value: Apr 14 19:21:42 volumio volumio[5122]: assert.ok(self.idling) Apr 14 19:21:42 volumio volumio[5122]: info: MPD running with PID5296 Apr 14 19:21:42 volumio volumio[5122]: ,establishing connection Apr 14 19:21:42 volumio volumio[5122]: error: updateQueue error: null Apr 14 19:21:42 volumio volumio[5122]: error: updateQueue error: null Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:42 volumio go-librespot[5339]: time="2026-04-14T19:21:42+07:00" level=debug msg="completed challenge" Apr 14 19:21:42 volumio volumio[5122]: info: New Spotify access tokenBQDHAHULIE... Apr 14 19:21:42 volumio volumio[5122]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 14 19:21:43 volumio go-librespot[5339]: time="2026-04-14T19:21:43+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:43 volumio volumio[5122]: SPOTIFY: User informations: {"country":"GB","display_name":"Kenky Cool","email":"kenkycool97@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/42j4swbhr91mth0xx3exmu8s0"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/42j4swbhr91mth0xx3exmu8s0","id":"42j4swbhr91mth0xx3exmu8s0","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=300&width=300&ext=1778753480&hash=AT8-KOYVDV5N6LlcBEJhd_qw","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=50&width=50&ext=1778753480&hash=AT-KltT7sc5TFuHT3APbyHTf","width":64}],"product":"free","type":"user","uri":"spotify:user:42j4swbhr91mth0xx3exmu8s0"} Apr 14 19:21:43 volumio volumio[5122]: info: Spotify Successfully logged in Apr 14 19:21:43 volumio volumio[5122]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:21:43 volumio volumio[5122]: info: [1776169303239] CoreMusicLibrary::Adding element Spotify Apr 14 19:21:43 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:43 volumio volumio[5122]: Cannot find translation for source Mixcloud Apr 14 19:21:43 volumio volumio[5122]: Cannot find translation for source YouTube2 Apr 14 19:21:43 volumio volumio[5122]: Cannot find translation for source Spotify Apr 14 19:21:43 volumio go-librespot[5339]: time="2026-04-14T19:21:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:21:43 volumio go-librespot[5339]: time="2026-04-14T19:21:43+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:43 volumio go-librespot[5339]: time="2026-04-14T19:21:43+07:00" level=debug msg="completed challenge" Apr 14 19:21:43 volumio go-librespot[5339]: time="2026-04-14T19:21:43+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:44 volumio volumio[5122]: info: [yt-cast-receiver] DIAL server listening on port 8098 Apr 14 19:21:44 volumio volumio[5122]: info: Completed starting Core Plugins Apr 14 19:21:44 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:44 volumio volumio[5122]: info: ----- MyVolumio plugins startup ---- Apr 14 19:21:44 volumio volumio[5122]: info: ------------------------------------------- Apr 14 19:21:44 volumio volumio[5122]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 19:21:44 volumio go-librespot[5339]: time="2026-04-14T19:21:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:21:44 volumio go-librespot[5339]: time="2026-04-14T19:21:44+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:44 volumio go-librespot[5339]: time="2026-04-14T19:21:44+07:00" level=debug msg="completed challenge" Apr 14 19:21:44 volumio go-librespot[5339]: time="2026-04-14T19:21:44+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:44 volumio volumio[5122]: verbose: New Socket.io Connection to 10.0.1.110 from 10.0.1.104 UA: Mozilla/5.0 (Linux; Android 16; SM-S901E Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 19:21:44 volumio volumio[5122]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 14 19:21:44 volumio volumio[5122]: info: Received Get System Version Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:21:44 volumio volumio[5122]: info: Received Get System Info Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:44 volumio volumio[5122]: info: Discovery: Getting this device information Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:44 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:44 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::volumioGetQueue Apr 14 19:21:44 volumio volumio[5122]: info: CoreStateMachine::getQueue Apr 14 19:21:44 volumio volumio[5122]: info: CorePlayQueue::getQueue Apr 14 19:21:44 volumio volumio[5122]: info: Listing playlists Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 19:21:44 volumio volumio[5122]: info: Received Get System Info Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 19:21:44 volumio volumio[5122]: info: Discovery: Getting this device information Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:44 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 19:21:44 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:44 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:45 volumio volumio[5122]: info: go-librespot daemon successfully initialized Apr 14 19:21:45 volumio go-librespot[5339]: time="2026-04-14T19:21:45+07:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 19:21:45 volumio go-librespot[5339]: time="2026-04-14T19:21:45+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:45 volumio go-librespot[5339]: time="2026-04-14T19:21:45+07:00" level=debug msg="completed challenge" Apr 14 19:21:45 volumio go-librespot[5339]: time="2026-04-14T19:21:45+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:46 volumio sudo[5405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:21:46 volumio sudo[5405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:46 volumio sudo[5405]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:46 volumio sudo[5407]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:21:46 volumio sudo[5407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:46 volumio sudo[5410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 19:21:46 volumio sudo[5410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:46 volumio sudo[5407]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:46 volumio sudo[5410]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:46 volumio volumio[5122]: info: Upmpdcli Daemon Started Apr 14 19:21:46 volumio go-librespot[5339]: time="2026-04-14T19:21:46+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 19:21:46 volumio volumio[5122]: info: CoreCommandRouter::volumioPlay Apr 14 19:21:46 volumio volumio[5122]: info: CoreStateMachine::play index undefined Apr 14 19:21:46 volumio volumio[5122]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 19:21:46 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:46 volumio volumio[5122]: info: CoreStateMachine::startPlaybackTimer Apr 14 19:21:46 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:46 volumio volumio[5122]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22SAU%20L%E1%BB%9CI%20T%E1%BB%AA%20KH%C6%AF%E1%BB%9AC%20-%20PHAN%20M%E1%BA%A0NH%20QU%E1%BB%B2NH%20%7C%20OFFICIAL%20MV%20(OST%20phim%20MAI%2C%20%C4%90%E1%BA%A1o%20Di%E1%BB%85n%20Tr%E1%BA%A5n%20Th%C3%A0nh)%22%2C%22artist%22%3A%22TR%E1%BA%A4N%20TH%C3%80NH%20TOWN%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fh_1t3-6oWz4%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLDqYqZEDhm8ALmDhRBLfHct9dZa6A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D Apr 14 19:21:46 volumio go-librespot[5339]: time="2026-04-14T19:21:46+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:46 volumio go-librespot[5339]: time="2026-04-14T19:21:46+07:00" level=debug msg="completed challenge" Apr 14 19:21:47 volumio go-librespot[5339]: time="2026-04-14T19:21:47+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:47 volumio volumio[5122]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 19:21:48 volumio volumio[5122]: info: Initializing connection to go-librespot Websocket Apr 14 19:21:48 volumio go-librespot[5339]: time="2026-04-14T19:21:48+07:00" level=debug msg="new websocket client" Apr 14 19:21:48 volumio volumio[5122]: info: Connection to go-librespot Websocket established Apr 14 19:21:48 volumio go-librespot[5339]: time="2026-04-14T19:21:48+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:21:48 volumio go-librespot[5339]: time="2026-04-14T19:21:48+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:48 volumio go-librespot[5339]: time="2026-04-14T19:21:48+07:00" level=debug msg="completed challenge" Apr 14 19:21:48 volumio go-librespot[5339]: time="2026-04-14T19:21:48+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:48 volumio go-librespot[5339]: time="2026-04-14T19:21:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Apr 14 19:21:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:21:51 volumio go-librespot[5421]: go-librespot daemon starting... Apr 14 19:21:51 volumio go-librespot[5422]: time="2026-04-14T19:21:51+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:21:51 volumio go-librespot[5422]: time="2026-04-14T19:21:51+07:00" level=debug msg="app state loaded" Apr 14 19:21:51 volumio go-librespot[5422]: time="2026-04-14T19:21:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" 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]" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" 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]" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" 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]" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=info msg="zeroconf server listening on port 37283" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=debug msg="obtained new client token: AAA250qk7VqumrffK9O09Q1sVN7C2ksdY3uO4xMApnfc7whRt/CM2oOKwHGKQURr0PnkWpxydLGhkKWDnmjvhLWnq67wb8kgc2IC3FVW48nhvA6zfpgVKOI/BxgP7wSe6dnBU9CXYkAZUhNEB2SHomAVfHJTgi/rTXVEkryuWm2lgKvPiC3nxnwQRs6LaBM+vOP6SksBqFhjuY6EjWUtcIngehoGNFrMDChk2gKISBZYzwOszN9GxYc9" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=debug msg="completed challenge" Apr 14 19:21:52 volumio go-librespot[5422]: time="2026-04-14T19:21:52+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:53 volumio go-librespot[5422]: time="2026-04-14T19:21:53+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Apr 14 19:21:53 volumio go-librespot[5422]: time="2026-04-14T19:21:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:21:53 volumio volumio[5122]: info: Getting Spotify volume Apr 14 19:21:53 volumio go-librespot[5422]: time="2026-04-14T19:21:53+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:53 volumio go-librespot[5422]: time="2026-04-14T19:21:53+07:00" level=debug msg="completed challenge" Apr 14 19:21:53 volumio volumio[5122]: info: CoreCommandRouter::volumioPlay Apr 14 19:21:53 volumio volumio[5122]: info: CoreStateMachine::play index undefined Apr 14 19:21:53 volumio volumio[5122]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 19:21:53 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:53 volumio volumio[5122]: info: CoreStateMachine::startPlaybackTimer Apr 14 19:21:53 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:53 volumio volumio[5122]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22SAU%20L%E1%BB%9CI%20T%E1%BB%AA%20KH%C6%AF%E1%BB%9AC%20-%20PHAN%20M%E1%BA%A0NH%20QU%E1%BB%B2NH%20%7C%20OFFICIAL%20MV%20(OST%20phim%20MAI%2C%20%C4%90%E1%BA%A1o%20Di%E1%BB%85n%20Tr%E1%BA%A5n%20Th%C3%A0nh)%22%2C%22artist%22%3A%22TR%E1%BA%A4N%20TH%C3%80NH%20TOWN%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fh_1t3-6oWz4%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLDqYqZEDhm8ALmDhRBLfHct9dZa6A%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D Apr 14 19:21:53 volumio volumio[5122]: info: Connection to go-librespot Websocket closed Apr 14 19:21:53 volumio volumio[5122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 14 19:21:53 volumio go-librespot[5422]: time="2026-04-14T19:21:53+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:53 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:53 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:53 volumio volumio[5122]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:21:53 volumio volumio[5122]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 19:21:53 volumio volumio[5122]: SPOTIFY: VOLUMIO VOLUME 30 Apr 14 19:21:53 volumio volumio[5122]: info: Aligning Spotify Volume to Volumio Volume Apr 14 19:21:53 volumio volumio[5122]: info: CoreCommandRouter::volumioGetState Apr 14 19:21:53 volumio volumio[5122]: info: CorePlayQueue::getTrack 0 Apr 14 19:21:53 volumio volumio[5122]: info: Setting Spotify Volume from Volumio: 30 Apr 14 19:21:54 volumio go-librespot[5422]: time="2026-04-14T19:21:54+07:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Apr 14 19:21:54 volumio go-librespot[5422]: time="2026-04-14T19:21:54+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:54 volumio go-librespot[5422]: time="2026-04-14T19:21:54+07:00" level=debug msg="completed challenge" Apr 14 19:21:55 volumio go-librespot[5422]: time="2026-04-14T19:21:55+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:55 volumio go-librespot[5422]: time="2026-04-14T19:21:55+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 19:21:56 volumio go-librespot[5422]: time="2026-04-14T19:21:56+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:56 volumio go-librespot[5422]: time="2026-04-14T19:21:56+07:00" level=debug msg="completed challenge" Apr 14 19:21:56 volumio go-librespot[5422]: time="2026-04-14T19:21:56+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:57 volumio go-librespot[5422]: time="2026-04-14T19:21:57+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:21:57 volumio volumio[5122]: npm ERR! code ENOTEMPTY Apr 14 19:21:57 volumio volumio[5122]: npm ERR! syscall rename Apr 14 19:21:57 volumio volumio[5122]: npm ERR! path /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno Apr 14 19:21:57 volumio volumio[5122]: npm ERR! dest /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv Apr 14 19:21:57 volumio volumio[5122]: npm ERR! errno -39 Apr 14 19:21:57 volumio volumio[5122]: npm ERR! ENOTEMPTY: directory not empty, rename '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno' -> '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv' Apr 14 19:21:57 volumio volumio[5122]: npm ERR! A complete log of this run can be found in: /home/volumio/.npm/_logs/2026-04-14T12_21_54_698Z-debug-0.log Apr 14 19:21:57 volumio volumio[5122]: info: [youtube2] Innertube support service: Deno not installed or otherwise failed to start: Command failed: npx --no-install --yes deno --version Apr 14 19:21:57 volumio volumio[5122]: npm ERR! code ENOTEMPTY Apr 14 19:21:57 volumio volumio[5122]: npm ERR! syscall rename Apr 14 19:21:57 volumio volumio[5122]: npm ERR! path /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno Apr 14 19:21:57 volumio volumio[5122]: npm ERR! dest /home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv Apr 14 19:21:57 volumio volumio[5122]: npm ERR! errno -39 Apr 14 19:21:57 volumio volumio[5122]: npm ERR! ENOTEMPTY: directory not empty, rename '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/deno' -> '/home/volumio/.npm/_npx/05b6ef7b13673c57/node_modules/.deno-CHaaUvCv' Apr 14 19:21:57 volumio volumio[5122]: npm ERR! A complete log of this run can be found in: /home/volumio/.npm/_logs/2026-04-14T12_21_54_698Z-debug-0.log Apr 14 19:21:57 volumio volumio[5122]: info: [youtube2] Innertube support service: Start service with Node Apr 14 19:21:57 volumio volumio[5122]: SPOTIFY: SETTING SPOTIFY VOLUME 30 Apr 14 19:21:57 volumio volumio[5122]: info: Sending Spotify command with payload to local API: /player/volume Apr 14 19:21:57 volumio volumio[5122]: info: Initializing connection to go-librespot Websocket Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin bluetooth to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin multiroom to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin metavolumio to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin cd_controller to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 14 19:21:57 volumio volumio[5122]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 14 19:21:57 volumio go-librespot[5422]: time="2026-04-14T19:21:57+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 10.0.1.110:35710->34.158.1.133:80: read: connection reset by peer" Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 19:21:58 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:58 volumio volumio[5122]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:21:58 volumio volumio[5122]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 19:21:58 volumio volumio[5122]: info: MyVolumio login type: Token Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 19:21:58 volumio go-librespot[5422]: time="2026-04-14T19:21:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:58 volumio go-librespot[5422]: time="2026-04-14T19:21:58+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:58 volumio go-librespot[5422]: time="2026-04-14T19:21:58+07:00" level=debug msg="completed challenge" Apr 14 19:21:58 volumio go-librespot[5422]: time="2026-04-14T19:21:58+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:58 volumio go-librespot[5422]: time="2026-04-14T19:21:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 19:21:58 volumio volumio[5122]: info: Streaming services startup Apr 14 19:21:58 volumio volumio[5122]: info: Starting Streaming Daemon Apr 14 19:21:58 volumio sudo[5489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 19:21:58 volumio sudo[5489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:58 volumio volumio[5122]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 19:21:58 volumio sudo[5489]: pam_unix(sudo:session): session closed for user root Apr 14 19:21:58 volumio volumio[5122]: info: Preload queue cleared Apr 14 19:21:58 volumio volumio[5122]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 14 19:21:58 volumio volumio[5122]: info: CoreStateMachine::ClearQueue Apr 14 19:21:58 volumio volumio[5122]: info: CoreStateMachine::stop Apr 14 19:21:58 volumio volumio[5122]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 19:21:58 volumio volumio[5122]: info: CorePlayQueue::clearPlayQueue Apr 14 19:21:58 volumio volumio[5122]: info: CorePlayQueue::saveQueue Apr 14 19:21:58 volumio volumio[5122]: info: CoreCommandRouter::volumioPushQueue Apr 14 19:21:58 volumio volumio[5122]: info: CoreStateMachine::addQueueItems Apr 14 19:21:58 volumio volumio[5122]: info: CorePlayQueue::addQueueItems Apr 14 19:21:58 volumio volumio[5122]: info: Preload queue cleared Apr 14 19:21:58 volumio volumio[5122]: info: Adding Item to queue: youtube2/search@query=Phan%20m%E1%BA%A1nh%20qu%E1%BB%B3nh/playlist@endpoints:o=%7B%22watch%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OALAAQE%253D%22%7D%7D%7D Apr 14 19:21:58 volumio volumio[5122]: info: Exploding uri youtube2/search@query=Phan%20m%E1%BA%A1nh%20qu%E1%BB%B3nh/playlist@endpoints:o=%7B%22watch%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OALAAQE%253D%22%7D%7D%7D in service youtube2 Apr 14 19:21:58 volumio volumio[5122]: info: [youtube2-browse] explodeUri: youtube2/search@query=Phan%20m%E1%BA%A1nh%20qu%E1%BB%B3nh/playlist@endpoints:o=%7B%22watch%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22h_1t3-6oWz4%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OALAAQE%253D%22%7D%7D%7D Apr 14 19:21:58 volumio volumio[5122]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 14 19:21:58 volumio volumio[5122]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:58 volumio volumio[5122]: Error: socket hang up Apr 14 19:21:58 volumio volumio[5122]: at connResetException (node:internal/errors:720:14) Apr 14 19:21:58 volumio volumio[5122]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 19:21:58 volumio volumio[5122]: at Socket.emit (node:events:526:35) Apr 14 19:21:58 volumio volumio[5122]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 19:21:58 volumio volumio[5122]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 19:21:58 volumio volumio[5122]: code: 'ECONNRESET', Apr 14 19:21:58 volumio volumio[5122]: response: undefined Apr 14 19:21:58 volumio volumio[5122]: } Apr 14 19:21:58 volumio volumio[5122]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:59 volumio sudo[5509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 19:20' Apr 14 19:21:59 volumio sudo[5509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:21:59 volumio sudo[5509]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:00 volumio volumio-remote-updater[827]: [2026-04-14 19:22:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 19:22:00 volumio volumio-remote-updater[827]: [2026-04-14 19:22:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 19:22:00 volumio volumio5-onboarding[1406]: time=2026-04-14T19:22:00.906+07:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Apr 14 19:22:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:22:00 volumio volumio5-onboarding[1406]: time=2026-04-14T19:22:00.911+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 14 19:22:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 19:22:00 volumio systemd[1]: volumio.service: Consumed 37.952s CPU time. Apr 14 19:22:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:22:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:22:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Apr 14 19:22:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:22:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 19:22:01 volumio systemd[1]: volumio.service: Consumed 37.952s CPU time. Apr 14 19:22:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 19:22:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:22:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Apr 14 19:22:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:22:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:22:01 volumio go-librespot[5551]: go-librespot daemon starting... Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" level=debug msg="app state loaded" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" 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]" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" 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]" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" 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]" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" level=info msg="zeroconf server listening on port 43575" Apr 14 19:22:01 volumio go-librespot[5552]: time="2026-04-14T19:22:01+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:22:02 volumio go-librespot[5552]: time="2026-04-14T19:22:02+07:00" level=debug msg="obtained new client token: AABE3XYhtq7L2zAb9FaizqY42WQRDbMW4sQIYoRcBa0dJUZtS8x1IiN1FJ9f7XVW5fPI8aXiVclPxi1DMu0DC6b3QtTkcUPpY4UWE2aUb8C3Tet3JTWHuvUgjowovTl8Xk8GzxySca4oqmZbLe1cU6T8h5ZYoGZlAf9iGlbaDNv3s+BGjVsbsg1UyR5FF7bVSCGVFISP1uy/j4yJD10jgTi+FlKA6CtyBXg2fb1MtYsf5J8D8tK61A==" Apr 14 19:22:02 volumio go-librespot[5552]: time="2026-04-14T19:22:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:22:02 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:02 volumio volumio[5536]: info: ----- Volumio3 ---- Apr 14 19:22:02 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:02 volumio volumio[5536]: info: ----- System startup ---- Apr 14 19:22:02 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:02 volumio go-librespot[5552]: time="2026-04-14T19:22:02+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:02 volumio go-librespot[5552]: time="2026-04-14T19:22:02+07:00" level=debug msg="completed challenge" Apr 14 19:22:02 volumio go-librespot[5552]: time="2026-04-14T19:22:02+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:02 volumio volumio[5536]: info: MYVOLUMIO Environment detected Apr 14 19:22:02 volumio volumio[5536]: info: Plugin folders cleanup Apr 14 19:22:02 volumio volumio[5536]: info: Scanning into folder /volumio/app/plugins/ Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category audio_interface Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category miscellanea Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category music_service Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category plugins.json Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category system_controller Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category user_interface Apr 14 19:22:02 volumio volumio[5536]: info: Scanning into folder /data/plugins/ Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category music_service Apr 14 19:22:02 volumio volumio[5536]: info: Scanning category system_hardware Apr 14 19:22:02 volumio volumio[5536]: info: Plugin folders cleanup completed Apr 14 19:22:02 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:02 volumio volumio[5536]: info: ----- Core plugins startup ---- Apr 14 19:22:02 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:02 volumio volumio[5536]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 19:22:02 volumio volumio[5536]: info: Adding plugin upnp to MyMusic Plugins Apr 14 19:22:02 volumio volumio[5536]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 19:22:02 volumio volumio[5536]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 19:22:02 volumio volumio[5536]: info: Loading plugins from folder /data/plugins/ Apr 14 19:22:02 volumio volumio[5536]: info: Loading plugin "system"... Apr 14 19:22:02 volumio volumio[5536]: info: Loading plugin "appearance"... Apr 14 19:22:02 volumio go-librespot[5552]: time="2026-04-14T19:22:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=debug msg="completed challenge" Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "network"... Apr 14 19:22:03 volumio volumio[5536]: info: Refreshing Cached IP Addresses Apr 14 19:22:03 volumio sudo[5576]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:22:03 volumio sudo[5576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:03 volumio sudo[5576]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "services"... Apr 14 19:22:03 volumio sudo[5578]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:22:03 volumio sudo[5578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "volumio5onboarding"... Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "alsa_controller"... Apr 14 19:22:03 volumio sudo[5589]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 19:22:03 volumio sudo[5589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:03 volumio sudo[5578]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:03 volumio sudo[5589]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:03 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "wizard"... Apr 14 19:22:03 volumio volumio5-onboarding[1406]: time=2026-04-14T19:22:03.668+07:00 level=ERROR msg="failed to read message" component=conn/ws remoteAddr=10.0.1.104:43326 error="read tcp 10.0.1.110:7331->10.0.1.104:43326: read: connection reset by peer" Apr 14 19:22:03 volumio volumio5-onboarding[1406]: time=2026-04-14T19:22:03.668+07:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=10.0.1.104:43326 Apr 14 19:22:03 volumio volumio5-onboarding[1406]: time=2026-04-14T19:22:03.668+07:00 level=INFO msg="connection to address closed" component=conn/multi addr=10.0.1.104:43326 Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "networkfs"... Apr 14 19:22:03 volumio volumio[5536]: info: Starting Udev Watcher for removable devices Apr 14 19:22:03 volumio volumio[5536]: info: Ignoring mount for partition: boot Apr 14 19:22:03 volumio volumio[5536]: info: Ignoring mount for partition: volumio Apr 14 19:22:03 volumio volumio[5536]: info: Ignoring mount for partition: volumio_data Apr 14 19:22:03 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "volumio_command_line_client"... Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "upnp"... Apr 14 19:22:03 volumio volumio[5536]: info: [1776169323716] Starting Upmpd Daemon Apr 14 19:22:03 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "my_music"... Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "mpd"... Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=debug msg="completed challenge" Apr 14 19:22:03 volumio go-librespot[5552]: time="2026-04-14T19:22:03+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:03 volumio volumio[5536]: info: Loading plugin "upnp_browser"... Apr 14 19:22:04 volumio go-librespot[5552]: time="2026-04-14T19:22:04+07:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Apr 14 19:22:04 volumio volumio[5536]: info: Starting UPNP Browser Apr 14 19:22:04 volumio volumio[5536]: info: Loading plugin "alarm-clock"... Apr 14 19:22:04 volumio volumio[5536]: info: Loading plugin "airplay_emulation"... Apr 14 19:22:04 volumio volumio[5536]: info: Starting Shairport Sync Apr 14 19:22:04 volumio volumio[5536]: info: Loading plugin "last_100"... Apr 14 19:22:04 volumio volumio[5536]: info: Loading plugin "webradio"... Apr 14 19:22:05 volumio volumio[5536]: info: Loading plugin "i2s_dacs"... Apr 14 19:22:05 volumio go-librespot[5552]: time="2026-04-14T19:22:05+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Apr 14 19:22:05 volumio volumio[5536]: info: I2S DAC not set, start Auto-detection Apr 14 19:22:05 volumio volumio[5536]: info: Loading plugin "volumiodiscovery"... Apr 14 19:22:05 volumio volumio[5536]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:22:05 volumio volumio[5536]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:22:05 volumio node[5536]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:22:05 volumio volumio[5536]: *** WARNING *** For more information see Apr 14 19:22:05 volumio volumio[5536]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:22:05 volumio volumio[5536]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:22:05 volumio volumio[5536]: *** WARNING *** For more information see Apr 14 19:22:05 volumio node[5536]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:22:05 volumio node[5536]: *** WARNING *** For more information see Apr 14 19:22:05 volumio node[5536]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:22:05 volumio node[5536]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:22:05 volumio node[5536]: *** WARNING *** For more information see Apr 14 19:22:05 volumio volumio[5536]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 19:22:05 volumio volumio[5536]: info: Discovery: Started advertising with name: Volumio Apr 14 19:22:05 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:22:05 volumio volumio[5536]: info: Loading plugin "mixcloud"... Apr 14 19:22:05 volumio go-librespot[5552]: time="2026-04-14T19:22:05+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:05 volumio go-librespot[5552]: time="2026-04-14T19:22:05+07:00" level=debug msg="completed challenge" Apr 14 19:22:05 volumio volumio[5536]: info: Plugin soundcloud is not enabled Apr 14 19:22:05 volumio volumio[5536]: info: Loading plugin "spop"... Apr 14 19:22:05 volumio go-librespot[5552]: time="2026-04-14T19:22:05+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:05 volumio volumio-remote-updater[827]: [2026-04-14 19:22:05] [connect] Successful connection Apr 14 19:22:06 volumio volumio[5536]: info: Loading plugin "youtube2"... Apr 14 19:22:06 volumio go-librespot[5552]: time="2026-04-14T19:22:06+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:22:06 volumio volumio[5536]: info: Loading plugin "ytcr"... Apr 14 19:22:06 volumio go-librespot[5552]: time="2026-04-14T19:22:06+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:06 volumio go-librespot[5552]: time="2026-04-14T19:22:06+07:00" level=debug msg="completed challenge" Apr 14 19:22:06 volumio go-librespot[5552]: time="2026-04-14T19:22:06+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:07 volumio ntpd[1029]: PROTO: 162.159.200.123 unlink local addr 10.0.1.110 -> Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "outputs"... Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "albumart"... Apr 14 19:22:07 volumio volumio[5536]: info: Plugin example_plugin is not enabled Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "inputs"... Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "updater_comm"... Apr 14 19:22:07 volumio go-librespot[5552]: time="2026-04-14T19:22:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:22:07 volumio volumio[5536]: info: Plugin mpdemulation is not enabled Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "rest_api"... Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "websocket"... Apr 14 19:22:07 volumio volumio[5536]: info: Starting Socket.io Server version 1.7.4 Apr 14 19:22:07 volumio volumio[5536]: info: Loading plugin "storage_manager"... Apr 14 19:22:07 volumio volumio[5620]: Forking 3 albumart workers Apr 14 19:22:07 volumio go-librespot[5552]: time="2026-04-14T19:22:07+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:07 volumio go-librespot[5552]: time="2026-04-14T19:22:07+07:00" level=debug msg="completed challenge" Apr 14 19:22:07 volumio go-librespot[5552]: time="2026-04-14T19:22:07+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:07 volumio go-librespot[5552]: time="2026-04-14T19:22:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:22:07 volumio volumio[5536]: info: Loading i18n strings for locale vi Apr 14 19:22:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:22:07 volumio volumio[5536]: Updating browse sources language Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::initPlayerControls Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: Express server listening on port 3000 Apr 14 19:22:07 volumio volumio[5536]: [Metrics] WebUI: 6s 27.52ms Apr 14 19:22:07 volumio volumio[5536]: info: Setting Device type: x86 Apr 14 19:22:07 volumio volumio[5536]: info: CoreStateMachine::resetVolumioState Apr 14 19:22:07 volumio volumio[5536]: info: CoreStateMachine::getcurrentVolume Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:22:07 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:07 volumio volumio[5536]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 14 19:22:07 volumio volumio[5536]: info: Completed loading Core Plugins Apr 14 19:22:07 volumio volumio[5536]: info: Preparing to generate the ALSA configuration file Apr 14 19:22:08 volumio volumio[5536]: info: Volumio Network Manager: Network status updated: 1 Apr 14 19:22:08 volumio volumio[5536]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 14 19:22:08 volumio volumio[5536]: wlan0 Interface doesn't support scanning. Apr 14 19:22:08 volumio volumio[5536]: info: Cannot use regular scanning, forcing with ap-force Apr 14 19:22:08 volumio sudo[5665]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 14 19:22:08 volumio sudo[5665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:08 volumio sudo[5665]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:08 volumio volumio[5536]: command failed: No such device (-19) Apr 14 19:22:08 volumio volumio[5536]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 14 19:22:08 volumio volumio[5536]: command failed: No such device (-19) Apr 14 19:22:08 volumio volumio[5536]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 14 19:22:08 volumio volumio[5633]: Starting albumart workers Apr 14 19:22:08 volumio volumio[5631]: Starting albumart workers Apr 14 19:22:08 volumio volumio[5536]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Apr 14 19:22:08 volumio volumio[5632]: Starting albumart workers Apr 14 19:22:08 volumio volumio[5536]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:22:08 volumio volumio[5536]: info: CoreStateMachine::pushState Apr 14 19:22:08 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::volumioPushState Apr 14 19:22:08 volumio volumio[5536]: info: CoreStateMachine::updateTrackBlock Apr 14 19:22:08 volumio volumio[5536]: info: CorePlayQueue::getTrackBlock Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:22:08 volumio volumio[5536]: info: Reloading queue from file Apr 14 19:22:08 volumio volumio-remote-updater[827]: [2026-04-14 19:22:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776169325 101 Apr 14 19:22:08 volumio volumio[5536]: 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: 2 Apr 14 19:22:08 volumio volumio[5536]: info: Asound.conf file unchanged, so no further update is needed Apr 14 19:22:08 volumio volumio[5536]: info: Output device has changed, restarting MPD Apr 14 19:22:08 volumio volumio[5536]: info: Output device has changed, restarting Shairport Sync Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:08 volumio sudo[5678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:22:08 volumio sudo[5678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:08 volumio sudo[5676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:22:08 volumio sudo[5676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:08 volumio sudo[5676]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:08 volumio volumio[5536]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:22:08 volumio volumio[5536]: info: ___________ START PLUGINS ___________ Apr 14 19:22:08 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 19:22:08 volumio volumio[5536]: info: ControllerMpd::onStart: Initializing MPD Apr 14 19:22:08 volumio volumio[5536]: info: Creating MPD Configuration file Apr 14 19:22:08 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:22:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:22:08 volumio systemd[1]: mpd.service: Consumed 1.549s CPU time. Apr 14 19:22:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:22:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:22:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:22:08 volumio sudo[5686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 14 19:22:08 volumio sudo[5686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:22:08 volumio volumio[5536]: info: [1776169328614] CoreMusicLibrary::Adding element Máy chủ Media Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:22:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:22:08 volumio sudo[5688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:22:08 volumio volumio[5536]: info: UPNP Browser: Client initialized successfully Apr 14 19:22:08 volumio sudo[5688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:08 volumio sudo[5691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:22:08 volumio sudo[5691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:08 volumio sudo[5688]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:08 volumio sudo[5686]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:08 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:22:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:22:08 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:22:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:22:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:22:08 volumio volumio[5536]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:22:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:22:08 volumio volumio[5536]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:22:08 volumio volumio[5536]: info: [1776169328785] CoreMusicLibrary::Adding element Last_100 Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:22:08 volumio volumio[5536]: info: [1776169328793] CoreMusicLibrary::Adding element Webradio Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:22:08 volumio volumio[5536]: info: Initializing BBC Radios Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:08 volumio sudo[5709]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 19:22:08 volumio sudo[5709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 19:22:08 volumio sudo[5709]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:22:08 volumio volumio[5536]: info: [1776169328926] CoreMusicLibrary::Adding element Mixcloud Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:08 volumio volumio[5536]: Cannot find translation for source Mixcloud Apr 14 19:22:08 volumio volumio[5536]: info: Creating Spotify config file Apr 14 19:22:08 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:22:09 volumio volumio[5536]: info: [1776169329151] CoreMusicLibrary::Adding element YouTube2 Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:09 volumio volumio[5536]: Cannot find translation for source Mixcloud Apr 14 19:22:09 volumio volumio[5536]: Cannot find translation for source YouTube2 Apr 14 19:22:09 volumio volumio[5536]: info: Volumio Calling Home Apr 14 19:22:09 volumio volumio[5536]: info: CoreStateMachine::setRepeat null single undefined Apr 14 19:22:09 volumio volumio[5536]: info: CoreStateMachine::pushState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioPushState Apr 14 19:22:09 volumio volumio[5536]: info: CoreStateMachine::setRandom false Apr 14 19:22:09 volumio volumio[5536]: info: CoreStateMachine::pushState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioPushState Apr 14 19:22:09 volumio volumio[5536]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Apr 14 19:22:09 volumio volumio[5536]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Apr 14 19:22:09 volumio volumio[5536]: info: MPD Permissions set Apr 14 19:22:09 volumio volumio[5536]: info: MPD Permissions set Apr 14 19:22:09 volumio volumio[5536]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioGetState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:09 volumio volumio[5536]: info: CoreStateMachine::pushState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioPushState Apr 14 19:22:09 volumio volumio[5536]: info: Spotify config file written Apr 14 19:22:09 volumio volumio[5536]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio sudo[5750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 19:22:09 volumio sudo[5750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:22:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:22:09 volumio go-librespot[5760]: go-librespot daemon starting... Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:22:09 volumio sudo[5750]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" level=debug msg="app state loaded" Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:22:09 volumio volumio[5536]: info: No need to fix Spotify hosts Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:22:09 volumio volumio[5536]: info: Discovery: adding aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:22:09 volumio volumio[5536]: info: Discovery: Found device Volumio Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioGetState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:09 volumio volumio[5536]: info: Starting Shairport Sync Apr 14 19:22:09 volumio volumio[5536]: info: Starting Shairport Sync Apr 14 19:22:09 volumio volumio[5536]: info: Starting Shairport Sync Apr 14 19:22:09 volumio sudo[5779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:22:09 volumio sudo[5779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:09 volumio volumio[5536]: info: Discovery: this is already registered, aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:22:09 volumio volumio[5536]: info: Discovery: Found device Volumio Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioGetState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:09 volumio sudo[5781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:22:09 volumio sudo[5781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:09 volumio sudo[5783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:22:09 volumio sudo[5783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:22:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:22:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:22:09 volumio systemd[1]: shairport-sync.service: Consumed 1.972s CPU time. Apr 14 19:22:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:22:09 volumio sudo[5779]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:22:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:22:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:22:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:22:09 volumio sudo[5783]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:09 volumio sudo[5781]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:09 volumio volumio[5536]: info: Shairport-Sync Started Apr 14 19:22:09 volumio volumio[5536]: Error adding Membership: Error: addMembership EINVAL Apr 14 19:22:09 volumio volumio[5536]: info: Volumio called home Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" 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]" Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" 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]" Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" 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]" Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" level=info msg="zeroconf server listening on port 39325" Apr 14 19:22:09 volumio go-librespot[5766]: time="2026-04-14T19:22:09+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:22:09 volumio volumio[5536]: info: Shairport-Sync Started Apr 14 19:22:09 volumio volumio[5536]: info: Shairport-Sync Started Apr 14 19:22:09 volumio volumio[5536]: info: CoreCommandRouter::volumioGetState Apr 14 19:22:09 volumio volumio[5536]: info: CorePlayQueue::getTrack 0 Apr 14 19:22:10 volumio go-librespot[5766]: time="2026-04-14T19:22:10+07:00" level=debug msg="obtained new client token: AAAMPsf3QZVoW8r2HUttFdrXmNhHzs10qv118/VsDFB8vateQE8veETN8djhFBYQvtCDxJo6XXp8xUhuvd1uss3yAvBoE0k+7dWcIYu7E+rhTsuLvdGdTXaiOC2v7rQwYn9dpjnncLDiOkFqzDdw3XEu1NOS45U9zXh875AQ5boEUz6P+9L+Pca4WZZwjkvLDpGrr9dmXMNtn/PoOuieM8ZjZfrWFw8YdJoOiXaKLZz6TzB/Cj6ypg==" Apr 14 19:22:10 volumio go-librespot[5766]: time="2026-04-14T19:22:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:22:10 volumio go-librespot[5766]: time="2026-04-14T19:22:10+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:10 volumio go-librespot[5766]: time="2026-04-14T19:22:10+07:00" level=debug msg="completed challenge" Apr 14 19:22:10 volumio mpd[5737]: 2026-04-14T19:22:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 19:22:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 19:22:10 volumio sudo[5691]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:10 volumio sudo[5678]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:10 volumio volumio[5536]: info: MPD running with PID5737 Apr 14 19:22:10 volumio volumio[5536]: ,establishing connection Apr 14 19:22:10 volumio go-librespot[5766]: time="2026-04-14T19:22:10+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:10 volumio volumio[5536]: error: MPD error: The expression evaluated to a falsy value: Apr 14 19:22:10 volumio volumio[5536]: assert.ok(self.idling) Apr 14 19:22:10 volumio volumio[5536]: error: The expression evaluated to a falsy value: Apr 14 19:22:10 volumio volumio[5536]: assert.ok(self.idling) Apr 14 19:22:10 volumio volumio[5536]: error: MPD error: The expression evaluated to a falsy value: Apr 14 19:22:10 volumio volumio[5536]: assert.ok(self.idling) Apr 14 19:22:10 volumio volumio[5536]: error: The expression evaluated to a falsy value: Apr 14 19:22:10 volumio volumio[5536]: assert.ok(self.idling) Apr 14 19:22:10 volumio volumio[5536]: error: updateQueue error: null Apr 14 19:22:10 volumio volumio[5536]: info: New Spotify access tokenBQAo2c4RE5... Apr 14 19:22:10 volumio volumio[5536]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 14 19:22:10 volumio volumio[5536]: SPOTIFY: User informations: {"country":"GB","display_name":"Kenky Cool","email":"kenkycool97@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/42j4swbhr91mth0xx3exmu8s0"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/42j4swbhr91mth0xx3exmu8s0","id":"42j4swbhr91mth0xx3exmu8s0","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=300&width=300&ext=1778753480&hash=AT8-KOYVDV5N6LlcBEJhd_qw","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=50&width=50&ext=1778753480&hash=AT-KltT7sc5TFuHT3APbyHTf","width":64}],"product":"free","type":"user","uri":"spotify:user:42j4swbhr91mth0xx3exmu8s0"} Apr 14 19:22:10 volumio volumio[5536]: info: Spotify Successfully logged in Apr 14 19:22:10 volumio volumio[5536]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:22:10 volumio volumio[5536]: info: [1776169330883] CoreMusicLibrary::Adding element Spotify Apr 14 19:22:10 volumio volumio[5536]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:22:10 volumio volumio[5536]: Cannot find translation for source Mixcloud Apr 14 19:22:10 volumio volumio[5536]: Cannot find translation for source YouTube2 Apr 14 19:22:10 volumio volumio[5536]: Cannot find translation for source Spotify Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=debug msg="completed challenge" Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:11 volumio volumio[5536]: info: [yt-cast-receiver] DIAL server listening on port 8098 Apr 14 19:22:11 volumio volumio[5536]: info: Completed starting Core Plugins Apr 14 19:22:11 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:11 volumio volumio[5536]: info: ----- MyVolumio plugins startup ---- Apr 14 19:22:11 volumio volumio[5536]: info: ------------------------------------------- Apr 14 19:22:11 volumio volumio[5536]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:11 volumio go-librespot[5766]: time="2026-04-14T19:22:11+07:00" level=debug msg="completed challenge" Apr 14 19:22:12 volumio go-librespot[5766]: time="2026-04-14T19:22:12+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:12 volumio volumio[5536]: info: go-librespot daemon successfully initialized Apr 14 19:22:12 volumio go-librespot[5766]: time="2026-04-14T19:22:12+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 19:22:13 volumio go-librespot[5766]: time="2026-04-14T19:22:13+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:13 volumio go-librespot[5766]: time="2026-04-14T19:22:13+07:00" level=debug msg="completed challenge" Apr 14 19:22:13 volumio go-librespot[5766]: time="2026-04-14T19:22:13+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:13 volumio sudo[5833]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:22:13 volumio sudo[5833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:13 volumio sudo[5833]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:13 volumio sudo[5835]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:22:13 volumio sudo[5835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:13 volumio sudo[5838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 19:22:13 volumio sudo[5838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:22:13 volumio sudo[5835]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:13 volumio sudo[5838]: pam_unix(sudo:session): session closed for user root Apr 14 19:22:13 volumio volumio[5536]: info: Upmpdcli Daemon Started Apr 14 19:22:14 volumio go-librespot[5766]: time="2026-04-14T19:22:14+07:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Apr 14 19:22:14 volumio go-librespot[5766]: time="2026-04-14T19:22:14+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:22:14 volumio go-librespot[5766]: time="2026-04-14T19:22:14+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:14 volumio go-librespot[5766]: time="2026-04-14T19:22:14+07:00" level=debug msg="completed challenge" Apr 14 19:22:14 volumio go-librespot[5766]: time="2026-04-14T19:22:14+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:15 volumio volumio[5536]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 19:22:15 volumio go-librespot[5766]: time="2026-04-14T19:22:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:22:15 volumio volumio[5536]: info: Initializing connection to go-librespot Websocket Apr 14 19:22:15 volumio go-librespot[5766]: time="2026-04-14T19:22:15+07:00" level=debug msg="new websocket client" Apr 14 19:22:15 volumio volumio[5536]: info: Connection to go-librespot Websocket established Apr 14 19:22:15 volumio go-librespot[5766]: time="2026-04-14T19:22:15+07:00" level=debug msg="completed keyexchange" Apr 14 19:22:15 volumio go-librespot[5766]: time="2026-04-14T19:22:15+07:00" level=debug msg="completed challenge" Apr 14 19:22:15 volumio go-librespot[5766]: time="2026-04-14T19:22:15+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:15 volumio go-librespot[5766]: time="2026-04-14T19:22:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:22:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:22:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:22:15 volumio volumio[5536]: info: Connection to go-librespot Websocket closed Apr 14 19:22:18 volumio volumio[5536]: info: Getting Spotify volume Apr 14 19:22:18 volumio volumio[5536]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:22:18 volumio volumio[5536]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 19:22:18 volumio volumio[5536]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 19:22:18 volumio volumio[5536]: errno: -111, Apr 14 19:22:18 volumio volumio[5536]: code: 'ECONNREFUSED', Apr 14 19:22:18 volumio volumio[5536]: syscall: 'connect', Apr 14 19:22:18 volumio volumio[5536]: address: '127.0.0.1', Apr 14 19:22:18 volumio volumio[5536]: port: 9879, Apr 14 19:22:18 volumio volumio[5536]: response: undefined Apr 14 19:22:18 volumio volumio[5536]: } Apr 14 19:22:18 volumio volumio[5536]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:22:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Apr 14 19:22:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:22:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:22:18 volumio go-librespot[5861]: go-librespot daemon starting... Apr 14 19:22:18 volumio go-librespot[5862]: time="2026-04-14T19:22:18+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:22:18 volumio go-librespot[5862]: time="2026-04-14T19:22:18+07:00" level=debug msg="app state loaded" Apr 14 19:22:18 volumio go-librespot[5862]: time="2026-04-14T19:22:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:22:18 volumio sudo[5872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 19:21' Apr 14 19:22:18 volumio sudo[5872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"