May 25 07:56:00 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:00 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791465. May 25 07:56:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:01 volumio go-librespot[17063]: go-librespot daemon starting... May 25 07:56:01 volumio go-librespot[17064]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:03 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:03 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791466. May 25 07:56:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:04 volumio go-librespot[17079]: go-librespot daemon starting... May 25 07:56:04 volumio go-librespot[17080]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:06 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:06 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791467. May 25 07:56:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:07 volumio go-librespot[17081]: go-librespot daemon starting... May 25 07:56:07 volumio go-librespot[17082]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:09 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:09 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791468. May 25 07:56:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:10 volumio go-librespot[17084]: go-librespot daemon starting... May 25 07:56:10 volumio go-librespot[17085]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:12 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:12 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791469. May 25 07:56:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:14 volumio go-librespot[17100]: go-librespot daemon starting... May 25 07:56:14 volumio go-librespot[17101]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:15 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:15 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791470. May 25 07:56:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:17 volumio go-librespot[17103]: go-librespot daemon starting... May 25 07:56:17 volumio go-librespot[17104]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:18 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:18 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791471. May 25 07:56:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:20 volumio go-librespot[17106]: go-librespot daemon starting... May 25 07:56:20 volumio go-librespot[17107]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:21 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:21 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791472. May 25 07:56:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:23 volumio go-librespot[17122]: go-librespot daemon starting... May 25 07:56:23 volumio go-librespot[17123]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:24 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:24 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791473. May 25 07:56:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:27 volumio go-librespot[17124]: go-librespot daemon starting... May 25 07:56:27 volumio go-librespot[17125]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:27 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:27 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791474. May 25 07:56:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:30 volumio go-librespot[17126]: go-librespot daemon starting... May 25 07:56:30 volumio go-librespot[17127]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:30 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:30 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791475. May 25 07:56:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:33 volumio go-librespot[17128]: go-librespot daemon starting... May 25 07:56:33 volumio go-librespot[17129]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:33 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:33 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791476. May 25 07:56:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:36 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:36 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:36 volumio go-librespot[17145]: go-librespot daemon starting... May 25 07:56:36 volumio go-librespot[17146]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:39 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:39 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791477. May 25 07:56:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:40 volumio go-librespot[17149]: go-librespot daemon starting... May 25 07:56:40 volumio go-librespot[17150]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:42 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:42 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791478. May 25 07:56:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:43 volumio go-librespot[17151]: go-librespot daemon starting... May 25 07:56:43 volumio go-librespot[17152]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:45 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:45 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791479. May 25 07:56:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:46 volumio go-librespot[17167]: go-librespot daemon starting... May 25 07:56:46 volumio go-librespot[17168]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:48 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:48 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791480. May 25 07:56:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:49 volumio go-librespot[17170]: go-librespot daemon starting... May 25 07:56:49 volumio go-librespot[17171]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:51 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:51 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791481. May 25 07:56:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:53 volumio go-librespot[17172]: go-librespot daemon starting... May 25 07:56:53 volumio go-librespot[17173]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:54 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:54 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791482. May 25 07:56:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:56 volumio go-librespot[17190]: go-librespot daemon starting... May 25 07:56:56 volumio go-librespot[17191]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:56:57 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:56:57 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:56:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791483. May 25 07:56:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:56:59 volumio go-librespot[17193]: go-librespot daemon starting... May 25 07:56:59 volumio go-librespot[17194]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:56:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:56:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:00 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:00 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791484. May 25 07:57:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:02 volumio go-librespot[17195]: go-librespot daemon starting... May 25 07:57:02 volumio go-librespot[17196]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:57:02 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 25 07:57:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:57:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:03 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. May 25 07:57:03 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 25 07:57:03 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:03 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:05 volumio kernel: usb 3-2: USB disconnect, device number 17 May 25 07:57:05 volumio volumio[28159]: info: [1779721025170] ControllerPandora::pandoraListener May 25 07:57:05 volumio volumio[28159]: info: ControllerMpd::getState May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand status May 25 07:57:05 volumio volumio[28159]: info: May 25 07:57:05 volumio volumio[28159]: ---------------------------- MPD announces state update: player May 25 07:57:05 volumio volumio[28159]: info: ControllerMpd::getState May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand status May 25 07:57:05 volumio volumio[28159]: error: MPD returned error for command status: Failed to open audio output May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand clearerror May 25 07:57:05 volumio volumio[28159]: info: sendMpdCommand status took 3 milliseconds May 25 07:57:05 volumio volumio[28159]: error: MPD returned error for command status: Failed to open audio output May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand clearerror May 25 07:57:05 volumio volumio[28159]: info: sendMpdCommand status took 2 milliseconds May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::parseState May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::parseState May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 25 07:57:05 volumio volumio[28159]: info: sendMpdCommand clearerror took 3 milliseconds May 25 07:57:05 volumio volumio[28159]: info: sendMpdCommand clearerror took 3 milliseconds May 25 07:57:05 volumio volumio[28159]: info: sendMpdCommand playlistinfo took 1 milliseconds May 25 07:57:05 volumio volumio[28159]: info: sendMpdCommand playlistinfo took 1 milliseconds May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::parseTrackInfo May 25 07:57:05 volumio volumio[28159]: verbose: ControllerMpd::parseTrackInfo May 25 07:57:05 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:05 volumio volumio[28159]: info: [1779721025176] ControllerPandora::pushState May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::servicePushState May 25 07:57:05 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:05 volumio volumio[28159]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received pandora May 25 07:57:05 volumio volumio[28159]: info: CoreStateMachine::setConsumeUpdateService mpd May 25 07:57:05 volumio volumio[28159]: info: ControllerMpd::pushState May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::servicePushState May 25 07:57:05 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:05 volumio volumio[28159]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":238169,"duration":491,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Of Dreams To Come","artist":"Robert Glasper","album":"In My Element","uri":"http://audio-usc-mp1-t2-2-v4v6.pandora.com/access/268871258832685024.mp3?version=5&lid=561256729&token=1oFjpkT7imrXIismMsnho%2FpctaymQ5a%2FbZrTfFaV9K%2B0aP%2FJZlwy2U1tH%2BB1Q64PFu1kgKSj00ii%2Bu0TvI1XQyfYjZVTGpMfEh%2FKm9SjV8FZY9EijlEcFFEW%2F0P09Vc8i3LrF2xcrIdZxVZVWAAMNFiQtzgLU7b6In1mRCyRHty8jPQQWRLGKaB1kJqvdw4GzNqfk0xSDHy35G%2FFpOcs1buY9TGLFfpcllg0loXlizJeiM8vjweyLNI5WHHGlWt1fl0KxMh8H8mdCb3rQLtr3aTIZ6IAxZTSZFOy2sc90LQG%2FdJYY5K50yYUlkXM0vYI%2BZNi0ysWcc3XYWRaHArXDw%3D%3D","trackType":""} May 25 07:57:05 volumio volumio[28159]: verbose: CURRENT POSITION 1 May 25 07:57:05 volumio volumio[28159]: info: CoreStateMachine::syncState stateService pause May 25 07:57:05 volumio volumio[28159]: info: CoreStateMachine::syncState currentStatus play May 25 07:57:05 volumio volumio[28159]: info: CoreStateMachine::pushState May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::volumioPushState May 25 07:57:05 volumio volumio[28159]: info: MRS: Pushing multiroomSync output update for this device May 25 07:57:05 volumio volumio[28159]: info: MRS: Pushing multiroomSync output May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:05 volumio volumio[28159]: info: CoreStateMachine::stPlaybackTimer May 25 07:57:05 volumio volumio[28159]: info: ------------------------------ 12ms May 25 07:57:05 volumio volumio[28159]: info: touch_display: Setting screensaver timeout to 120 seconds. May 25 07:57:05 volumio volumio[28159]: info: May 25 07:57:05 volumio volumio[28159]: ---------------------------- USB Audio Device Detached May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 25 07:57:05 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: raat , onStop May 25 07:57:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791485. May 25 07:57:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:06 volumio go-librespot[17250]: go-librespot daemon starting... May 25 07:57:06 volumio go-librespot[17251]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:57:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:57:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:06 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:06 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791486. May 25 07:57:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:09 volumio go-librespot[17252]: go-librespot daemon starting... May 25 07:57:09 volumio go-librespot[17253]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:57:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:57:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:09 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:09 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791487. May 25 07:57:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:12 volumio go-librespot[17255]: go-librespot daemon starting... May 25 07:57:12 volumio go-librespot[17256]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:57:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:57:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:12 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:12 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:15 volumio kernel: usb 3-2: new high-speed USB device number 18 using xhci-hcd May 25 07:57:15 volumio kernel: usb 3-2: New USB device found, idVendor=17ae, idProduct=000d, bcdDevice= 1.19 May 25 07:57:15 volumio kernel: usb 3-2: New USB device strings: Mfr=1, Product=3, SerialNumber=2 May 25 07:57:15 volumio kernel: usb 3-2: Product: NAD USB Audio May 25 07:57:15 volumio kernel: usb 3-2: Manufacturer: NAD May 25 07:57:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791488. May 25 07:57:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:15 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:15 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:15 volumio go-librespot[17272]: go-librespot daemon starting... May 25 07:57:15 volumio go-librespot[17273]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:57:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:57:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:16 volumio kernel: hid-generic 0003:17AE:000D.0018: hiddev96,hidraw1: USB HID v1.10 Device [NAD NAD USB Audio] on usb-xhci-hcd.1-2/input3 May 25 07:57:16 volumio volumio[28159]: info: May 25 07:57:16 volumio volumio[28159]: ---------------------------- USB Audio Device Attached May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::Close All Modals sent May 25 07:57:16 volumio volumio[28159]: info: Preparing to save Alsa Options, stopping services first May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioPause May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::pause May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::stPlaybackTimer May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::servicePause May 25 07:57:16 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::servicePause May 25 07:57:16 volumio volumio[28159]: info: [1779721036878] ControllerPandora::pause May 25 07:57:16 volumio volumio[28159]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"NAD USB Audio","alsacard":"Audio"},"i2s":false} May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 25 07:57:16 volumio volumio[28159]: info: Device 5 does not have any Mixer Control Available May 25 07:57:16 volumio volumio[28159]: info: QobuzConnect: setDeactiveState invoked May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:16 volumio vtcs[15382]: [2026-05-25 07:57:16.910] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 25 07:57:16 volumio vtcs[15382]: [2026-05-25 07:57:16.913] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 25 07:57:16 volumio sudo[17296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 25 07:57:16 volumio sudo[17296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 25 07:57:16 volumio volumio[28159]: info: Updating Volume Controller Parameters: Device: 5 Name: NAD USB Audio Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 25 07:57:16 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 25 07:57:16 volumio volumio[28159]: info: Disabling external Volume Control May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 07:57:16 volumio systemd[1]: vtcs.service: Deactivated successfully. May 25 07:57:16 volumio volumio[28159]: info: ControllerMpd::pause May 25 07:57:16 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand pause May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::pushState May 25 07:57:16 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioPushState May 25 07:57:16 volumio volumio[28159]: info: MRS: Pushing multiroomSync output update for this device May 25 07:57:16 volumio volumio[28159]: info: MRS: Pushing multiroomSync output May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:16 volumio volumio[28159]: info: Preparing to generate the ALSA configuration file May 25 07:57:16 volumio sudo[17296]: pam_unix(sudo:session): session closed for user root May 25 07:57:16 volumio sudo[17304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 25 07:57:16 volumio sudo[17304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:16 volumio volumio[28159]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 25 07:57:16 volumio volumio[28159]: info: Reading ALSA contributions from plugins. May 25 07:57:16 volumio volumio[28159]: info: May 25 07:57:16 volumio volumio[28159]: ---------------------------- MPD announces state update: player May 25 07:57:16 volumio volumio[28159]: info: sendMpdCommand pause took 46 milliseconds May 25 07:57:16 volumio volumio[28159]: info: ControllerMpd::getState May 25 07:57:16 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand status May 25 07:57:16 volumio volumio[28159]: info: [1779721036980] ControllerPandora::pushState May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::servicePushState May 25 07:57:16 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:16 volumio volumio[28159]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received pandora May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::setConsumeUpdateService mpd May 25 07:57:16 volumio sudo[17311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 25 07:57:16 volumio volumio[28159]: info: sendMpdCommand status took 2 milliseconds May 25 07:57:16 volumio volumio[28159]: verbose: ControllerMpd::parseState May 25 07:57:16 volumio volumio[28159]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 25 07:57:16 volumio volumio[28159]: info: sendMpdCommand playlistinfo took 1 milliseconds May 25 07:57:16 volumio volumio[28159]: verbose: ControllerMpd::parseTrackInfo May 25 07:57:16 volumio volumio[28159]: info: ControllerMpd::pushState May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::servicePushState May 25 07:57:16 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:16 volumio volumio[28159]: verbose: STATE SERVICE {"status":"play","position":0,"seek":239430,"duration":491,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Of Dreams To Come","artist":"Robert Glasper","album":"In My Element","uri":"http://audio-usc-mp1-t2-2-v4v6.pandora.com/access/268871258832685024.mp3?version=5&lid=561256729&token=1oFjpkT7imrXIismMsnho%2FpctaymQ5a%2FbZrTfFaV9K%2B0aP%2FJZlwy2U1tH%2BB1Q64PFu1kgKSj00ii%2Bu0TvI1XQyfYjZVTGpMfEh%2FKm9SjV8FZY9EijlEcFFEW%2F0P09Vc8i3LrF2xcrIdZxVZVWAAMNFiQtzgLU7b6In1mRCyRHty8jPQQWRLGKaB1kJqvdw4GzNqfk0xSDHy35G%2FFpOcs1buY9TGLFfpcllg0loXlizJeiM8vjweyLNI5WHHGlWt1fl0KxMh8H8mdCb3rQLtr3aTIZ6IAxZTSZFOy2sc90LQG%2FdJYY5K50yYUlkXM0vYI%2BZNi0ysWcc3XYWRaHArXDw%3D%3D","trackType":""} May 25 07:57:16 volumio volumio[28159]: verbose: CURRENT POSITION 1 May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::syncState stateService play May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::syncState currentStatus pause May 25 07:57:16 volumio volumio[28159]: info: CoreStateMachine::pushState May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioPushState May 25 07:57:16 volumio sudo[17311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:16 volumio volumio[28159]: info: MRS: Pushing multiroomSync output update for this device May 25 07:57:16 volumio volumio[28159]: info: MRS: Pushing multiroomSync output May 25 07:57:16 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:16 volumio volumio[28159]: info: ------------------------------ 8ms May 25 07:57:16 volumio sudo[17304]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio sudo[17311]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio sudo[17314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 25 07:57:17 volumio sudo[17314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 25 07:57:17 volumio qobuz-connect[15346]: 20260525 07:57:17.030 [15346.15346] INFO SampleApp: Stopping Local configuration server May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 25 07:57:17 volumio volumio[28159]: info: Asound.conf file unchanged, so no further update is needed May 25 07:57:17 volumio volumio[28159]: info: Output device has changed, restarting MPD May 25 07:57:17 volumio volumio[28159]: info: Output device has changed, restarting Shairport Sync May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 07:57:17 volumio sudo[17323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 25 07:57:17 volumio sudo[17323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio sudo[17327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 25 07:57:17 volumio sudo[17327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio sudo[17323]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio volumio[28159]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 25 07:57:17 volumio volumio[28159]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: QobuzConnect: setDeactiveState invoked May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:17 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 25 07:57:17 volumio sudo[17335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 25 07:57:17 volumio sudo[17335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio sudo[17338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 25 07:57:17 volumio sudo[17338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio volumio[28159]: info: MPD Permissions set May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 25 07:57:17 volumio sudo[17338]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio sudo[17345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 25 07:57:17 volumio sudo[17345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio sudo[17335]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio sudo[17345]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio volumio[28159]: info: Starting Shairport Sync May 25 07:57:17 volumio sudo[17354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 25 07:57:17 volumio sudo[17354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio sudo[17356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 25 07:57:17 volumio sudo[17356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 25 07:57:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 25 07:57:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 25 07:57:17 volumio systemd[1]: shairport-sync.service: Consumed 2.354s CPU time. May 25 07:57:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 25 07:57:17 volumio sudo[17356]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio volumio[28159]: info: Shairport-Sync Started May 25 07:57:17 volumio systemd[1]: mpd.service: Deactivated successfully. May 25 07:57:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 25 07:57:17 volumio systemd[1]: mpd.service: Consumed 5.320s CPU time. May 25 07:57:17 volumio systemd[1]: mpd.socket: Deactivated successfully. May 25 07:57:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 25 07:57:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 25 07:57:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 25 07:57:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 25 07:57:17 volumio sudo[17375]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 25 07:57:17 volumio sudo[17375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 25 07:57:17 volumio sudo[17375]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat May 25 07:57:17 volumio qobuz-connect[15346]: 20260525 07:57:17.657 [15346.15346] INFO SampleApp: shat down connection on UNIX socket May 25 07:57:17 volumio volumio[28159]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 25 07:57:17 volumio volumio[28159]: info: QobuzConnect: setDeactiveState invoked May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:17 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. May 25 07:57:17 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 25 07:57:17 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 25 07:57:17 volumio sudo[17314]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio sudo[17354]: pam_unix(sudo:session): session closed for user root May 25 07:57:17 volumio volumio[28159]: info: Executing endpoint qc_getconfig May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.709 [17378.17378] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 25 07:57:17 volumio volumio[28159]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.710 [17378.17378] INFO VolumeManager: [0x17020e8]: Setting new playback volume: 75 May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.710 [17378.17378] INFO VolumeManager: [0x17020e8]: Setting new mute state: 0 May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.710 [17378.17378] INFO AudioStreamManager: [0x1701e40]: Setting new audio download buffer size: 1048576 May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.710 [17378.17378] INFO QobuzConnect: [0x17029b0]: Client initialized! May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.710 [17378.17378] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp May 25 07:57:17 volumio mpd[17377]: 2026-05-25T07:57:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 25 07:57:17 volumio volumio[28159]: info: QobuzConnect: QOBUZ Connect daemon connected May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.717 [17378.17378] INFO LocalConfigManager: [0x1701b68]: Starting Local Configuration server May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.717 [17378.17378] INFO SampleApp: Starting Local configuration server May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.718 [17378.17378] INFO SampleApp: Connected to UNIX socket client 0x16ec818 May 25 07:57:17 volumio qobuz-connect[17378]: 20260525 07:57:17.858 [17378.17378] INFO SampleApp: Playback volume changed: 75 May 25 07:57:17 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:18 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 25 07:57:18 volumio sudo[17327]: pam_unix(sudo:session): session closed for user root May 25 07:57:18 volumio volumio[28159]: error: updateQueue error: null May 25 07:57:18 volumio volumio[28159]: info: CorePlayQueue::getQueue May 25 07:57:18 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:18 volumio volumio[28159]: info: [1779721038724] ControllerPandora::ExpireOldTracks::reaper May 25 07:57:18 volumio volumio[28159]: info: [1779721038724] [Pandora] ExpireOldTracks::reaper: No victims found: Expiring zero tracks. Don't worry -- Jason will return. May 25 07:57:18 volumio volumio[28159]: info: Initializing connection to go-librespot Websocket May 25 07:57:18 volumio volumio[28159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 25 07:57:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 791489. May 25 07:57:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 25 07:57:19 volumio go-librespot[17387]: go-librespot daemon starting... May 25 07:57:19 volumio go-librespot[17388]: /bin/start-go-librespot.sh: 7: /usr/bin/go-librespot: not found May 25 07:57:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a May 25 07:57:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 25 07:57:19 volumio volumio[28159]: info: TidalConnect service stoped! May 25 07:57:19 volumio volumio[28159]: info: TidalConnect service stoped! May 25 07:57:20 volumio volumio[28159]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 25 07:57:20 volumio volumio[28159]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 25 07:57:20 volumio sudo[17400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 25 07:57:20 volumio sudo[17400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 25 07:57:20 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. May 25 07:57:20 volumio sudo[17400]: pam_unix(sudo:session): session closed for user root May 25 07:57:20 volumio volumio[28159]: info: TidalConnect service stoped! May 25 07:57:20 volumio volumio[28159]: info: Executing endpoint tc_getconfig May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 25 07:57:20 volumio vtcs[17403]: STARTING TidalConnect services, version: 1.6.1 May 25 07:57:20 volumio vtcs[17403]: STARTED TidalConnect services. May 25 07:57:20 volumio volumio[28159]: info: TidalConnect service stoped! May 25 07:57:20 volumio volumio[28159]: info: Executing endpoint tc_connect May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 25 07:57:20 volumio volumio[28159]: info: Connecting to TidalConnect May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::servicePushState May 25 07:57:20 volumio volumio[28159]: info: CoreStateMachine::pushState May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::volumioPushState May 25 07:57:20 volumio volumio[28159]: info: MRS: Pushing multiroomSync output update for this device May 25 07:57:20 volumio volumio[28159]: info: MRS: Pushing multiroomSync output May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:20 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:20 volumio volumio[28159]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::servicePushState May 25 07:57:20 volumio volumio[28159]: info: CoreStateMachine::pushState May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::volumioPushState May 25 07:57:20 volumio volumio[28159]: info: MRS: Pushing multiroomSync output update for this device May 25 07:57:20 volumio volumio[28159]: info: MRS: Pushing multiroomSync output May 25 07:57:20 volumio volumio[28159]: info: CoreCommandRouter::volumioGetState May 25 07:57:20 volumio volumio[28159]: info: CorePlayQueue::getTrack 1 May 25 07:57:20 volumio volumio[28159]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 25 07:57:20 volumio volumio[28159]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 25 07:57:20 volumio volumio[28159]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 25 07:57:20 volumio volumio[28159]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 07:57:20 volumio volumio[28159]: Error: ENOENT: no such file or directory, unlink '/tmp/F3XO870U3pxVDQ5S15WpxvBMPSkKHrJzBig2XgQ3aSKzkE2Th1WRDNvWq12jETS7TNLQMQ5zH2yCvZhX6HNDnFQO2oYFhtSjnX7h' May 25 07:57:20 volumio volumio[28159]: at Object.unlinkSync (node:fs:1899:3) May 25 07:57:20 volumio volumio[28159]: at ControllerTidalconnect.deleteCertificate (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:11265) May 25 07:57:20 volumio volumio[28159]: at TidalConnectClient. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:2774) May 25 07:57:20 volumio volumio[28159]: at TidalConnectClient.emit (node:events:514:28) May 25 07:57:20 volumio volumio[28159]: at TidalConnectClient.parseData (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:44713) May 25 07:57:20 volumio volumio[28159]: at /myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41683 May 25 07:57:20 volumio volumio[28159]: at Array.forEach () May 25 07:57:20 volumio volumio[28159]: at Socket. (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:41561) May 25 07:57:20 volumio volumio[28159]: at Socket.emit (node:events:514:28) May 25 07:57:20 volumio volumio[28159]: at addChunk (node:internal/streams/readable:343:12) May 25 07:57:20 volumio volumio[28159]: at readableAddChunk (node:internal/streams/readable:316:9) May 25 07:57:20 volumio volumio[28159]: at Readable.push (node:internal/streams/readable:253:10) May 25 07:57:20 volumio volumio[28159]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) { May 25 07:57:20 volumio volumio[28159]: errno: -2, May 25 07:57:20 volumio volumio[28159]: syscall: 'unlink', May 25 07:57:20 volumio volumio[28159]: code: 'ENOENT', May 25 07:57:20 volumio volumio[28159]: path: '/tmp/F3XO870U3pxVDQ5S15WpxvBMPSkKHrJzBig2XgQ3aSKzkE2Th1WRDNvWq12jETS7TNLQMQ5zH2yCvZhX6HNDnFQO2oYFhtSjnX7h' May 25 07:57:20 volumio volumio[28159]: } May 25 07:57:20 volumio volumio[28159]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 07:57:20 volumio sudo[17441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-25 07:56' May 25 07:57:20 volumio sudo[17441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"