-- Logs begin at Fri 2024-07-12 20:44:04 EDT, end at Fri 2024-07-12 22:02:55 EDT. -- Jul 12 22:01:00 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:00 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:00 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:00 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:01 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:01 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:01 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:01 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:02 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:02 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:02 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:02 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:03 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:03 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:03 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:03 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:04 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:04 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:04 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:04 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:05 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:05 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:05 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:05 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:06 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:06 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:06 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:06 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:06 volumio volumio[1442]: error: MyVolumio Plugin failed to start in a timely fashion Jul 12 22:01:06 volumio volumio[1442]: info: BOOT COMPLETED Jul 12 22:01:06 volumio volumio[1442]: [Metrics] CommandRouter: 54s 411.53ms Jul 12 22:01:06 volumio volumio[1442]: info: CoreCommandRouter::volumiosetStartupVolume Jul 12 22:01:06 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 12 22:01:06 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:06 volumio volumio[1442]: info: CoreCommandRouter::Close All Modals sent Jul 12 22:01:06 volumio volumio[1442]: info: CoreCommandRouter::Close All Modals sent Jul 12 22:01:07 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:07 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:07 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:07 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:07 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 12 22:01:07 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 12 22:01:07 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 12 22:01:08 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:08 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:08 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:08 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:09 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 12 22:01:09 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:09 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 12 22:01:09 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:09 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:09 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:09 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:09 volumio volumio[1442]: verbose: ControllerMpd::sendMpdCommand add "http://149.13.0.81/radio1rock128" Jul 12 22:01:09 volumio volumio[1442]: info: Jul 12 22:01:09 volumio volumio[1442]: ---------------------------- MPD announces system playlist update Jul 12 22:01:09 volumio volumio[1442]: info: Ignoring MPD Status Update Jul 12 22:01:09 volumio volumio[1442]: info: sendMpdCommand add "http://149.13.0.81/radio1rock128" took 3 milliseconds Jul 12 22:01:09 volumio volumio[1442]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 12 22:01:09 volumio volumio[1442]: verbose: ControllerMpd::sendMpdCommand play Jul 12 22:01:09 volumio volumio[1442]: info: ------------------------------ 5ms Jul 12 22:01:09 volumio volumio[1442]: info: sendMpdCommand play took 4 milliseconds Jul 12 22:01:10 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:10 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:10 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:10 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:11 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:11 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:11 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:11 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:12 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:12 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:12 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:12 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:13 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:13 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:13 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:13 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:14 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:14 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:14 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:14 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:15 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:15 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:15 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:15 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:16 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:16 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:16 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:16 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:16 volumio go-librespot[1914]: time="2024-07-12T22:01:16-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 10.0.0.1:443: i/o timeout" Jul 12 22:01:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:01:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:01:16 volumio volumio[1442]: (node:1442) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 12 22:01:16 volumio volumio[1442]: at connResetException (internal/errors.js:607:14) Jul 12 22:01:16 volumio volumio[1442]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 12 22:01:16 volumio volumio[1442]: at Socket.emit (events.js:327:22) Jul 12 22:01:16 volumio volumio[1442]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 12 22:01:16 volumio volumio[1442]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 12 22:01:16 volumio volumio[1442]: (Use `node --trace-warnings ...` to show where the warning was created) Jul 12 22:01:16 volumio volumio[1442]: (node:1442) 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: 1) Jul 12 22:01:16 volumio volumio[1442]: (node:1442) [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. Jul 12 22:01:16 volumio volumio[1442]: info: Connection to go-librespot Websocket closed Jul 12 22:01:17 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:17 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:17 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:17 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:18 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:18 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:18 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:18 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:19 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:19 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:19 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:19 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:19 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:01:19 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:01:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:01:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 12 22:01:19 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:01:19 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:01:19 volumio go-librespot[2002]: Librespot-go daemon starting... Jul 12 22:01:19 volumio go-librespot[2002]: time="2024-07-12T22:01:19-04:00" level=info msg="generated new device id: 012a0c9cd326601ba830381805a5cde6a30f45ac" Jul 12 22:01:19 volumio go-librespot[2002]: time="2024-07-12T22:01:19-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:01:20 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:20 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:20 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:20 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:20 volumio volumio[1442]: info: Jul 12 22:01:20 volumio volumio[1442]: ---------------------------- MPD announces state update: player Jul 12 22:01:20 volumio volumio[1442]: info: ControllerMpd::getState Jul 12 22:01:20 volumio volumio[1442]: verbose: ControllerMpd::sendMpdCommand status Jul 12 22:01:20 volumio volumio[1442]: verbose: ControllerMpd::sendMpdCommand clearerror Jul 12 22:01:20 volumio volumio[1442]: info: sendMpdCommand status took 40 milliseconds Jul 12 22:01:20 volumio volumio[1442]: verbose: ControllerMpd::parseState Jul 12 22:01:20 volumio volumio[1442]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 12 22:01:20 volumio volumio[1442]: info: sendMpdCommand clearerror took 6 milliseconds Jul 12 22:01:20 volumio volumio[1442]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 12 22:01:20 volumio volumio[1442]: verbose: ControllerMpd::parseTrackInfo Jul 12 22:01:20 volumio volumio[1442]: info: ControllerMpd::pushState Jul 12 22:01:20 volumio volumio[1442]: info: CoreCommandRouter::servicePushState Jul 12 22:01:20 volumio volumio[1442]: info: CoreStateMachine::pushState Jul 12 22:01:20 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 12 22:01:20 volumio volumio[1442]: info: CoreCommandRouter::volumioPushState Jul 12 22:01:20 volumio volumio[1442]: info: CorePlayQueue::getTrack 0 Jul 12 22:01:20 volumio volumio[1442]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"radio1rock128","artist":null,"album":null,"uri":"http://149.13.0.81/radio1rock128","trackType":""} Jul 12 22:01:20 volumio volumio[1442]: verbose: CURRENT POSITION 0 Jul 12 22:01:20 volumio volumio[1442]: info: CoreStateMachine::syncState stateService stop Jul 12 22:01:20 volumio volumio[1442]: info: CoreStateMachine::syncState currentStatus stop Jul 12 22:01:20 volumio volumio[1442]: info: CoreStateMachine::pushState Jul 12 22:01:20 volumio volumio[1442]: info: CoreCommandRouter::volumioPushState Jul 12 22:01:20 volumio volumio[1442]: info: No code Jul 12 22:01:20 volumio volumio[1442]: info: CoreStateMachine::pushState Jul 12 22:01:20 volumio volumio[1442]: info: CoreCommandRouter::volumioPushState Jul 12 22:01:20 volumio volumio[1442]: info: ------------------------------ 155ms Jul 12 22:01:21 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:21 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:21 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:21 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:22 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:22 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:22 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:22 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:22 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:01:22 volumio go-librespot[2002]: time="2024-07-12T22:01:22-04:00" level=debug msg="new websocket client" Jul 12 22:01:22 volumio volumio[1442]: info: Connection to go-librespot Websocket established Jul 12 22:01:23 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:23 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:23 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:23 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:23 volumio ntpd[723]: Soliciting pool server 10.0.0.1 Jul 12 22:01:24 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:24 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:24 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:24 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:25 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:25 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:25 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:25 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:25 volumio volumio[1442]: info: Getting Spotify volume Jul 12 22:01:25 volumio volumio[1442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 12 22:01:25 volumio volumio[1442]: info: CoreCommandRouter::volumioGetState Jul 12 22:01:26 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:26 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:26 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:26 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:27 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:27 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:27 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:27 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:28 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:28 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:28 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:28 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:28 volumio dhcpcd[1129]: wlan0: carrier lost Jul 12 22:01:28 volumio wpa_supplicant[1117]: wlan0: Associated with a0:a3:f0:2f:7d:80 Jul 12 22:01:28 volumio wpa_supplicant[1117]: wlan0: CTRL-EVENT-CONNECTED - Connection to a0:a3:f0:2f:7d:80 completed [id=0 id_str=] Jul 12 22:01:28 volumio wpa_supplicant[1117]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 12 22:01:28 volumio avahi-daemon[549]: Withdrawing address record for 192.168.100.105 on wlan0. Jul 12 22:01:28 volumio avahi-daemon[549]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.105. Jul 12 22:01:28 volumio dhcpcd[1129]: wlan0: deleting route to 192.168.100.0/24 Jul 12 22:01:28 volumio avahi-daemon[549]: Interface wlan0.IPv4 no longer relevant for mDNS. Jul 12 22:01:28 volumio volumio[1442]: info: Discovery: A device disappeared from network Jul 12 22:01:28 volumio volumio[1442]: info: Discovery: Device volumio disappeared from network Jul 12 22:01:28 volumio dhcpcd[1129]: wlan0: carrier acquired Jul 12 22:01:28 volumio dhcpcd[1129]: wlan0: IAID eb:36:03:51 Jul 12 22:01:29 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:29 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:29 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:29 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:29 volumio dhcpcd[1129]: wlan0: rebinding lease of 192.168.100.105 Jul 12 22:01:29 volumio dhcpcd[1129]: wlan0: NAK: address not available from 192.168.100.1 Jul 12 22:01:29 volumio dhcpcd[1129]: wlan0: message: address not available Jul 12 22:01:29 volumio nmbd[658]: [2024/07/12 22:01:29.852660, 0] ../source3/libsmb/nmblib.c:917(send_udp) Jul 12 22:01:29 volumio nmbd[658]: Packet send failed to 192.168.100.255(137) ERRNO=Network is unreachable Jul 12 22:01:29 volumio nmbd[658]: [2024/07/12 22:01:29.852947, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jul 12 22:01:29 volumio nmbd[658]: retransmit_or_expire_response_records: Failed to resend packet id 14031 to IP 192.168.100.255 on subnet 192.168.100.44 Jul 12 22:01:29 volumio dhcpcd[1129]: wlan0: soliciting an IPv6 router Jul 12 22:01:29 volumio dhcpcd[1129]: wlan0: soliciting a DHCP lease Jul 12 22:01:30 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:30 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:30 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:30 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:30 volumio ntpd[723]: Deleting interface #22 wlan0, 192.168.100.105#123, interface stats: received=0, sent=12, dropped=0, active_time=57 secs Jul 12 22:01:30 volumio ntpd[723]: 195.85.215.8 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 195.85.215.215 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 162.159.200.1 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 77.236.182.128 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 162.159.200.123 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 45.81.36.15 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 185.117.82.66 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 194.59.28.22 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio ntpd[723]: 185.117.82.71 local addr 192.168.100.105 -> Jul 12 22:01:30 volumio nmbd[658]: [2024/07/12 22:01:30.853423, 0] ../source3/libsmb/nmblib.c:917(send_udp) Jul 12 22:01:30 volumio nmbd[658]: Packet send failed to 192.168.100.255(137) ERRNO=Network is unreachable Jul 12 22:01:30 volumio nmbd[658]: [2024/07/12 22:01:30.853686, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jul 12 22:01:30 volumio nmbd[658]: retransmit_or_expire_response_records: Failed to resend packet id 14031 to IP 192.168.100.255 on subnet 192.168.100.44 Jul 12 22:01:31 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:31 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:31 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:31 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:31 volumio nmbd[658]: [2024/07/12 22:01:31.855043, 0] ../source3/libsmb/nmblib.c:917(send_udp) Jul 12 22:01:31 volumio nmbd[658]: Packet send failed to 192.168.100.255(137) ERRNO=Network is unreachable Jul 12 22:01:31 volumio nmbd[658]: [2024/07/12 22:01:31.855280, 0] ../source3/nmbd/nmbd_packets.c:1639(retransmit_or_expire_response_records) Jul 12 22:01:31 volumio nmbd[658]: retransmit_or_expire_response_records: Failed to resend packet id 14031 to IP 192.168.100.255 on subnet 192.168.100.44 Jul 12 22:01:32 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:32 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:32 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:32 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:32 volumio ntpd[723]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jul 12 22:01:32 volumio nmbd[658]: [2024/07/12 22:01:32.856606, 0] ../source3/libsmb/nmblib.c:917(send_udp) Jul 12 22:01:32 volumio nmbd[658]: Packet send failed to 192.168.100.255(138) ERRNO=Network is unreachable Jul 12 22:01:33 volumio dhcpcd[1129]: wlan0: offered 192.168.100.44 from 192.168.100.1 Jul 12 22:01:33 volumio dhcpcd[1129]: wlan0: probing address 192.168.100.44/24 Jul 12 22:01:33 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:33 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:33 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:33 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:34 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:34 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:34 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:34 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:35 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:35 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:35 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:35 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:36 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:36 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:36 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:36 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:37 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:37 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:37 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:37 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:38 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:38 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:38 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:38 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:38 volumio dhcpcd[1129]: wlan0: leased 192.168.100.44 for 604800 seconds Jul 12 22:01:38 volumio avahi-daemon[549]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.44. Jul 12 22:01:38 volumio dhcpcd[1129]: wlan0: adding route to 192.168.100.0/24 Jul 12 22:01:38 volumio dhcpcd[1129]: wlan0: adding default route via 192.168.100.1 Jul 12 22:01:38 volumio avahi-daemon[549]: New relevant interface wlan0.IPv4 for mDNS. Jul 12 22:01:38 volumio avahi-daemon[549]: Registering new address record for 192.168.100.44 on wlan0.IPv4. Jul 12 22:01:39 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:39 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:39 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:39 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:39 volumio volumio[1442]: info: Discovery: adding 186db06e-1c5f-4c1e-be3d-626077eb7a13 Jul 12 22:01:39 volumio volumio[1442]: info: Discovery: Found device Volumio Jul 12 22:01:39 volumio volumio[1442]: info: CoreCommandRouter::volumioGetState Jul 12 22:01:40 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:40 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:40 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:40 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:40 volumio ntpd[723]: Listen normally on 23 wlan0 192.168.100.44:123 Jul 12 22:01:40 volumio ntpd[723]: new interface(s) found: waking up resolver Jul 12 22:01:41 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:41 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:41 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:41 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:42 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:42 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:42 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:42 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jul 12 22:01:43 volumio volumio[1442]: info: Adding plugin bluetooth to MyMusic Plugins Jul 12 22:01:43 volumio volumio[1442]: info: Adding plugin multiroom to MyMusic Plugins Jul 12 22:01:43 volumio volumio[1442]: info: Adding plugin metavolumio to MyMusic Plugins Jul 12 22:01:43 volumio volumio[1442]: info: Adding plugin cd_controller to MyMusic Plugins Jul 12 22:01:43 volumio volumio[1442]: info: Adding plugin smart_inputs to MyMusic Plugins Jul 12 22:01:43 volumio volumio[1442]: info: Adding plugin tidalconnect to MyMusic Plugins Jul 12 22:01:43 volumio volumio[1442]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jul 12 22:01:43 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:43 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:43 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:43 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:44 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:44 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:44 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:44 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:44 volumio volumio[1442]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jul 12 22:01:44 volumio volumio[1442]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jul 12 22:01:44 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:44 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:44 volumio volumio[1442]: info: Starting MyVolumio Remote Streaming Endpoints Jul 12 22:01:44 volumio volumio[1442]: info: MyVolumio login type: Token Jul 12 22:01:44 volumio volumio[1442]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jul 12 22:01:44 volumio volumio[1442]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jul 12 22:01:45 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:45 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:45 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:45 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:46 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:46 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:46 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:46 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:46 volumio volumio[1442]: info: Starting Streaming Service Transparent Proxy Jul 12 22:01:46 volumio volumio[1442]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jul 12 22:01:46 volumio volumio[1442]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jul 12 22:01:46 volumio volumio[1442]: info: Streaming services startup Jul 12 22:01:46 volumio volumio[1442]: info: Starting Streaming Daemon Jul 12 22:01:46 volumio sudo[2089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 12 22:01:46 volumio sudo[2089]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 12 22:01:46 volumio sudo[2089]: pam_unix(sudo:session): session closed for user root Jul 12 22:01:46 volumio volumio[1442]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jul 12 22:01:47 volumio volumio[1442]: error: Cannot start Volumio Streaming Daemon Jul 12 22:01:47 volumio volumio[1442]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 12 22:01:47 volumio volumio[1442]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 12 22:01:47 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:47 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:47 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:47 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:47 volumio volumio[1442]: error: MyVolumio Custom Token format not valid, refreshing it Jul 12 22:01:48 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:48 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:48 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:48 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:48 volumio volumio[1442]: STREAMING PROXY: Starting server on port 3245 Jul 12 22:01:48 volumio volumio[1442]: Node JS runtime: 14 Jul 12 22:01:48 volumio volumio[1442]: info: MyVolumio login type: Token Jul 12 22:01:49 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:49 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:49 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:49 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:49 volumio volumio[1442]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 12 22:01:49 volumio go-librespot[2002]: time="2024-07-12T22:01: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 10.0.0.1:443: i/o timeout" Jul 12 22:01:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:01:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:01:49 volumio volumio[1442]: (node:1442) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 12 22:01:49 volumio volumio[1442]: at connResetException (internal/errors.js:607:14) Jul 12 22:01:49 volumio volumio[1442]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 12 22:01:49 volumio volumio[1442]: at Socket.emit (events.js:327:22) Jul 12 22:01:49 volumio volumio[1442]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 12 22:01:49 volumio volumio[1442]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 12 22:01:49 volumio volumio[1442]: (node:1442) 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) Jul 12 22:01:49 volumio volumio[1442]: info: Connection to go-librespot Websocket closed Jul 12 22:01:50 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:50 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:50 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:50 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:50 volumio volumio[1442]: info: MyVolumio token set successfully Jul 12 22:01:50 volumio volumio[1442]: info: MYVOLUMIO: Adding device Jul 12 22:01:50 volumio volumio[1442]: info: MYVOLUMIO: Evaluating Server Jul 12 22:01:51 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:51 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:51 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:51 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:51 volumio volumio[1442]: info: MyVolumio status changed Jul 12 22:01:51 volumio volumio[1442]: info: Streaming services startup Jul 12 22:01:51 volumio volumio[1442]: info: Starting Streaming Daemon Jul 12 22:01:51 volumio volumio[1442]: info: Removing browser output: myVolumio user plan is not superstar Jul 12 22:01:51 volumio volumio[1442]: info: Removing audio output: Jul 12 22:01:51 volumio volumio[1442]: info: Stoppping Tunnel 1 Jul 12 22:01:51 volumio sudo[2120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 12 22:01:51 volumio sudo[2120]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 12 22:01:51 volumio sudo[2120]: pam_unix(sudo:session): session closed for user root Jul 12 22:01:51 volumio volumio[1442]: error: Cannot start Volumio Streaming Daemon Jul 12 22:01:51 volumio volumio[1442]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 12 22:01:51 volumio volumio[1442]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 12 22:01:51 volumio sudo[2123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jul 12 22:01:51 volumio sudo[2123]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 12 22:01:51 volumio sudo[2123]: pam_unix(sudo:session): session closed for user root Jul 12 22:01:51 volumio volumio[1442]: info: Remote SSH Stopped Jul 12 22:01:51 volumio ntpd[723]: Soliciting pool server 95.43.236.49 Jul 12 22:01:51 volumio volumio[1442]: info: Setting Geolocation for MyVolumio to eu10 Jul 12 22:01:51 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:51 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:51 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:52 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:52 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:52 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:52 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:52 volumio volumio[1442]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jul 12 22:01:52 volumio volumio[1442]: info: Updating MyVolumio device info Jul 12 22:01:52 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:52 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:52 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:52 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:01:52 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:01:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:01:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 12 22:01:52 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:01:52 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:01:52 volumio go-librespot[2125]: Librespot-go daemon starting... Jul 12 22:01:52 volumio go-librespot[2125]: time="2024-07-12T22:01:52-04:00" level=info msg="generated new device id: fb104ef928a3658a854e7396212f52d34a1912c0" Jul 12 22:01:52 volumio go-librespot[2125]: time="2024-07-12T22:01:52-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:01:53 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:53 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:53 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:53 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:53 volumio go-librespot[2125]: time="2024-07-12T22:01:53-04:00" level=debug msg="obtained new client token: AABdc1xifsZNcF9O45yHAKmlDfpAVaNv+2l2sGC1pqSj/hizBbP843nSE3sOZKKcnBcNW3Ryy7ljXJgmc/hSjxOBbyXYSDpm8YyG245frImk/pzLmKPzvWG/wDjEESF5ipb++6SMHrhJvMJwZeZyTmPTJHURqSVJV9nKev3OmOvqNY3I8awah9OU6hPFB4YcdmuTZFcrp/Ypu3LhF7DPzZITmh1vd7flYGNcmO8WiyPmc0CqvnjM63BJSmjXNxw=" Jul 12 22:01:53 volumio volumio[1442]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jul 12 22:01:53 volumio go-librespot[2125]: time="2024-07-12T22:01:53-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:01:53 volumio go-librespot[2125]: time="2024-07-12T22:01:53-04:00" level=debug msg="completed keyexchange" Jul 12 22:01:54 volumio go-librespot[2125]: time="2024-07-12T22:01:54-04:00" level=debug msg="completed challenge" Jul 12 22:01:54 volumio go-librespot[2125]: time="2024-07-12T22:01:54-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:01:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:01:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:01:54 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:54 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:54 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:54 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:55 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:55 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:55 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:55 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:55 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:01:55 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:01:56 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:56 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:56 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:56 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:56 volumio volumio[1442]: info: MYVOLUMIO: Adding device Jul 12 22:01:56 volumio volumio[1442]: info: MYVOLUMIO: Evaluating Server Jul 12 22:01:57 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:57 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:57 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:57 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:01:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jul 12 22:01:57 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:01:57 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:01:57 volumio go-librespot[2148]: Librespot-go daemon starting... Jul 12 22:01:57 volumio go-librespot[2148]: time="2024-07-12T22:01:57-04:00" level=info msg="generated new device id: fcfbe8621ef441d6bf915eca4364e5abf4fa07f6" Jul 12 22:01:57 volumio go-librespot[2148]: time="2024-07-12T22:01:57-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:01:57 volumio volumio[1442]: info: Setting Geolocation for MyVolumio to eu10 Jul 12 22:01:57 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:57 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:57 volumio go-librespot[2148]: time="2024-07-12T22:01:57-04:00" level=debug msg="obtained new client token: AACXl4f6vXP6DeKABgUhquOFhB5ty2V93cqkzEpfR4HbktMHxdeqwrvsLVVOjDzLDTHcGJTWow/5F6+ek18dJ+OxG8JTQD1nvK9fPS/rDeINYGU5qu69IizQsaDNuzwRiE2+2q1xplzJsPCIivQUon9q6GGKRvQxMDEKJzuil0v+cQ0PCHdmjSGrd8oLgKdIUCK8g8ys3XFxuCYXiHXhyguLQbDsNZ/evTujc/n6LSnm1XFarOQqp5SYawj1NQE=" Jul 12 22:01:57 volumio go-librespot[2148]: time="2024-07-12T22:01:57-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:01:58 volumio go-librespot[2148]: time="2024-07-12T22:01:58-04:00" level=debug msg="completed keyexchange" Jul 12 22:01:58 volumio volumio[1442]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jul 12 22:01:58 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:58 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:58 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:58 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:58 volumio volumio[1442]: info: Updating MyVolumio device info Jul 12 22:01:58 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:58 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:58 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 12 22:01:58 volumio go-librespot[2148]: time="2024-07-12T22:01:58-04:00" level=debug msg="completed challenge" Jul 12 22:01:58 volumio go-librespot[2148]: time="2024-07-12T22:01:58-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:01:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:01:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:01:58 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:01:58 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:01:58 volumio volumio[1442]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jul 12 22:01:59 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:59 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:59 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:01:59 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:01:59 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 12 22:01:59 volumio volumio[1442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 10 Jul 12 22:01:59 volumio volumio[1442]: info: CoreCommandRouter::volumioGetState Jul 12 22:02:00 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:00 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:00 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:00 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:01 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:01 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:01 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:01 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:01 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:01 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jul 12 22:02:01 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:01 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:01 volumio go-librespot[2155]: Librespot-go daemon starting... Jul 12 22:02:01 volumio go-librespot[2155]: time="2024-07-12T22:02:01-04:00" level=info msg="generated new device id: 1b5181e00aa42bf754d8cad3b0fcd3bee62dba29" Jul 12 22:02:01 volumio go-librespot[2155]: time="2024-07-12T22:02:01-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:02 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:02 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:02 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:02 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:02 volumio go-librespot[2155]: time="2024-07-12T22:02:02-04:00" level=debug msg="obtained new client token: AADQ258+e+yLhkuee7ZKVaXIX8dLqS2pEqGn7nc+EYPcUF3GdVTvL1g/D3RS5IcOtk9NA/vJJ5PCWrXFw6P2062dImJtn85A6v+nnDX6uZyUNqMeqr6L3QYgO9ISHTBvM9fEVKnwkhD3Ydue53v/h09mAFhXOtpdX/ZsTokfXIy8eypV+EGoqagRmR5D3kY8T/p/mIFUIQnaWDVXlqq2oqy2fmoLdfbPMxU2t1HGBzdOI3gs9Qgo7ixOtsgi" Jul 12 22:02:02 volumio go-librespot[2155]: time="2024-07-12T22:02:02-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 12 22:02:02 volumio go-librespot[2155]: time="2024-07-12T22:02:02-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:03 volumio go-librespot[2155]: time="2024-07-12T22:02:03-04:00" level=debug msg="completed challenge" Jul 12 22:02:03 volumio go-librespot[2155]: time="2024-07-12T22:02:03-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:03 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:03 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:03 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:03 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:04 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:04 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:04 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:04 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:04 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:04 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::volumioGetBrowseSources Jul 12 22:02:04 volumio volumio[1442]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 12 22:02:05 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:05 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:05 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:05 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:06 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:06 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:06 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:06 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jul 12 22:02:06 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:06 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:06 volumio go-librespot[2163]: Librespot-go daemon starting... Jul 12 22:02:06 volumio go-librespot[2163]: time="2024-07-12T22:02:06-04:00" level=info msg="generated new device id: b8f80ef839e2545ee148d2ff394e752d4ca8cb05" Jul 12 22:02:06 volumio go-librespot[2163]: time="2024-07-12T22:02:06-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:06 volumio go-librespot[2163]: time="2024-07-12T22:02:06-04:00" level=debug msg="obtained new client token: AAArBQxTtG7LlGmWre1cLzUl9Wp/IDPIoM89xgh7ISeWPss+PaJmULUsl/57Slx1MvtXR2duET8o8GLIBUHah3UdC9Z/kXwxmgwJUFQu1vHxVDQdhq3RwYo3UEqt2oLvfu1KoKSZpFesRFv5ApePnBsymT7a7C3sm+W37tKdDiMg/mcKKutrnLsuxhuVh64JJDBqXzt+QSc8AHXNfEkxgxN3Af7aEeMtcoOHbik0c6PbKwcuFoNxhqg6y8Ii6Tk=" Jul 12 22:02:06 volumio go-librespot[2163]: time="2024-07-12T22:02:06-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:07 volumio go-librespot[2163]: time="2024-07-12T22:02:07-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:07 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:07 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:07 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:07 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:07 volumio go-librespot[2163]: time="2024-07-12T22:02:07-04:00" level=debug msg="completed challenge" Jul 12 22:02:07 volumio go-librespot[2163]: time="2024-07-12T22:02:07-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:07 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:07 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:08 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:08 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:08 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:08 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:09 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:09 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:09 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:09 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:10 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:10 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:10 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:10 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:10 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:10 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jul 12 22:02:10 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:10 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:10 volumio go-librespot[2171]: Librespot-go daemon starting... Jul 12 22:02:10 volumio go-librespot[2171]: time="2024-07-12T22:02:10-04:00" level=info msg="generated new device id: ba1f26df1dbce7197de1bc5bfef784010003797b" Jul 12 22:02:10 volumio go-librespot[2171]: time="2024-07-12T22:02:10-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:11 volumio go-librespot[2171]: time="2024-07-12T22:02:11-04:00" level=debug msg="obtained new client token: AADh0FBNgfdnHpiJqXN4CP2yS/OaNl0HwWV347nwXMXavsgUPMui9T4ZyutAquuCjzfqb7sOTXThvNUqq6VbjVmZaKMKlCfBg8qmrImx2Unegi6R0z6Nfa0Z3VpXSEBEm/6ZdYojnC9K2NX6ooFlUbiAllw215zZJdplOdsAIMMo4ts/unbT61Vfydune5M1zIloKO2SQtjVXfFAM3sF+w+jNvmM2gI0YHRk3ToskfqTrEm9GybFrYOj2KUs" Jul 12 22:02:11 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:11 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:11 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:11 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:11 volumio go-librespot[2171]: time="2024-07-12T22:02:11-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:11 volumio go-librespot[2171]: time="2024-07-12T22:02:11-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:12 volumio go-librespot[2171]: time="2024-07-12T22:02:12-04:00" level=debug msg="completed challenge" Jul 12 22:02:12 volumio go-librespot[2171]: time="2024-07-12T22:02:12-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:12 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:12 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:12 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:12 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:13 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:13 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:13 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:13 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:13 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:13 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:14 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:14 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:14 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:14 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:15 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:15 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:15 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:15 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jul 12 22:02:15 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:15 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:15 volumio go-librespot[2177]: Librespot-go daemon starting... Jul 12 22:02:15 volumio go-librespot[2177]: time="2024-07-12T22:02:15-04:00" level=info msg="generated new device id: 2618e26946033c20404aa4ac1c3de62cda41dde9" Jul 12 22:02:15 volumio go-librespot[2177]: time="2024-07-12T22:02:15-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:15 volumio go-librespot[2177]: time="2024-07-12T22:02:15-04:00" level=debug msg="obtained new client token: AACNiSswfbjWzW8pmcGXyt6DM/Ts2iKrZnKaWY8nskH3O2z0j1CtdjPtNOcpJLrbibZTn2bsY11LNr+dUGuQlt9gRapMI3Z9lSJT09usLhFgB07/fAye1xAv3M3kmwL0HZrt0vmIIfKtOnuqW9nP+/EHUr/jJBqBKZ18LgOFN8vgIV5mJK0dnBtZYsfaKovW5zwJ0VNXEo/15NGZ8HgFMfiT//E14JrBt3TGQ76QyKn2L8Kwz9EHcHn+eZzIFnU=" Jul 12 22:02:15 volumio go-librespot[2177]: time="2024-07-12T22:02:15-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:15 volumio go-librespot[2177]: time="2024-07-12T22:02:15-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:16 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:16 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:16 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:16 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:16 volumio go-librespot[2177]: time="2024-07-12T22:02:16-04:00" level=debug msg="completed challenge" Jul 12 22:02:16 volumio go-librespot[2177]: time="2024-07-12T22:02:16-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:16 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:16 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:17 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:17 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:17 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:17 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:18 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:18 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:18 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:18 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:19 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:19 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:19 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:19 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jul 12 22:02:19 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:19 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:19 volumio go-librespot[2184]: Librespot-go daemon starting... Jul 12 22:02:19 volumio go-librespot[2184]: time="2024-07-12T22:02:19-04:00" level=info msg="generated new device id: d6f8d6f722c46392927e0ba1c9b7e4e59b6a7e66" Jul 12 22:02:19 volumio go-librespot[2184]: time="2024-07-12T22:02:19-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:19 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:19 volumio volumio[1442]: info: Connection to go-librespot Websocket established Jul 12 22:02:19 volumio go-librespot[2184]: time="2024-07-12T22:02:19-04:00" level=debug msg="new websocket client" Jul 12 22:02:20 volumio go-librespot[2184]: time="2024-07-12T22:02:20-04:00" level=debug msg="obtained new client token: AABEM51TKzNWjWFXoqq0vmSQuZVY6WPQqgxENR5TwwIJSPamFstVo6Z0gR0fdl0SYETSQ9uSSOGjhqWHYFZPCzCfg3urFFj3OybRBhkjea4IYI7wSW42/T/IHNAiaHm25krT+gxwplikhU8YUOgeu/gkjV3+9kQobF0hFUCVABhEK3wZOXgCXWAE4Dsrjib8SBYAuEgrVGTnMCeNBfct3mqtT0AV5rje+PLNWQUJJA/vUePwzmAiN+hAq1OUWeQ=" Jul 12 22:02:20 volumio go-librespot[2184]: time="2024-07-12T22:02:20-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:20 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:20 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:20 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:20 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:20 volumio go-librespot[2184]: time="2024-07-12T22:02:20-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:20 volumio go-librespot[2184]: time="2024-07-12T22:02:20-04:00" level=debug msg="completed challenge" Jul 12 22:02:20 volumio go-librespot[2184]: time="2024-07-12T22:02:20-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:20 volumio volumio[1442]: info: Connection to go-librespot Websocket closed Jul 12 22:02:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:21 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:21 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:21 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:21 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:22 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:22 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:22 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:22 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:22 volumio volumio[1442]: info: Getting Spotify volume Jul 12 22:02:22 volumio volumio[1442]: (node:1442) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:22 volumio volumio[1442]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 12 22:02:22 volumio volumio[1442]: (node:1442) 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) Jul 12 22:02:22 volumio volumio[1442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jul 12 22:02:22 volumio volumio[1442]: info: CoreCommandRouter::volumioGetState Jul 12 22:02:23 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:23 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:23 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:23 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:23 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:23 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jul 12 22:02:24 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:24 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:24 volumio go-librespot[2192]: Librespot-go daemon starting... Jul 12 22:02:24 volumio go-librespot[2192]: time="2024-07-12T22:02:24-04:00" level=info msg="generated new device id: 3648185ac82e8b8e39325229a8552ef8c0ab38e6" Jul 12 22:02:24 volumio go-librespot[2192]: time="2024-07-12T22:02:24-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:24 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:24 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:24 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:24 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:24 volumio go-librespot[2192]: time="2024-07-12T22:02:24-04:00" level=debug msg="obtained new client token: AABVuZXwnSBzWdkbiqFJF7pT445O/gC90UBFKRaVoA/kQA1p9HC4/e9EDXVki+gQn/f88EMBlmryjbBhkR00mOondN98+ZvIybzntYkcVHjp4hGXDh5a869+lOhrOgHaUZ7Zc4Ua6msNgDV63d0YvXwQ14e9pHz6SM6FzAKoWYaIhYqoNFwdiCbIRV9ORdc4M4pE5jWzl0YWX+Soj4yGS3ossGlCxD8mX649pHuPK4HIuFxjOCHxVv94lu4NqEQ=" Jul 12 22:02:24 volumio go-librespot[2192]: time="2024-07-12T22:02:24-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:24 volumio go-librespot[2192]: time="2024-07-12T22:02:24-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:25 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:25 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:25 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:25 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:25 volumio go-librespot[2192]: time="2024-07-12T22:02:25-04:00" level=debug msg="completed challenge" Jul 12 22:02:25 volumio go-librespot[2192]: time="2024-07-12T22:02:25-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:26 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:26 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:26 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:26 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:26 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:26 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:27 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:27 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:27 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:27 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:28 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:28 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:28 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:28 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jul 12 22:02:28 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:28 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:28 volumio go-librespot[2199]: Librespot-go daemon starting... Jul 12 22:02:28 volumio go-librespot[2199]: time="2024-07-12T22:02:28-04:00" level=info msg="generated new device id: bbce17523cc1bee948bdbbe745afb8b2fdd3aae3" Jul 12 22:02:28 volumio go-librespot[2199]: time="2024-07-12T22:02:28-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:28 volumio go-librespot[2199]: time="2024-07-12T22:02:28-04:00" level=debug msg="obtained new client token: AADnm1o15wZaI+q/TfPqojnEylrungEXlW5/XoBRlDy2iD1k+ZKl9YmDPzPOFRPse8i+02+fYH41s3XU0dTOP8ar7vn/yCoCUfh7qssBLlT+UjYgB+tDuTQFsbrkIFTLyLFxDEbRrMbSkykFen1MpkuCx8HYzn5blsPHOmr7Xj8Ydi7nrhlfb8MwoR5YN6S1OeFrR9mztjEQCJOJACTiEEwT2IHMtf23XfQTFrqonyGtwSvWfMQbf/JYJitCpRI=" Jul 12 22:02:29 volumio go-librespot[2199]: time="2024-07-12T22:02:29-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:29 volumio go-librespot[2199]: time="2024-07-12T22:02:29-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:29 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:29 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:29 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:29 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:29 volumio go-librespot[2199]: time="2024-07-12T22:02:29-04:00" level=debug msg="completed challenge" Jul 12 22:02:29 volumio go-librespot[2199]: time="2024-07-12T22:02:29-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:29 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:29 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:30 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:30 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:30 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:30 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:31 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:31 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:31 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:31 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:32 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:32 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:32 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:32 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:32 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:32 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jul 12 22:02:33 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:33 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:33 volumio go-librespot[2208]: Librespot-go daemon starting... Jul 12 22:02:33 volumio go-librespot[2208]: time="2024-07-12T22:02:33-04:00" level=info msg="generated new device id: 698138ae853df3cbc174bcf6cca06fa6e505decc" Jul 12 22:02:33 volumio go-librespot[2208]: time="2024-07-12T22:02:33-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:33 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:33 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:33 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:33 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:33 volumio go-librespot[2208]: time="2024-07-12T22:02:33-04:00" level=debug msg="obtained new client token: AAAJ6HYZedegCAAfUHrO2fRfWzm/WH6OSyWp2ZSwEGcd3xehNG4AK7Ou47wiRzwx5jguJO3IZ4kzFeYhvHeMXLV1sGJAPlANOC6ojpfx0Lu4TZldJuP4NH1e9P5npuI5rIlMoCUKmRQaioeC7DPPADFBMw5gHeyzWdno66LdwEtiu8aQbHMwrDhiTr5Y2TM0IMTTGcLT1lpr2fM7tlmgCVmZxVJaVbjxwkABKE3+8Fbaut8FBtLYg+4kBUSKgO8=" Jul 12 22:02:33 volumio go-librespot[2208]: time="2024-07-12T22:02:33-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:33 volumio go-librespot[2208]: time="2024-07-12T22:02:33-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:34 volumio go-librespot[2208]: time="2024-07-12T22:02:34-04:00" level=debug msg="completed challenge" Jul 12 22:02:34 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:34 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:34 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:34 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:34 volumio go-librespot[2208]: time="2024-07-12T22:02:34-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:35 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:35 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:35 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:35 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:35 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:35 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:36 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:36 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:36 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:36 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:37 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:37 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:37 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:37 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jul 12 22:02:37 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:37 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:37 volumio go-librespot[2215]: Librespot-go daemon starting... Jul 12 22:02:37 volumio go-librespot[2215]: time="2024-07-12T22:02:37-04:00" level=info msg="generated new device id: 742f2f719de12637248ec9199b0a5651f76ae850" Jul 12 22:02:37 volumio go-librespot[2215]: time="2024-07-12T22:02:37-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:37 volumio go-librespot[2215]: time="2024-07-12T22:02:37-04:00" level=debug msg="obtained new client token: AAAoflgqH05Zd00XK4scX2Dt93KOSAzANgOD1ZsqJowFQvRV++vkuHRnGdOygiNNmHF1PQtrmNWq7cfq5NfuIjBGfjsXWpq2dIP7M6o5nVBtMS4294Za8303y3oJq8zBQbFlvEIgQ3IH74rDCh6P3vjri9BW8eNj7FScAvUe4KFmKz4usa67pXIIy+b9E5IJhlfHJHcfJAOVLLnClArPCb0+9dVFxkxX865pTqk35c9kRO6IYV7WKLRCLyOpJ0s=" Jul 12 22:02:37 volumio go-librespot[2215]: time="2024-07-12T22:02:37-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:38 volumio go-librespot[2215]: time="2024-07-12T22:02:38-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:38 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:38 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:38 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:38 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:38 volumio go-librespot[2215]: time="2024-07-12T22:02:38-04:00" level=debug msg="completed challenge" Jul 12 22:02:38 volumio go-librespot[2215]: time="2024-07-12T22:02:38-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:38 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:38 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:39 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:39 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:39 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:39 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:40 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:40 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:40 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:40 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:41 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:41 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:41 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:41 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jul 12 22:02:41 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:41 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:41 volumio go-librespot[2222]: Librespot-go daemon starting... Jul 12 22:02:41 volumio go-librespot[2222]: time="2024-07-12T22:02:41-04:00" level=info msg="generated new device id: 1f128a752fe6e887fdaabf05b4cbf63092cb9b3f" Jul 12 22:02:41 volumio go-librespot[2222]: time="2024-07-12T22:02:41-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:41 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:41 volumio go-librespot[2222]: time="2024-07-12T22:02:41-04:00" level=debug msg="new websocket client" Jul 12 22:02:41 volumio volumio[1442]: info: Connection to go-librespot Websocket established Jul 12 22:02:42 volumio go-librespot[2222]: time="2024-07-12T22:02:42-04:00" level=debug msg="obtained new client token: AABevcshZL3wa+OaE7zi7A76o19Au9hRR2zYg+QTjQCwdUvwEfg9MJ53E3vML83nMnYKS6m0rN5E9ecYJ42WFmheYoGdcgZ8l44Ur0JSEaWZaKWE+CXNTmUPyeHUfiixqIdnBXyVVGyhqY8XbSw/lo14qtSqEFqS/EJ43S3HN7+jDBiXa4l/cNiKGUoFM4015YAfVgSDOdKnYxFgyezBBz6idsQfbeGbsef4nFrVUeE55OayLEQTKnxi4F+8" Jul 12 22:02:42 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:42 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:42 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:42 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:42 volumio go-librespot[2222]: time="2024-07-12T22:02:42-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:42 volumio go-librespot[2222]: time="2024-07-12T22:02:42-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:43 volumio go-librespot[2222]: time="2024-07-12T22:02:43-04:00" level=debug msg="completed challenge" Jul 12 22:02:43 volumio go-librespot[2222]: time="2024-07-12T22:02:43-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:43 volumio volumio[1442]: info: Connection to go-librespot Websocket closed Jul 12 22:02:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:43 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:43 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:43 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:43 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:44 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:44 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:44 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:44 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:44 volumio volumio[1442]: info: Getting Spotify volume Jul 12 22:02:45 volumio volumio[1442]: (node:1442) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:45 volumio volumio[1442]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Jul 12 22:02:45 volumio volumio[1442]: (node:1442) 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: 4) Jul 12 22:02:45 volumio volumio[1442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Jul 12 22:02:45 volumio volumio[1442]: info: CoreCommandRouter::volumioGetState Jul 12 22:02:45 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:45 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:45 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:45 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:46 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:46 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:46 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:46 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:46 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:46 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jul 12 22:02:46 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:46 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:46 volumio go-librespot[2229]: Librespot-go daemon starting... Jul 12 22:02:46 volumio go-librespot[2229]: time="2024-07-12T22:02:46-04:00" level=info msg="generated new device id: 29b223db997a5d15d9e244953eb9fc037dc20898" Jul 12 22:02:46 volumio go-librespot[2229]: time="2024-07-12T22:02:46-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:46 volumio go-librespot[2229]: time="2024-07-12T22:02:46-04:00" level=debug msg="obtained new client token: AABpaDg1L8HNBD1FkcSoWaVbtfnCB3pca99JsKxcAdrcqueC+Sua+RhmoYsn2yA1xViAbBfFiAY/1WR1C/bCB6olwqOEOntnh7fQ/gUvEZVZ6oZ3kLaweQqUohbEm0VzmQjuB5h7AZhQMSqcR7Ra7ySaUv7KDAs1vQkftEZjj2bA0D+de2iXUpnEY5Dm1JyMu66j3HKKoVGffmJBSk7zr/0lHDAK3uLmyAITWTIOXf9sVGJ7LH9+YkTU7Ol7r3U=" Jul 12 22:02:46 volumio go-librespot[2229]: time="2024-07-12T22:02:46-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 12 22:02:46 volumio go-librespot[2229]: time="2024-07-12T22:02:46-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:47 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:47 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:47 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:47 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:47 volumio go-librespot[2229]: time="2024-07-12T22:02:47-04:00" level=debug msg="completed challenge" Jul 12 22:02:47 volumio go-librespot[2229]: time="2024-07-12T22:02:47-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:48 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:48 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:48 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:48 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:49 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:49 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:49 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:49 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:49 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:49 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:50 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:50 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:50 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:50 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:50 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jul 12 22:02:50 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:50 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:50 volumio go-librespot[2236]: Librespot-go daemon starting... Jul 12 22:02:50 volumio go-librespot[2236]: time="2024-07-12T22:02:50-04:00" level=info msg="generated new device id: 64b70c7da04cc002d9215b62519917c3054f2d20" Jul 12 22:02:50 volumio go-librespot[2236]: time="2024-07-12T22:02:50-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:51 volumio go-librespot[2236]: time="2024-07-12T22:02:51-04:00" level=debug msg="obtained new client token: AAC2NlhxAAakJvizRUPHl3Xq4qKdM68/+DGqgEzgwjVFzv/UkDtSJbgt64RNsNU7MkIigFnGxHOL/T6juHxFTuPUE2ZVCqk3adfJxjOSU3FZUP6+sZxQMQ4LWw0NszIITjWep29ZEv7T1c5ZXDhmP7d3Z38WvA61f51DI3PfH6c37qAnjVVu3EeJNXpLCo8et0QjOGYdP6WDHMwOCP4k4a201qY7vBS7btX1xOQ0vcCZc6RfPDFRqbMvkYW5joI=" Jul 12 22:02:51 volumio go-librespot[2236]: time="2024-07-12T22:02:51-04:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 12 22:02:51 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:51 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:51 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:51 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:51 volumio go-librespot[2236]: time="2024-07-12T22:02:51-04:00" level=debug msg="completed keyexchange" Jul 12 22:02:51 volumio go-librespot[2236]: time="2024-07-12T22:02:51-04:00" level=debug msg="completed challenge" Jul 12 22:02:51 volumio go-librespot[2236]: time="2024-07-12T22:02:51-04:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: TravelRestriction" Jul 12 22:02:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 12 22:02:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 12 22:02:52 volumio volumio[1442]: info: Initializing connection to go-librespot Websocket Jul 12 22:02:52 volumio volumio[1442]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 12 22:02:52 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:52 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:52 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:52 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:53 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:53 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:53 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:53 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:54 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:54 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:54 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:54 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:54 volumio volumio[1442]: error: [now-playing] Error fetching https://openweathermap.org: FetchError: request to https://openweathermap.org/ failed, reason: connect ENETUNREACH 10.0.0.1:443 Jul 12 22:02:54 volumio volumio[1442]: at ClientRequest. (/data/plugins/user_interface/now_playing/node_modules/node-fetch/lib/index.js:1505:11) Jul 12 22:02:54 volumio volumio[1442]: at ClientRequest.emit (events.js:315:20) Jul 12 22:02:54 volumio volumio[1442]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Jul 12 22:02:54 volumio volumio[1442]: at TLSSocket.emit (events.js:315:20) Jul 12 22:02:54 volumio volumio[1442]: at emitErrorNT (internal/streams/destroy.js:106:8) Jul 12 22:02:54 volumio volumio[1442]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Jul 12 22:02:54 volumio volumio[1442]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 12 22:02:54 volumio volumio[1442]: (node:1442) UnhandledPromiseRejectionWarning: FetchError: request to https://openweathermap.org/ failed, reason: connect ENETUNREACH 10.0.0.1:443 Jul 12 22:02:54 volumio volumio[1442]: at ClientRequest. (/data/plugins/user_interface/now_playing/node_modules/node-fetch/lib/index.js:1505:11) Jul 12 22:02:54 volumio volumio[1442]: at ClientRequest.emit (events.js:315:20) Jul 12 22:02:54 volumio volumio[1442]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Jul 12 22:02:54 volumio volumio[1442]: at TLSSocket.emit (events.js:315:20) Jul 12 22:02:54 volumio volumio[1442]: at emitErrorNT (internal/streams/destroy.js:106:8) Jul 12 22:02:54 volumio volumio[1442]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Jul 12 22:02:54 volumio volumio[1442]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 12 22:02:54 volumio volumio[1442]: (node:1442) 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: 7) Jul 12 22:02:54 volumio volumio[1442]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 12 22:02:54 volumio volumio[1442]: Error: connect ENETUNREACH 10.0.0.1:80 Jul 12 22:02:54 volumio volumio[1442]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Jul 12 22:02:54 volumio volumio[1442]: errno: -101, Jul 12 22:02:54 volumio volumio[1442]: code: 'ENETUNREACH', Jul 12 22:02:54 volumio volumio[1442]: syscall: 'connect', Jul 12 22:02:54 volumio volumio[1442]: address: '10.0.0.1', Jul 12 22:02:54 volumio volumio[1442]: port: 80 Jul 12 22:02:54 volumio volumio[1442]: } Jul 12 22:02:54 volumio volumio[1442]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 12 22:02:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 12 22:02:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jul 12 22:02:55 volumio systemd[1]: Stopped go-librespot Daemon. Jul 12 22:02:55 volumio go-librespot[2252]: Librespot-go daemon starting... Jul 12 22:02:55 volumio systemd[1]: Started go-librespot Daemon. Jul 12 22:02:55 volumio go-librespot[2252]: time="2024-07-12T22:02:55-04:00" level=info msg="generated new device id: 73f04a735df4f2f2adbc48b0f9d503df2c5f3348" Jul 12 22:02:55 volumio go-librespot[2252]: time="2024-07-12T22:02:55-04:00" level=debug msg="stored credentials found for maximtms" Jul 12 22:02:55 volumio lircd[1945]: lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:55 volumio lircd[1945]: lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:55 volumio lircd-0.10.1[1945]: Error: could not get file information for /dev/lirc0 Jul 12 22:02:55 volumio lircd-0.10.1[1945]: default_init(): No such file or directory Jul 12 22:02:55 volumio sudo[2260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-12 22:01 Jul 12 22:02:55 volumio sudo[2260]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 12 22:02:55 volumio go-librespot[2252]: time="2024-07-12T22:02:55-04:00" level=debug msg="obtained new client token: AACNoPnHJ6Jc888uk27+lAklWy8r/gpCHI00VS3EXDbOCah9Xil5zZZP3CtW5eKlajAKTh0fnGeh6xQ4rdCFSZlZW9YYGsKOEOWl4frevWhd2M8ktsG5q2EbVSSgYx9bSNeq03qbu0+HvLBW1KOrVjcgqb/jSyHuVVoa0bu50bdUonjLYVqz82o4YNrvHzJ4vUAfMo+ZW7yi77YFiDrfQuw+24fhVDKGYQYoYm5AJmyaIidl6819k515rNaaIio=" 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="f8baf7ad070f376535a93fcc6590774528ddb153" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="0e3cf2fcfe1906c5090fab62b4cc2a5ff0069fd8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 30 Jan 2024 03:58:37 PM CET" VOLUMIO_VERSION="3.611" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="1d6379ebb89c40061afa8aee78176887"