-- Logs begin at Sat 2025-07-19 08:00:48 CEST, end at Sat 2025-07-19 09:38:01 CEST. -- Jul 19 09:37:01 motivoo wpa_supplicant[935]: wlan0: Trying to associate with SSID 'devgianlu' Jul 19 09:37:01 motivoo kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jul 19 09:37:01 motivoo kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jul 19 09:37:01 motivoo kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jul 19 09:37:01 motivoo kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jul 19 09:37:01 motivoo kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jul 19 09:37:01 motivoo kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: carrier acquired Jul 19 09:37:01 motivoo wpa_supplicant[935]: wlan0: Associated with a2:8f:a4:28:07:52 Jul 19 09:37:01 motivoo wpa_supplicant[935]: wlan0: CTRL-EVENT-CONNECTED - Connection to a2:8f:a4:28:07:52 completed [id=0 id_str=] Jul 19 09:37:01 motivoo wpa_supplicant[935]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 19 09:37:01 motivoo wpa_supplicant[935]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=IT Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: IAID 67:3f:27:6f Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: carrier lost Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: carrier acquired Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: IAID 67:3f:27:6f Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: soliciting a DHCP lease Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: probing address 10.178.251.55/24 Jul 19 09:37:01 motivoo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 19 09:37:01 motivoo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13616. Jul 19 09:37:01 motivoo systemd[1]: Stopped go-librespot Daemon. Jul 19 09:37:01 motivoo systemd[1]: Started go-librespot Daemon. Jul 19 09:37:01 motivoo dhcpcd[947]: wlan0: soliciting an IPv6 router Jul 19 09:37:01 motivoo go-librespot[10237]: go-librespot daemon starting... Jul 19 09:37:01 motivoo go-librespot[10237]: time="2025-07-19T09:37:01+02:00" level=info msg="running go-librespot 0.2.0" Jul 19 09:37:01 motivoo go-librespot[10237]: time="2025-07-19T09:37:01+02:00" level=debug msg="app state loaded" Jul 19 09:37:01 motivoo go-librespot[10237]: time="2025-07-19T09:37:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 19 09:37:01 motivoo go-librespot[10237]: time="2025-07-19T09:37:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 19 09:37:01 motivoo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 19 09:37:01 motivoo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 19 09:37:02 motivoo volumio[1035]: info: Initializing connection to go-librespot Websocket Jul 19 09:37:02 motivoo volumio[1035]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 19 09:37:04 motivoo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 19 09:37:04 motivoo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13617. Jul 19 09:37:04 motivoo systemd[1]: Stopped go-librespot Daemon. Jul 19 09:37:04 motivoo systemd[1]: Started go-librespot Daemon. Jul 19 09:37:04 motivoo go-librespot[10244]: go-librespot daemon starting... Jul 19 09:37:04 motivoo go-librespot[10244]: time="2025-07-19T09:37:04+02:00" level=info msg="running go-librespot 0.2.0" Jul 19 09:37:04 motivoo go-librespot[10244]: time="2025-07-19T09:37:04+02:00" level=debug msg="app state loaded" Jul 19 09:37:04 motivoo go-librespot[10244]: time="2025-07-19T09:37:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 19 09:37:04 motivoo go-librespot[10244]: time="2025-07-19T09:37:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 19 09:37:04 motivoo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 19 09:37:04 motivoo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 19 09:37:05 motivoo volumio[1035]: info: Initializing connection to go-librespot Websocket Jul 19 09:37:05 motivoo volumio[1035]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 19 09:37:06 motivoo dhcpcd[947]: wlan0: leased 10.178.251.55 for 3599 seconds Jul 19 09:37:06 motivoo avahi-daemon[719]: Joining mDNS multicast group on interface wlan0.IPv4 with address 10.178.251.55. Jul 19 09:37:06 motivoo avahi-daemon[719]: New relevant interface wlan0.IPv4 for mDNS. Jul 19 09:37:06 motivoo avahi-daemon[719]: Registering new address record for 10.178.251.55 on wlan0.IPv4. Jul 19 09:37:06 motivoo dhcpcd[947]: wlan0: adding route to 10.178.251.0/24 Jul 19 09:37:06 motivoo dhcpcd[947]: wlan0: adding default route via 10.178.251.10 Jul 19 09:37:07 motivoo ntpd[825]: Listen normally on 6 wlan0 10.178.251.55:123 Jul 19 09:37:07 motivoo ntpd[825]: new interface(s) found: waking up resolver Jul 19 09:37:07 motivoo ntpd[825]: Soliciting pool server 89.46.74.148 Jul 19 09:37:08 motivoo systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 19 09:37:08 motivoo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13618. Jul 19 09:37:08 motivoo systemd[1]: Stopped go-librespot Daemon. Jul 19 09:37:08 motivoo systemd[1]: Started go-librespot Daemon. Jul 19 09:37:08 motivoo go-librespot[10290]: go-librespot daemon starting... Jul 19 09:37:08 motivoo go-librespot[10290]: time="2025-07-19T09:37:08+02:00" level=info msg="running go-librespot 0.2.0" Jul 19 09:37:08 motivoo go-librespot[10290]: time="2025-07-19T09:37:08+02:00" level=debug msg="app state loaded" Jul 19 09:37:08 motivoo go-librespot[10290]: time="2025-07-19T09:37:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 19 09:37:08 motivoo volumio[1035]: info: Initializing connection to go-librespot Websocket Jul 19 09:37:08 motivoo go-librespot[10290]: time="2025-07-19T09:37:08+02:00" level=debug msg="new websocket client" Jul 19 09:37:08 motivoo volumio[1035]: info: Connection to go-librespot Websocket established Jul 19 09:37:08 motivoo volumio[1035]: info: Discovery: adding 17f9d5cc-7523-42b4-b5af-3eaee32fdb03 Jul 19 09:37:08 motivoo volumio[1035]: info: Discovery: Found device Motivoo Jul 19 09:37:08 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:09 motivoo ntpd[825]: 151.22.209.90 local addr 10.178.251.55 -> Jul 19 09:37:09 motivoo ntpd[825]: Soliciting pool server 185.157.229.254 Jul 19 09:37:10 motivoo go-librespot[10290]: time="2025-07-19T09:37:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 19 09:37:10 motivoo go-librespot[10290]: time="2025-07-19T09:37:10+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jul 19 09:37:10 motivoo go-librespot[10290]: time="2025-07-19T09:37:10+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jul 19 09:37:10 motivoo go-librespot[10290]: time="2025-07-19T09:37:10+02:00" level=info msg="zeroconf server listening on port 36687" Jul 19 09:37:10 motivoo ntpd[825]: 185.221.173.236 local addr 10.178.251.55 -> Jul 19 09:37:10 motivoo ntpd[825]: Soliciting pool server 185.19.184.35 Jul 19 09:37:11 motivoo volumio[1035]: info: Getting Spotify volume Jul 19 09:37:11 motivoo volumio[1035]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jul 19 09:37:11 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:11 motivoo volumio[1035]: SPOTIFY: RECEIVED VOLUMIO VOLUME 0 Jul 19 09:37:13 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 19 09:37:13 motivoo volumio[1035]: info: Received Get System Info Jul 19 09:37:13 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 19 09:37:13 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 19 09:37:13 motivoo volumio[1035]: info: Discovery: Getting this device information Jul 19 09:37:13 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:13 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 19 09:37:14 motivoo go-librespot[10290]: time="2025-07-19T09:37:14+02:00" level=debug msg="obtained new client token: AAC4DyRcfd67rUVAH424NMjbXHwKaKhwc33/5elDENnYEwagSwvQ4bcnH6KksbaTx6Y2K6BHOB7pAu3rU49gYjVuX22hlXSevWeUe0NI/1OWB5b3MK6NXV1iFQx/mrxKvCKQPTjqtBkwTd/SOQXDY9D21s3t59nYQXWyuNQ/zOHriwtxDO15MdKwPbn6q893TdxMIXg8OLLHKARe0yd3InQt8v+ukPcjsjRHLmMfjrqYMRa3jmgmBGz+04Y=" Jul 19 09:37:15 motivoo volumio[1035]: info: Reporting MCU Network Status: 2 Jul 19 09:37:15 motivoo volumio[1035]: info: Volumio Network Manager: Network status updated: 2 Jul 19 09:37:17 motivoo go-librespot[10290]: time="2025-07-19T09:37:17+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jul 19 09:37:19 motivoo ntpd[825]: receive: Unexpected origin timestamp 0xec25c9ad.7ac5ba50 does not match aorg 0xec25c9af.7ac5164a from server@185.19.184.35 xmt 0xec25c9af.c4bf6da7 Jul 19 09:37:19 motivoo go-librespot[10290]: time="2025-07-19T09:37:19+02:00" level=debug msg="completed keyexchange" Jul 19 09:37:19 motivoo go-librespot[10290]: time="2025-07-19T09:37:19+02:00" level=debug msg="completed challenge" Jul 19 09:37:23 motivoo ntpd[825]: receive: Unexpected origin timestamp 0xec25c9af.7ac5164a does not match aorg 0xec25c9b3.7ac4e749 from server@185.19.184.35 xmt 0xec25c9b3.896b540e Jul 19 09:37:23 motivoo go-librespot[10290]: time="2025-07-19T09:37:23+02:00" level=info msg="authenticated AP as 11145089019" Jul 19 09:37:25 motivoo ntpd[825]: receive: Unexpected origin timestamp 0xec25c9b0.7ac461a7 does not match aorg 0xec25c9b2.7ac4fe3d from server@185.157.229.254 xmt 0xec25c9b5.0e08277a Jul 19 09:37:26 motivoo ntpd[825]: receive: Unexpected origin timestamp 0xec25c9b1.7ac461fe does not match aorg 0xec25c9b3.7ac4e749 from server@185.19.184.35 xmt 0xec25c9b6.b570b3ee Jul 19 09:37:28 motivoo volumio[1035]: verbose: New Socket.io Connection to 10.178.251.55 from 10.178.251.79 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetVisibleSources Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 19 09:37:28 motivoo volumio[1035]: info: Received Get System Info Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 19 09:37:28 motivoo volumio[1035]: info: Discovery: Getting this device information Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:28 motivoo volumio[1035]: info: Listing playlists Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 19 09:37:28 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jul 19 09:37:28 motivoo sudo[10388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jul 19 09:37:28 motivoo sudo[10388]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:28 motivoo sudo[10388]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:28 motivoo sudo[10393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jul 19 09:37:28 motivoo sudo[10393]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:28 motivoo sudo[10393]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:28 motivoo sudo[10402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jul 19 09:37:28 motivoo sudo[10402]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:28 motivoo sudo[10402]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:28 motivoo sudo[10408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jul 19 09:37:28 motivoo sudo[10408]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:29 motivoo sudo[10408]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:29 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Jul 19 09:37:29 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Jul 19 09:37:29 motivoo sudo[10413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 19 09:37:29 motivoo sudo[10413]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:29 motivoo sudo[10416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 19 09:37:29 motivoo sudo[10413]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:29 motivoo sudo[10416]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:29 motivoo sudo[10416]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:29 motivoo sudo[10420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 19 09:37:29 motivoo sudo[10420]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 19 09:37:30 motivoo volumio[1035]: info: Received Get System Info Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 19 09:37:30 motivoo volumio[1035]: info: Discovery: Getting this device information Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::volumioGetState Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 19 09:37:30 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jul 19 09:37:32 motivoo sudo[10420]: pam_unix(sudo:session): session closed for user root Jul 19 09:37:39 motivoo volumio[1035]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jul 19 09:37:55 motivoo ntpd[825]: Soliciting pool server 188.213.165.209 Jul 19 09:38:00 motivoo ntpd[825]: Soliciting pool server 81.56.230.156 Jul 19 09:38:00 motivoo go-librespot[10290]: time="2025-07-19T09:38:00+02:00" level=info msg="authenticated Login5 as 11145089019" Jul 19 09:38:00 motivoo go-librespot[10290]: time="2025-07-19T09:38:00+02:00" level=debug msg="initializing zeroconf session, username: 11145089019" Jul 19 09:38:00 motivoo ntpd[825]: Soliciting pool server 162.159.200.123 Jul 19 09:38:00 motivoo volumio[1035]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 19 09:38:00 motivoo volumio[1035]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Jul 19 09:38:00 motivoo volumio[1035]: code: 'auth/network-request-failed', Jul 19 09:38:00 motivoo volumio[1035]: a: null Jul 19 09:38:00 motivoo volumio[1035]: } Jul 19 09:38:00 motivoo volumio[1035]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 19 09:38:01 motivoo sudo[10477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-19 09:37 Jul 19 09:38:01 motivoo sudo[10477]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="motivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 07:55:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Motivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Motivo" VOLUMIO_HASH="47546d7431a0ac02b252b63cc0168466"