-- Logs begin at Fri 2024-08-16 11:36:50 PDT, end at Thu 2024-08-22 01:55:54 PDT. --
Aug 22 01:54:12 volumio go-librespot[22245]: time="2024-08-22T01:54:12-07: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"
Aug 22 01:54:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 22 01:54:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 22 01:54:12 volumio volumio[1002]: (node:1002) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 22 01:54:12 volumio volumio[1002]: at connResetException (internal/errors.js:607:14)
Aug 22 01:54:12 volumio volumio[1002]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 22 01:54:12 volumio volumio[1002]: at Socket.emit (events.js:327:22)
Aug 22 01:54:12 volumio volumio[1002]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 22 01:54:12 volumio volumio[1002]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 22 01:54:12 volumio volumio[1002]: (node:1002) 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: 47)
Aug 22 01:54:12 volumio volumio[1002]: info: Connection to go-librespot Websocket closed
Aug 22 01:54:15 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:54:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 22 01:54:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36.
Aug 22 01:54:15 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 22 01:54:15 volumio volumio[1002]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 22 01:54:15 volumio systemd[1]: Started go-librespot Daemon.
Aug 22 01:54:15 volumio go-librespot[22255]: Librespot-go daemon starting...
Aug 22 01:54:15 volumio go-librespot[22255]: time="2024-08-22T01:54:15-07:00" level=info msg="generated new device id: a1a9a2ab2b7399a2a9d40d5744d78d77e91c369e"
Aug 22 01:54:15 volumio go-librespot[22255]: time="2024-08-22T01:54:15-07:00" level=debug msg="stored credentials found for 12156046794"
Aug 22 01:54:18 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:54:18 volumio go-librespot[22255]: time="2024-08-22T01:54:18-07:00" level=debug msg="new websocket client"
Aug 22 01:54:18 volumio volumio[1002]: info: Connection to go-librespot Websocket established
Aug 22 01:54:21 volumio volumio[1002]: info: Getting Spotify volume
Aug 22 01:54:21 volumio volumio[1002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Aug 22 01:54:21 volumio volumio[1002]: info: CoreCommandRouter::volumioGetState
Aug 22 01:54:21 volumio volumio[1002]: info: CorePlayQueue::getTrack 1
Aug 22 01:54:21 volumio volumio[1002]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Aug 22 01:54:33 volumio go-librespot[22255]: time="2024-08-22T01:54:33-07: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"
Aug 22 01:54:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 22 01:54:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 22 01:54:33 volumio volumio[1002]: (node:1002) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 22 01:54:33 volumio volumio[1002]: at connResetException (internal/errors.js:607:14)
Aug 22 01:54:33 volumio volumio[1002]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 22 01:54:33 volumio volumio[1002]: at Socket.emit (events.js:327:22)
Aug 22 01:54:33 volumio volumio[1002]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 22 01:54:33 volumio volumio[1002]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 22 01:54:33 volumio volumio[1002]: (node:1002) 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: 49)
Aug 22 01:54:33 volumio volumio[1002]: info: Connection to go-librespot Websocket closed
Aug 22 01:54:36 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:54:36 volumio volumio[1002]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 22 01:54:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 22 01:54:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Aug 22 01:54:36 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 22 01:54:36 volumio systemd[1]: Started go-librespot Daemon.
Aug 22 01:54:36 volumio go-librespot[22302]: Librespot-go daemon starting...
Aug 22 01:54:36 volumio go-librespot[22302]: time="2024-08-22T01:54:36-07:00" level=info msg="generated new device id: 279f27493ae20e58c1ac15ed40988c65f3c9c1bf"
Aug 22 01:54:36 volumio go-librespot[22302]: time="2024-08-22T01:54:36-07:00" level=debug msg="stored credentials found for 12156046794"
Aug 22 01:54:39 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:54:39 volumio go-librespot[22302]: time="2024-08-22T01:54:39-07:00" level=debug msg="new websocket client"
Aug 22 01:54:39 volumio volumio[1002]: info: Connection to go-librespot Websocket established
Aug 22 01:54:42 volumio volumio[1002]: info: Getting Spotify volume
Aug 22 01:54:42 volumio volumio[1002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Aug 22 01:54:42 volumio volumio[1002]: info: CoreCommandRouter::volumioGetState
Aug 22 01:54:42 volumio volumio[1002]: info: CorePlayQueue::getTrack 1
Aug 22 01:54:42 volumio volumio[1002]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Aug 22 01:54:51 volumio go-librespot[22302]: time="2024-08-22T01:54:51-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Aug 22 01:54:51 volumio go-librespot[22302]: time="2024-08-22T01:54:51-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Aug 22 01:54:51 volumio go-librespot[22302]: time="2024-08-22T01:54:51-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Aug 22 01:54:51 volumio go-librespot[22302]: time="2024-08-22T01:54:51-07:00" level=debug msg="zeroconf server listening on port 41897"
Aug 22 01:54:53 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-DISCONNECTED bssid=5c:e9:31:9f:78:6a reason=8
Aug 22 01:54:53 volumio dhcpcd[917]: wlan0: carrier lost
Aug 22 01:54:53 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Aug 22 01:54:53 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US
Aug 22 01:54:53 volumio avahi-daemon[634]: Withdrawing address record for 192.168.0.250 on wlan0.
Aug 22 01:54:53 volumio avahi-daemon[634]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.250.
Aug 22 01:54:53 volumio avahi-daemon[634]: Interface wlan0.IPv4 no longer relevant for mDNS.
Aug 22 01:54:53 volumio dhcpcd[917]: wlan0: deleting route to 192.168.0.0/24
Aug 22 01:54:53 volumio dhcpcd[917]: wlan0: deleting default route via 192.168.0.1
Aug 22 01:54:53 volumio volumio[1002]: info: Discovery: A device disappeared from network
Aug 22 01:54:53 volumio volumio[1002]: info: Discovery: Device volumio disappeared from network
Aug 22 01:54:53 volumio wpa_supplicant[905]: wlan0: Trying to associate with SSID 'ARRIS-E559_EXT2'
Aug 22 01:54:55 volumio ntpd[811]: Deleting interface #8 wlan0, 192.168.0.250#123, interface stats: received=696, sent=714, dropped=0, active_time=117030 secs
Aug 22 01:54:55 volumio ntpd[811]: 192.92.6.30 local addr 192.168.0.250 ->
Aug 22 01:54:55 volumio ntpd[811]: 162.159.200.1 local addr 192.168.0.250 ->
Aug 22 01:54:55 volumio ntpd[811]: 162.159.200.123 local addr 192.168.0.250 ->
Aug 22 01:54:55 volumio ntpd[811]: 104.167.241.197 local addr 192.168.0.250 ->
Aug 22 01:54:55 volumio ntpd[811]: 50.205.57.38 local addr 192.168.0.250 ->
Aug 22 01:54:55 volumio ntpd[811]: 44.4.53.1 local addr 192.168.0.250 ->
Aug 22 01:54:56 volumio go-librespot[22302]: time="2024-08-22T01:54:56-07: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"
Aug 22 01:54:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 22 01:54:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 22 01:54:56 volumio volumio[1002]: (node:1002) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 22 01:54:56 volumio volumio[1002]: at connResetException (internal/errors.js:607:14)
Aug 22 01:54:56 volumio volumio[1002]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 22 01:54:56 volumio volumio[1002]: at Socket.emit (events.js:327:22)
Aug 22 01:54:56 volumio volumio[1002]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 22 01:54:56 volumio volumio[1002]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 22 01:54:56 volumio volumio[1002]: (node:1002) 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: 51)
Aug 22 01:54:56 volumio volumio[1002]: info: Connection to go-librespot Websocket closed
Aug 22 01:54:57 volumio dhcpcd[917]: wlan0: carrier acquired
Aug 22 01:54:57 volumio wpa_supplicant[905]: wlan0: Associated with 5c:e9:31:9f:78:6a
Aug 22 01:54:57 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:e9:31:9f:78:6a completed [id=0 id_str=]
Aug 22 01:54:57 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Aug 22 01:54:57 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
Aug 22 01:54:57 volumio dhcpcd[917]: wlan0: IAID eb:15:de:9d
Aug 22 01:54:57 volumio dhcpcd[917]: wlan0: carrier lost
Aug 22 01:54:57 volumio dhcpcd[917]: wlan0: carrier acquired
Aug 22 01:54:57 volumio dhcpcd[917]: wlan0: IAID eb:15:de:9d
Aug 22 01:54:57 volumio dhcpcd[917]: wlan0: rebinding lease of 192.168.0.250
Aug 22 01:54:58 volumio dhcpcd[917]: wlan0: soliciting an IPv6 router
Aug 22 01:54:59 volumio dhcpcd[917]: wlan0: NAK: from 192.168.0.70
Aug 22 01:54:59 volumio dhcpcd[917]: wlan0: soliciting a DHCP lease
Aug 22 01:54:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 22 01:54:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Aug 22 01:54:59 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 22 01:54:59 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:54:59 volumio volumio[1002]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 22 01:54:59 volumio systemd[1]: Started go-librespot Daemon.
Aug 22 01:54:59 volumio go-librespot[22364]: Librespot-go daemon starting...
Aug 22 01:54:59 volumio go-librespot[22364]: time="2024-08-22T01:54:59-07:00" level=info msg="generated new device id: da904082ae074b9ade360b6b1ed460a0cae68cbd"
Aug 22 01:54:59 volumio go-librespot[22364]: time="2024-08-22T01:54:59-07:00" level=debug msg="stored credentials found for 12156046794"
Aug 22 01:54:59 volumio go-librespot[22364]: time="2024-08-22T01:54:59-07: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"
Aug 22 01:54:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 22 01:54:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 22 01:54:59 volumio dhcpcd[917]: wlan0: offered 192.168.0.104 from 192.168.0.70
Aug 22 01:54:59 volumio dhcpcd[917]: wlan0: probing address 192.168.0.104/24
Aug 22 01:55:02 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:55:02 volumio volumio[1002]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 22 01:55:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 22 01:55:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Aug 22 01:55:02 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 22 01:55:02 volumio systemd[1]: Started go-librespot Daemon.
Aug 22 01:55:02 volumio go-librespot[22372]: Librespot-go daemon starting...
Aug 22 01:55:02 volumio go-librespot[22372]: time="2024-08-22T01:55:02-07:00" level=info msg="generated new device id: 4c439c3f77b21486a39b7b0a5d04b15139be1ea0"
Aug 22 01:55:02 volumio go-librespot[22372]: time="2024-08-22T01:55:02-07:00" level=debug msg="stored credentials found for 12156046794"
Aug 22 01:55:02 volumio go-librespot[22372]: time="2024-08-22T01:55:02-07: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"
Aug 22 01:55:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 22 01:55:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 22 01:55:05 volumio dhcpcd[917]: wlan0: leased 192.168.0.104 for 180 seconds
Aug 22 01:55:05 volumio avahi-daemon[634]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.104.
Aug 22 01:55:05 volumio avahi-daemon[634]: New relevant interface wlan0.IPv4 for mDNS.
Aug 22 01:55:05 volumio dhcpcd[917]: wlan0: adding route to 192.168.0.0/24
Aug 22 01:55:05 volumio avahi-daemon[634]: Registering new address record for 192.168.0.104 on wlan0.IPv4.
Aug 22 01:55:05 volumio dhcpcd[917]: wlan0: adding default route via 192.168.0.70
Aug 22 01:55:05 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:55:05 volumio volumio[1002]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Aug 22 01:55:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 22 01:55:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Aug 22 01:55:06 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 22 01:55:06 volumio systemd[1]: Started go-librespot Daemon.
Aug 22 01:55:06 volumio go-librespot[22401]: Librespot-go daemon starting...
Aug 22 01:55:06 volumio go-librespot[22401]: time="2024-08-22T01:55:06-07:00" level=info msg="generated new device id: 16d0b800795be008330a9a4d7c617ec77d6d3caf"
Aug 22 01:55:06 volumio go-librespot[22401]: time="2024-08-22T01:55:06-07:00" level=debug msg="stored credentials found for 12156046794"
Aug 22 01:55:06 volumio volumio[1002]: info: Discovery: adding 59db8334-370f-4fd8-8e96-bd731550c9d3
Aug 22 01:55:06 volumio volumio[1002]: info: Discovery: Found device Volumio
Aug 22 01:55:06 volumio volumio[1002]: info: CoreCommandRouter::volumioGetState
Aug 22 01:55:06 volumio volumio[1002]: info: CorePlayQueue::getTrack 1
Aug 22 01:55:06 volumio ntpd[811]: Listen normally on 9 wlan0 192.168.0.104:123
Aug 22 01:55:06 volumio ntpd[811]: new interface(s) found: waking up resolver
Aug 22 01:55:08 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:55:08 volumio go-librespot[22401]: time="2024-08-22T01:55:08-07:00" level=debug msg="new websocket client"
Aug 22 01:55:08 volumio volumio[1002]: info: Connection to go-librespot Websocket established
Aug 22 01:55:11 volumio volumio[1002]: info: Getting Spotify volume
Aug 22 01:55:11 volumio volumio[1002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Aug 22 01:55:11 volumio volumio[1002]: info: CoreCommandRouter::volumioGetState
Aug 22 01:55:11 volumio volumio[1002]: info: CorePlayQueue::getTrack 1
Aug 22 01:55:11 volumio volumio[1002]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Aug 22 01:55:20 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-DISCONNECTED bssid=5c:e9:31:9f:78:6a reason=8
Aug 22 01:55:20 volumio dhcpcd[917]: wlan0: carrier lost
Aug 22 01:55:20 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Aug 22 01:55:20 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US
Aug 22 01:55:20 volumio avahi-daemon[634]: Withdrawing address record for 192.168.0.104 on wlan0.
Aug 22 01:55:20 volumio avahi-daemon[634]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.104.
Aug 22 01:55:20 volumio avahi-daemon[634]: Interface wlan0.IPv4 no longer relevant for mDNS.
Aug 22 01:55:20 volumio dhcpcd[917]: wlan0: deleting route to 192.168.0.0/24
Aug 22 01:55:20 volumio dhcpcd[917]: wlan0: deleting default route via 192.168.0.70
Aug 22 01:55:20 volumio volumio[1002]: info: Discovery: A device disappeared from network
Aug 22 01:55:20 volumio volumio[1002]: info: Discovery: Device volumio disappeared from network
Aug 22 01:55:21 volumio wpa_supplicant[905]: wlan0: Trying to associate with SSID 'ARRIS-E559_EXT2'
Aug 22 01:55:21 volumio ntpd[811]: error resolving pool 0.debian.pool.ntp.org: System error (-11)
Aug 22 01:55:22 volumio ntpd[811]: Deleting interface #9 wlan0, 192.168.0.104#123, interface stats: received=0, sent=6, dropped=0, active_time=16 secs
Aug 22 01:55:22 volumio ntpd[811]: 192.92.6.30 local addr 192.168.0.104 ->
Aug 22 01:55:22 volumio ntpd[811]: 162.159.200.1 local addr 192.168.0.104 ->
Aug 22 01:55:22 volumio ntpd[811]: 162.159.200.123 local addr 192.168.0.104 ->
Aug 22 01:55:22 volumio ntpd[811]: 104.167.241.197 local addr 192.168.0.104 ->
Aug 22 01:55:22 volumio ntpd[811]: 50.205.57.38 local addr 192.168.0.104 ->
Aug 22 01:55:22 volumio ntpd[811]: 44.4.53.1 local addr 192.168.0.104 ->
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: carrier acquired
Aug 22 01:55:24 volumio wpa_supplicant[905]: wlan0: Associated with 5c:e9:31:9f:78:6a
Aug 22 01:55:24 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:e9:31:9f:78:6a completed [id=0 id_str=]
Aug 22 01:55:24 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Aug 22 01:55:24 volumio wpa_supplicant[905]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: IAID eb:15:de:9d
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: carrier lost
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: carrier acquired
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: IAID eb:15:de:9d
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: rebinding lease of 192.168.0.104
Aug 22 01:55:24 volumio dhcpcd[917]: wlan0: soliciting an IPv6 router
Aug 22 01:55:25 volumio ntpd[811]: error resolving pool 1.debian.pool.ntp.org: System error (-11)
Aug 22 01:55:29 volumio dhcpcd[917]: wlan0: probing for an IPv4LL address
Aug 22 01:55:29 volumio dhcpcd[917]: wlan0: DHCP lease expired
Aug 22 01:55:29 volumio dhcpcd[917]: wlan0: soliciting a DHCP lease
Aug 22 01:55:30 volumio dhcpcd[917]: wlan0: offered 192.168.0.250 from 192.168.0.1
Aug 22 01:55:32 volumio ntpd[811]: Soliciting pool server 2620:8d:c000::f
Aug 22 01:55:33 volumio nmbd[770]: [2024/08/22 01:55:33.964600, 0] ../source3/libsmb/nmblib.c:917(send_udp)
Aug 22 01:55:33 volumio nmbd[770]: Packet send failed to 192.168.0.255(137) ERRNO=Network is unreachable
Aug 22 01:55:33 volumio nmbd[770]: [2024/08/22 01:55:33.964841, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet)
Aug 22 01:55:33 volumio nmbd[770]: send_netbios_packet: send_packet() to IP 192.168.0.255 port 137 failed
Aug 22 01:55:33 volumio nmbd[770]: [2024/08/22 01:55:33.964932, 0] ../source3/nmbd/nmbd_namequery.c:245(query_name)
Aug 22 01:55:33 volumio nmbd[770]: query_name: Failed to send packet trying to query name WORKGROUP<1d>
Aug 22 01:55:34 volumio dhcpcd[917]: wlan0: using IPv4LL address 169.254.222.48
Aug 22 01:55:34 volumio avahi-daemon[634]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.222.48.
Aug 22 01:55:34 volumio avahi-daemon[634]: New relevant interface wlan0.IPv4 for mDNS.
Aug 22 01:55:34 volumio avahi-daemon[634]: Registering new address record for 169.254.222.48 on wlan0.IPv4.
Aug 22 01:55:34 volumio dhcpcd[917]: wlan0: adding route to 169.254.0.0/16
Aug 22 01:55:34 volumio dhcpcd[917]: wlan0: adding default route
Aug 22 01:55:36 volumio go-librespot[22401]: time="2024-08-22T01:55:36-07: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 10.0.0.1:443: i/o timeout"
Aug 22 01:55:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Aug 22 01:55:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Aug 22 01:55:36 volumio volumio[1002]: (node:1002) UnhandledPromiseRejectionWarning: Error: socket hang up
Aug 22 01:55:36 volumio volumio[1002]: at connResetException (internal/errors.js:607:14)
Aug 22 01:55:36 volumio volumio[1002]: at Socket.socketOnEnd (_http_client.js:493:23)
Aug 22 01:55:36 volumio volumio[1002]: at Socket.emit (events.js:327:22)
Aug 22 01:55:36 volumio volumio[1002]: at endReadableNT (internal/streams/readable.js:1327:12)
Aug 22 01:55:36 volumio volumio[1002]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Aug 22 01:55:36 volumio volumio[1002]: (node:1002) 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: 53)
Aug 22 01:55:36 volumio volumio[1002]: info: Connection to go-librespot Websocket closed
Aug 22 01:55:36 volumio ntpd[811]: Listen normally on 10 wlan0 169.254.222.48:123
Aug 22 01:55:36 volumio ntpd[811]: new interface(s) found: waking up resolver
Aug 22 01:55:39 volumio volumio[1002]: info: Initializing connection to go-librespot Websocket
Aug 22 01:55:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Aug 22 01:55:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Aug 22 01:55:39 volumio systemd[1]: Stopped go-librespot Daemon.
Aug 22 01:55:39 volumio systemd[1]: Started go-librespot Daemon.
Aug 22 01:55:39 volumio go-librespot[22515]: Librespot-go daemon starting...
Aug 22 01:55:39 volumio go-librespot[22515]: time="2024-08-22T01:55:39-07:00" level=info msg="generated new device id: 2e5c049591a903c80c66f9446a131031e1a4369d"
Aug 22 01:55:39 volumio go-librespot[22515]: time="2024-08-22T01:55:39-07:00" level=debug msg="stored credentials found for 12156046794"
Aug 22 01:55:43 volumio dhcpcd[917]: wlan0: probing address 192.168.0.250/24
Aug 22 01:55:48 volumio dhcpcd[917]: wlan0: leased 192.168.0.250 for 3600 seconds
Aug 22 01:55:48 volumio avahi-daemon[634]: Registering new address record for 192.168.0.250 on wlan0.IPv4.
Aug 22 01:55:48 volumio dhcpcd[917]: wlan0: adding route to 192.168.0.0/24
Aug 22 01:55:48 volumio dhcpcd[917]: wlan0: changing default route via 192.168.0.1
Aug 22 01:55:49 volumio avahi-daemon[634]: Withdrawing address record for 169.254.222.48 on wlan0.
Aug 22 01:55:49 volumio avahi-daemon[634]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.222.48.
Aug 22 01:55:49 volumio avahi-daemon[634]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.250.
Aug 22 01:55:49 volumio dhcpcd[917]: wlan0: deleting route to 169.254.0.0/16
Aug 22 01:55:49 volumio dhcpcd[917]: wlan0: pid 917 deleted default route via 192.168.0.1
Aug 22 01:55:50 volumio ntpd[811]: Soliciting pool server 207.246.65.226
Aug 22 01:55:50 volumio ntpd[811]: Listen normally on 11 wlan0 192.168.0.250:123
Aug 22 01:55:50 volumio ntpd[811]: Deleting interface #10 wlan0, 169.254.222.48#123, interface stats: received=0, sent=6, dropped=1, active_time=14 secs
Aug 22 01:55:50 volumio ntpd[811]: 192.92.6.30 local addr 169.254.222.48 ->
Aug 22 01:55:50 volumio ntpd[811]: 162.159.200.1 local addr 169.254.222.48 ->
Aug 22 01:55:50 volumio ntpd[811]: 162.159.200.123 local addr 169.254.222.48 ->
Aug 22 01:55:50 volumio ntpd[811]: 104.167.241.197 local addr 169.254.222.48 ->
Aug 22 01:55:50 volumio ntpd[811]: 50.205.57.38 local addr 169.254.222.48 ->
Aug 22 01:55:50 volumio ntpd[811]: 44.4.53.1 local addr 169.254.222.48 ->
Aug 22 01:55:50 volumio ntpd[811]: new interface(s) found: waking up resolver
Aug 22 01:55:50 volumio volumio[1002]: info: Discovery: adding 59db8334-370f-4fd8-8e96-bd731550c9d3
Aug 22 01:55:50 volumio volumio[1002]: info: Discovery: Found device Volumio
Aug 22 01:55:50 volumio volumio[1002]: info: CoreCommandRouter::volumioGetState
Aug 22 01:55:50 volumio volumio[1002]: info: CorePlayQueue::getTrack 1
Aug 22 01:55:50 volumio go-librespot[22515]: time="2024-08-22T01:55:50-07:00" level=debug msg="new websocket client"
Aug 22 01:55:50 volumio volumio[1002]: info: Connection to go-librespot Websocket established
Aug 22 01:55:52 volumio volumio[1002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Aug 22 01:55:52 volumio volumio-remote-updater[617]: No test mode
Aug 22 01:55:52 volumio volumio-remote-updater[617]: No alpha test mode
Aug 22 01:55:52 volumio volumio[1002]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Aug 22 01:55:52 volumio volumio[1002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Aug 22 01:55:53 volumio volumio[1002]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Improved translations
- Fix for controlling Volumio device from another one
- Fix for slow playback on RPi5 with HifiBerry DAC
- Improved speed for default albumart
- Fix for HifiBerry DAC detection
- Fix for Supersearch bar on Iphone
- Fix for Network connection on Wizard
NEW ADDITIONS
- Facility for third party UIs
","title":"Update v3.742","updateavailable":true}
Aug 22 01:55:53 volumio volumio[1002]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 22 01:55:53 volumio volumio[1002]: info: Getting Spotify volume
Aug 22 01:55:53 volumio volumio[1002]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5
Aug 22 01:55:53 volumio volumio[1002]: info: CoreCommandRouter::volumioGetState
Aug 22 01:55:53 volumio volumio[1002]: info: CorePlayQueue::getTrack 1
Aug 22 01:55:53 volumio volumio[1002]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Aug 22 01:55:54 volumio volumio[1002]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 22 01:55:54 volumio volumio[1002]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] {
Aug 22 01:55:54 volumio volumio[1002]: code: 'auth/network-request-failed',
Aug 22 01:55:54 volumio volumio[1002]: a: null
Aug 22 01:55:54 volumio volumio[1002]: }
Aug 22 01:55:54 volumio volumio[1002]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 22 01:55:54 volumio sudo[22576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-22 01:54
Aug 22 01:55:54 volumio sudo[22576]: 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"