-- Logs begin at Tue 2024-06-11 04:28:51 EDT, end at Tue 2024-06-11 04:33:46 EDT. -- Jun 11 04:32:03 volumio go-librespot[1724]: time="2024-06-11T04:32:03-04:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 11 04:32:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 11 04:32:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 11 04:32:04 volumio volumio[1375]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.703&uuid=79702e64a4ce75bcb0f5916e49e6488e" http://updates.volumio.org/downloader-v1/track-device Jun 11 04:32:04 volumio volumio[1375]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 11 04:32:04 volumio volumio[1375]: Dload Upload Total Spent Left Speed Jun 11 04:32:04 volumio volumio[1375]: [1.0K blob data] Jun 11 04:32:04 volumio volumio[1375]: retrying in 5 seconds, trial 1 Jun 11 04:32:04 volumio volumio[1375]: info: Volumio Calling Home Jun 11 04:32:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 11 04:32:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jun 11 04:32:06 volumio systemd[1]: Stopped go-librespot Daemon. Jun 11 04:32:06 volumio systemd[1]: Started go-librespot Daemon. Jun 11 04:32:06 volumio go-librespot[1776]: Librespot-go daemon starting... Jun 11 04:32:06 volumio go-librespot[1776]: time="2024-06-11T04:32:06-04:00" level=info msg="generated new device id: 6cc057cf6dce45b8a748a2398739d09898c90b5d" Jun 11 04:32:06 volumio go-librespot[1776]: time="2024-06-11T04:32:06-04:00" level=debug msg="stored credentials found for ddervieux" Jun 11 04:32:07 volumio ntpd[652]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 11 04:32:17 volumio go-librespot[1776]: time="2024-06-11T04:32:17-04:00" level=debug msg="new websocket client" Jun 11 04:32:17 volumio volumio[1375]: info: Connection to go-librespot Websocket established Jun 11 04:32:17 volumio volumio[1375]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 11 04:32:18 volumio go-librespot[1776]: time="2024-06-11T04:32:18-04:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 11 04:32:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 11 04:32:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 11 04:32:18 volumio volumio[1375]: info: Connection to go-librespot Websocket closed Jun 11 04:32:20 volumio volumio[1375]: info: Getting Spotify volume Jun 11 04:32:20 volumio volumio[1375]: (node:1375) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 11 04:32:20 volumio volumio[1375]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jun 11 04:32:20 volumio volumio[1375]: (Use `node --trace-warnings ...` to show where the warning was created) Jun 11 04:32:20 volumio volumio[1375]: (node:1375) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Jun 11 04:32:20 volumio volumio[1375]: (node:1375) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Jun 11 04:32:21 volumio volumio[1375]: info: Initializing connection to go-librespot Websocket Jun 11 04:32:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 11 04:32:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jun 11 04:32:21 volumio systemd[1]: Stopped go-librespot Daemon. Jun 11 04:32:22 volumio systemd[1]: Started go-librespot Daemon. Jun 11 04:32:22 volumio go-librespot[1785]: Librespot-go daemon starting... Jun 11 04:32:22 volumio go-librespot[1785]: time="2024-06-11T04:32:22-04:00" level=info msg="generated new device id: ed9d05d4d5905bc7c56a18250310f407af4fc5bd" Jun 11 04:32:22 volumio go-librespot[1785]: time="2024-06-11T04:32:22-04:00" level=debug msg="stored credentials found for ddervieux" Jun 11 04:32:26 volumio volumio[1375]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.703&uuid=79702e64a4ce75bcb0f5916e49e6488e" http://updates.volumio.org/downloader-v1/track-device Jun 11 04:32:26 volumio volumio[1375]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 11 04:32:26 volumio volumio[1375]: Dload Upload Total Spent Left Speed Jun 11 04:32:26 volumio volumio[1375]: [1.0K blob data] Jun 11 04:32:26 volumio volumio[1375]: retrying in 5 seconds, trial 2 Jun 11 04:32:26 volumio volumio[1375]: info: Volumio Calling Home Jun 11 04:32:30 volumio ntpd[652]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 11 04:32:34 volumio go-librespot[1785]: time="2024-06-11T04:32:34-04:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 11 04:32:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 11 04:32:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 11 04:32:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 11 04:32:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jun 11 04:32:37 volumio systemd[1]: Stopped go-librespot Daemon. Jun 11 04:32:37 volumio systemd[1]: Started go-librespot Daemon. Jun 11 04:32:37 volumio go-librespot[1797]: Librespot-go daemon starting... Jun 11 04:32:37 volumio go-librespot[1797]: time="2024-06-11T04:32:37-04:00" level=info msg="generated new device id: 96336b542a211e048e407e3bcb7d065147ab562b" Jun 11 04:32:37 volumio go-librespot[1797]: time="2024-06-11T04:32:37-04:00" level=debug msg="stored credentials found for ddervieux" Jun 11 04:32:42 volumio ntpd[652]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 11 04:32:49 volumio go-librespot[1797]: time="2024-06-11T04:32:49-04:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Jun 11 04:32:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 11 04:32:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 11 04:32:51 volumio volumio[1375]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 11 04:32:51 volumio volumio[1375]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 11 04:32:51 volumio volumio[1375]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jun 11 04:32:51 volumio volumio[1375]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 11 04:32:51 volumio volumio[1375]: info: CoreCommandRouter::volumioGetState Jun 11 04:32:51 volumio volumio[1375]: info: CorePlayQueue::getTrack 0 Jun 11 04:32:51 volumio volumio[1375]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 11 04:32:51 volumio volumio[1375]: SPOTIFY: SPOTIFY VOLUME undefined Jun 11 04:32:51 volumio volumio[1375]: SPOTIFY: VOLUMIO VOLUME 100 Jun 11 04:32:51 volumio volumio[1375]: info: Aligning Spotify Volume to Volumio Volume Jun 11 04:32:51 volumio volumio[1375]: info: CoreCommandRouter::volumioGetState Jun 11 04:32:51 volumio volumio[1375]: info: CorePlayQueue::getTrack 0 Jun 11 04:32:51 volumio volumio[1375]: info: Setting Spotify Volume from Volumio: 100 Jun 11 04:32:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 11 04:32:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jun 11 04:32:52 volumio systemd[1]: Stopped go-librespot Daemon. Jun 11 04:32:52 volumio systemd[1]: Started go-librespot Daemon. Jun 11 04:32:52 volumio go-librespot[1804]: Librespot-go daemon starting... Jun 11 04:32:52 volumio go-librespot[1804]: time="2024-06-11T04:32:52-04:00" level=info msg="generated new device id: 602aefb0235054e0ece0b018f8fff19c2fd3da14" Jun 11 04:32:52 volumio go-librespot[1804]: time="2024-06-11T04:32:52-04:00" level=debug msg="stored credentials found for ddervieux" Jun 11 04:32:53 volumio volumio[1375]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jun 11 04:32:53 volumio volumio[1375]: info: Sending Spotify command with payload to local API: /player/volume Jun 11 04:32:54 volumio ntpd[652]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 11 04:32:54 volumio volumio[1375]: info: Initializing connection to go-librespot Websocket Jun 11 04:32:54 volumio go-librespot[1804]: time="2024-06-11T04:32:54-04:00" level=debug msg="new websocket client" Jun 11 04:32:54 volumio volumio[1375]: info: Connection to go-librespot Websocket established Jun 11 04:32:54 volumio ntpd[652]: Soliciting pool server 199.182.221.110 Jun 11 04:32:57 volumio volumio[1375]: info: Getting Spotify volume Jun 11 04:32:57 volumio volumio[1375]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 11 04:32:57 volumio volumio[1375]: info: CoreCommandRouter::volumioGetState Jun 11 04:32:57 volumio volumio[1375]: info: CorePlayQueue::getTrack 0 Jun 11 04:32:57 volumio volumio[1375]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 11 04:33:22 volumio go-librespot[1804]: time="2024-06-11T04:33:22-04:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp 35.186.224.24:443: i/o timeout" Jun 11 04:33:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 11 04:33:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 11 04:33:22 volumio volumio[1375]: (node:1375) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 11 04:33:22 volumio volumio[1375]: at connResetException (internal/errors.js:607:14) Jun 11 04:33:22 volumio volumio[1375]: at Socket.socketOnEnd (_http_client.js:493:23) Jun 11 04:33:22 volumio volumio[1375]: at Socket.emit (events.js:327:22) Jun 11 04:33:22 volumio volumio[1375]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 11 04:33:22 volumio volumio[1375]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 11 04:33:22 volumio volumio[1375]: (node:1375) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3) Jun 11 04:33:22 volumio volumio[1375]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jun 11 04:33:22 volumio volumio[1375]: info: Connection to go-librespot Websocket closed Jun 11 04:33:25 volumio volumio[1375]: info: Initializing connection to go-librespot Websocket Jun 11 04:33:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jun 11 04:33:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jun 11 04:33:25 volumio systemd[1]: Stopped go-librespot Daemon. Jun 11 04:33:25 volumio systemd[1]: Started go-librespot Daemon. Jun 11 04:33:25 volumio go-librespot[1852]: Librespot-go daemon starting... Jun 11 04:33:25 volumio go-librespot[1852]: time="2024-06-11T04:33:25-04:00" level=info msg="generated new device id: 6fd3b178c41f777c0c480486bdf17fb62424138f" Jun 11 04:33:25 volumio go-librespot[1852]: time="2024-06-11T04:33:25-04:00" level=debug msg="stored credentials found for ddervieux" Jun 11 04:33:32 volumio ntpd[652]: Soliciting pool server 206.108.0.131 Jun 11 04:33:33 volumio volumio[1375]: info: Connection to go-librespot Websocket established Jun 11 04:33:33 volumio go-librespot[1852]: time="2024-06-11T04:33:33-04:00" level=debug msg="new websocket client" Jun 11 04:33:33 volumio ntpd[652]: Soliciting pool server 192.99.168.180 Jun 11 04:33:33 volumio ntpd[652]: Soliciting pool server 216.58.108.188 Jun 11 04:33:33 volumio ntpd[652]: Soliciting pool server 192.95.27.155 Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 11 04:33:33 volumio volumio[1375]: info: Adding plugin bluetooth to MyMusic Plugins Jun 11 04:33:33 volumio volumio[1375]: info: Adding plugin multiroom to MyMusic Plugins Jun 11 04:33:33 volumio volumio[1375]: info: Adding plugin metavolumio to MyMusic Plugins Jun 11 04:33:33 volumio volumio[1375]: info: Adding plugin cd_controller to MyMusic Plugins Jun 11 04:33:33 volumio volumio[1375]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 11 04:33:33 volumio volumio[1375]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 11 04:33:33 volumio volumio[1375]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 11 04:33:34 volumio ntpd[652]: Soliciting pool server 206.108.0.133 Jun 11 04:33:34 volumio ntpd[652]: Soliciting pool server 206.108.0.133 Jun 11 04:33:34 volumio ntpd[652]: Soliciting pool server 162.159.200.1 Jun 11 04:33:34 volumio go-librespot[1852]: time="2024-06-11T04:33:34-04:00" level=debug msg="obtained new client token: AAAY2825ElF0gxbf5CQEmY5fbvi34kMof3bgG5VML06CHIYvpLyDYaC2OpY6GuwgkRD+Wzn1gl/fZAfPtqgTzMZX0yWiFabxM3qC0XC+xY6P3YGz0JqFk3jEtS0GYiagpCPdcs4exqeHm1K0Ukx6nnJBVOKTj3rbrZvlhvcwTWL2NPZ6PrTYLQ/Fwab3avgvd1a+EPzkOMVtDv3Boaoyb2zCNOBRE6mRp6e1X+Ms+NiKnIwMvIgiRDggTCwBisZu" Jun 11 04:33:34 volumio go-librespot[1852]: time="2024-06-11T04:33:34-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: carrier lost Jun 11 04:33:35 volumio kernel: wlan0: disassociated from b0:a7:b9:eb:5e:f6 (Reason: 1=UNSPECIFIED) Jun 11 04:33:35 volumio avahi-daemon[538]: Withdrawing address record for 192.168.68.64 on wlan0. Jun 11 04:33:35 volumio avahi-daemon[538]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.64. Jun 11 04:33:35 volumio avahi-daemon[538]: Interface wlan0.IPv4 no longer relevant for mDNS. Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b0:a7:b9:eb:5e:f6 reason=1 Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: deleting route to 192.168.68.0/22 Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: deleting default route via 192.168.68.1 Jun 11 04:33:35 volumio ntpd[652]: Soliciting pool server 216.232.132.102 Jun 11 04:33:35 volumio ntpd[652]: Soliciting pool server 131.153.171.250 Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: SME: Trying to authenticate with b0:a7:b9:eb:5e:fa (SSID='maison1' freq=2422 MHz) Jun 11 04:33:35 volumio kernel: wlan0: authenticate with b0:a7:b9:eb:5e:fa Jun 11 04:33:35 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Jun 11 04:33:35 volumio kernel: wlan0: send auth to b0:a7:b9:eb:5e:fa (try 1/3) Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: Trying to associate with b0:a7:b9:eb:5e:fa (SSID='maison1' freq=2422 MHz) Jun 11 04:33:35 volumio kernel: wlan0: authenticated Jun 11 04:33:35 volumio kernel: wlan0: associate with b0:a7:b9:eb:5e:fa (try 1/3) Jun 11 04:33:35 volumio kernel: wlan0: RX AssocResp from b0:a7:b9:eb:5e:fa (capab=0x1431 status=0 aid=2) Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: carrier acquired Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: Associated with b0:a7:b9:eb:5e:fa Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 11 04:33:35 volumio kernel: wlan0: associated Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: WPA: Key negotiation completed with b0:a7:b9:eb:5e:fa [PTK=CCMP GTK=CCMP] Jun 11 04:33:35 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-CONNECTED - Connection to b0:a7:b9:eb:5e:fa completed [id=0 id_str=] Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: IAID 06:32:3a:4d Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: carrier lost Jun 11 04:33:35 volumio kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b0:a7:b9:eb:5e:fa Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: carrier acquired Jun 11 04:33:35 volumio dhcpcd[799]: wlan0: IAID 06:32:3a:4d Jun 11 04:33:36 volumio dhcpcd[799]: wlan0: soliciting an IPv6 router Jun 11 04:33:36 volumio dhcpcd[799]: wlan0: rebinding lease of 192.168.68.64 Jun 11 04:33:36 volumio dhcpcd[799]: wlan0: probing address 192.168.68.64/22 Jun 11 04:33:36 volumio kernel: hwmon hwmon1: Undervoltage detected! Jun 11 04:33:36 volumio volumio[1375]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 11 04:33:36 volumio volumio[1375]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 11 04:33:36 volumio volumio[1375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 04:33:36 volumio volumio[1375]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 04:33:36 volumio volumio[1375]: info: Starting MyVolumio Remote Streaming Endpoints Jun 11 04:33:37 volumio volumio[1375]: info: MyVolumio login type: Token Jun 11 04:33:37 volumio volumio[1375]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 11 04:33:37 volumio volumio[1375]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 11 04:33:37 volumio ntpd[652]: Deleting interface #4 wlan0, 192.168.68.64#123, interface stats: received=9, sent=10, dropped=4, active_time=186 secs Jun 11 04:33:37 volumio ntpd[652]: 206.108.0.133 local addr 192.168.68.64 -> Jun 11 04:33:37 volumio ntpd[652]: 162.159.200.1 local addr 192.168.68.64 -> Jun 11 04:33:37 volumio ntpd[652]: 192.95.27.155 local addr 192.168.68.64 -> Jun 11 04:33:37 volumio ntpd[652]: 216.58.108.188 local addr 192.168.68.64 -> Jun 11 04:33:37 volumio ntpd[652]: 192.99.168.180 local addr 192.168.68.64 -> Jun 11 04:33:39 volumio dhcpcd[799]: wlan0: carrier lost Jun 11 04:33:39 volumio kernel: wlan0: disassociated from b0:a7:b9:eb:5e:fa (Reason: 1=UNSPECIFIED) Jun 11 04:33:39 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b0:a7:b9:eb:5e:fa reason=1 Jun 11 04:33:39 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jun 11 04:33:39 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: SME: Trying to authenticate with b0:a7:b9:eb:5e:f6 (SSID='maison1' freq=2422 MHz) Jun 11 04:33:40 volumio kernel: wlan0: authenticate with b0:a7:b9:eb:5e:f6 Jun 11 04:33:40 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Jun 11 04:33:40 volumio kernel: wlan0: send auth to b0:a7:b9:eb:5e:f6 (try 1/3) Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: Trying to associate with b0:a7:b9:eb:5e:f6 (SSID='maison1' freq=2422 MHz) Jun 11 04:33:40 volumio kernel: wlan0: authenticated Jun 11 04:33:40 volumio kernel: wlan0: associate with b0:a7:b9:eb:5e:f6 (try 1/3) Jun 11 04:33:40 volumio kernel: wlan0: associate with b0:a7:b9:eb:5e:f6 (try 2/3) Jun 11 04:33:40 volumio kernel: wlan0: associate with b0:a7:b9:eb:5e:f6 (try 3/3) Jun 11 04:33:40 volumio kernel: wlan0: RX AssocResp from b0:a7:b9:eb:5e:f6 (capab=0x1431 status=0 aid=4) Jun 11 04:33:40 volumio dhcpcd[799]: wlan0: carrier acquired Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: Associated with b0:a7:b9:eb:5e:f6 Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Jun 11 04:33:40 volumio kernel: wlan0: associated Jun 11 04:33:40 volumio kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by b0:a7:b9:eb:5e:f6 Jun 11 04:33:40 volumio dhcpcd[799]: wlan0: IAID 06:32:3a:4d Jun 11 04:33:40 volumio dhcpcd[799]: wlan0: carrier lost Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: WPA: Key negotiation completed with b0:a7:b9:eb:5e:f6 [PTK=CCMP GTK=CCMP] Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: CTRL-EVENT-CONNECTED - Connection to b0:a7:b9:eb:5e:f6 completed [id=0 id_str=] Jun 11 04:33:40 volumio dhcpcd[799]: wlan0: carrier acquired Jun 11 04:33:40 volumio wpa_supplicant[786]: wlan0: WPA: Key negotiation completed with b0:a7:b9:eb:5e:f6 [PTK=CCMP GTK=CCMP] Jun 11 04:33:40 volumio dhcpcd[799]: wlan0: IAID 06:32:3a:4d Jun 11 04:33:40 volumio volumio[1375]: info: Starting Streaming Service Transparent Proxy Jun 11 04:33:40 volumio volumio[1375]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 11 04:33:40 volumio volumio[1375]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 11 04:33:40 volumio volumio[1375]: info: Streaming services startup Jun 11 04:33:40 volumio volumio[1375]: info: Starting Streaming Daemon Jun 11 04:33:40 volumio dhcpcd[799]: wlan0: soliciting an IPv6 router Jun 11 04:33:41 volumio sudo[1943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 11 04:33:41 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 04:33:41 volumio volumio[1375]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 11 04:33:41 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root Jun 11 04:33:41 volumio dhcpcd[799]: wlan0: rebinding lease of 192.168.68.64 Jun 11 04:33:41 volumio dhcpcd[799]: wlan0: probing address 192.168.68.64/22 Jun 11 04:33:41 volumio volumio[1375]: info: Getting Spotify volume Jun 11 04:33:41 volumio volumio[1375]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Jun 11 04:33:41 volumio volumio[1375]: info: Retrying Login Due to Network Error Jun 11 04:33:41 volumio volumio[1375]: error: Cannot start Volumio Streaming Daemon Jun 11 04:33:41 volumio volumio[1375]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 11 04:33:41 volumio volumio[1375]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 11 04:33:41 volumio volumio[1375]: info: Discovery: A device disappeared from network Jun 11 04:33:41 volumio volumio[1375]: info: Discovery: Device volumio disappeared from network Jun 11 04:33:41 volumio volumio[1375]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 11 04:33:41 volumio volumio[1375]: info: CoreCommandRouter::volumioGetState Jun 11 04:33:41 volumio volumio[1375]: info: CorePlayQueue::getTrack 0 Jun 11 04:33:41 volumio volumio[1375]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 11 04:33:44 volumio volumio[1375]: STREAMING PROXY: Starting server on port 3245 Jun 11 04:33:44 volumio volumio[1375]: Node JS runtime: 14 Jun 11 04:33:45 volumio volumio[1375]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 11 04:33:45 volumio volumio[1375]: Error: send ENETUNREACH 255.255.255.255:3483 Jun 11 04:33:45 volumio volumio[1375]: at doSend (dgram.js:692:16) Jun 11 04:33:45 volumio volumio[1375]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Jun 11 04:33:45 volumio volumio[1375]: at afterDns (dgram.js:638:5) Jun 11 04:33:45 volumio volumio[1375]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Jun 11 04:33:45 volumio volumio[1375]: errno: -101, Jun 11 04:33:45 volumio volumio[1375]: code: 'ENETUNREACH', Jun 11 04:33:45 volumio volumio[1375]: syscall: 'send', Jun 11 04:33:45 volumio volumio[1375]: address: '255.255.255.255', Jun 11 04:33:45 volumio volumio[1375]: port: 3483 Jun 11 04:33:45 volumio volumio[1375]: } Jun 11 04:33:45 volumio volumio[1375]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 11 04:33:46 volumio dhcpcd[799]: wlan0: leased 192.168.68.64 for 7200 seconds Jun 11 04:33:46 volumio dhcpcd[799]: wlan0: adding route to 192.168.68.0/22 Jun 11 04:33:46 volumio dhcpcd[799]: wlan0: adding default route via 192.168.68.1 Jun 11 04:33:46 volumio avahi-daemon[538]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.64. Jun 11 04:33:46 volumio avahi-daemon[538]: New relevant interface wlan0.IPv4 for mDNS. Jun 11 04:33:46 volumio avahi-daemon[538]: Registering new address record for 192.168.68.64 on wlan0.IPv4. Jun 11 04:33:46 volumio sudo[1959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-06-11 04:32 Jun 11 04:33:46 volumio sudo[1959]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"