-- Logs begin at Mon 2024-07-22 14:21:29 BST, end at Thu 2025-12-11 14:11:20 GMT. --
Dec 11 14:10:00 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:00 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:02 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:02 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Dec 11 14:10:02 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:03 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:03 arpal go-librespot[2013]: go-librespot daemon starting...
Dec 11 14:10:03 arpal go-librespot[2013]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:03 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:03 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:03 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:03 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:06 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:06 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35.
Dec 11 14:10:06 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:06 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:06 arpal go-librespot[2015]: go-librespot daemon starting...
Dec 11 14:10:06 arpal go-librespot[2015]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:06 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:06 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:06 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:06 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:09 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:09 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36.
Dec 11 14:10:09 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:09 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:09 arpal go-librespot[2017]: go-librespot daemon starting...
Dec 11 14:10:09 arpal go-librespot[2017]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:09 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:09 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:09 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:09 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:12 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:12 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37.
Dec 11 14:10:12 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:12 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:12 arpal go-librespot[2019]: go-librespot daemon starting...
Dec 11 14:10:12 arpal go-librespot[2019]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:12 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:12 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:12 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:12 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:13 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Dec 11 14:10:13 arpal volumio[1079]: info: CURURI: artists://
Dec 11 14:10:13 arpal volumio[1079]: info: Preload queue cleared
Dec 11 14:10:15 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:15 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:15 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:15 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38.
Dec 11 14:10:15 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:16 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:16 arpal go-librespot[2022]: go-librespot daemon starting...
Dec 11 14:10:16 arpal go-librespot[2022]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:16 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:16 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:18 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:18 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:19 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:19 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39.
Dec 11 14:10:19 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:19 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:19 arpal go-librespot[2025]: go-librespot daemon starting...
Dec 11 14:10:19 arpal go-librespot[2025]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:19 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:19 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:21 arpal volumio[1079]: Searching plugin music_service/mpd
Dec 11 14:10:21 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Dec 11 14:10:21 arpal volumio[1079]: info: All search sources collected, pushing search results
Dec 11 14:10:21 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:21 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:22 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:22 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40.
Dec 11 14:10:22 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:22 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:22 arpal go-librespot[2027]: go-librespot daemon starting...
Dec 11 14:10:22 arpal go-librespot[2027]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:22 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:22 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:23 arpal volumio[1079]: Searching plugin music_service/mpd
Dec 11 14:10:23 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Dec 11 14:10:24 arpal volumio[1079]: info: All search sources collected, pushing search results
Dec 11 14:10:24 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:24 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:25 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:25 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41.
Dec 11 14:10:25 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:25 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:25 arpal go-librespot[2029]: go-librespot daemon starting...
Dec 11 14:10:25 arpal go-librespot[2029]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:25 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:25 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:27 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:27 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:28 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:28 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42.
Dec 11 14:10:28 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:29 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:29 arpal go-librespot[2031]: go-librespot daemon starting...
Dec 11 14:10:29 arpal go-librespot[2031]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:29 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:29 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:30 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:30 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:32 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:32 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43.
Dec 11 14:10:32 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:32 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:32 arpal go-librespot[2033]: go-librespot daemon starting...
Dec 11 14:10:32 arpal go-librespot[2033]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:32 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:32 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:33 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:33 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:34 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Dec 11 14:10:34 arpal volumio[1079]: info: CURURI: albums://Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)
Dec 11 14:10:34 arpal volumio[1079]: info: Preload queue cleared
Dec 11 14:10:34 arpal volumio[1079]: info: Preloading song: music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Preloading song: music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-02 Les Chants Magnétiques, Pt. 2.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Preloading song: music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-03 Les Chants Magnétiques, Pt. 3.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Preloading song: music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-04 Les Chants Magnétiques, Pt. 4.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Preloading song: music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-05 Les Chants Magnétiques, Pt. 5.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Exploding uri music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a in service mpd
Dec 11 14:10:34 arpal volumio[1079]: info: ALBUMART /albumart?cacheid=869&web=Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)/extralarge&path=%2Fmnt%2FNAS%2FARNAS%2FMusic%2FJean-Michel%20Jarre%2FMagnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)%2F1-01%20Les%20Chants%20Magn%C3%A9tiques%2C%20Pt.%201.m4a&metadata=false
Dec 11 14:10:34 arpal volumio[1079]: info: URI /mnt/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Exploding uri music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-02 Les Chants Magnétiques, Pt. 2.m4a in service mpd
Dec 11 14:10:34 arpal volumio[1079]: info: ALBUMART /albumart?cacheid=869&web=Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)/extralarge&path=%2Fmnt%2FNAS%2FARNAS%2FMusic%2FJean-Michel%20Jarre%2FMagnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)%2F1-02%20Les%20Chants%20Magn%C3%A9tiques%2C%20Pt.%202.m4a&metadata=false
Dec 11 14:10:34 arpal volumio[1079]: info: URI /mnt/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-02 Les Chants Magnétiques, Pt. 2.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Exploding uri music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-03 Les Chants Magnétiques, Pt. 3.m4a in service mpd
Dec 11 14:10:34 arpal volumio[1079]: info: ALBUMART /albumart?cacheid=869&web=Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)/extralarge&path=%2Fmnt%2FNAS%2FARNAS%2FMusic%2FJean-Michel%20Jarre%2FMagnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)%2F1-03%20Les%20Chants%20Magn%C3%A9tiques%2C%20Pt.%203.m4a&metadata=false
Dec 11 14:10:34 arpal volumio[1079]: info: URI /mnt/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-03 Les Chants Magnétiques, Pt. 3.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Exploding uri music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-04 Les Chants Magnétiques, Pt. 4.m4a in service mpd
Dec 11 14:10:34 arpal volumio[1079]: info: ALBUMART /albumart?cacheid=869&web=Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)/extralarge&path=%2Fmnt%2FNAS%2FARNAS%2FMusic%2FJean-Michel%20Jarre%2FMagnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)%2F1-04%20Les%20Chants%20Magn%C3%A9tiques%2C%20Pt.%204.m4a&metadata=false
Dec 11 14:10:34 arpal volumio[1079]: info: URI /mnt/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-04 Les Chants Magnétiques, Pt. 4.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: Exploding uri music-library/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-05 Les Chants Magnétiques, Pt. 5.m4a in service mpd
Dec 11 14:10:34 arpal volumio[1079]: info: ALBUMART /albumart?cacheid=869&web=Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)/extralarge&path=%2Fmnt%2FNAS%2FARNAS%2FMusic%2FJean-Michel%20Jarre%2FMagnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)%2F1-05%20Les%20Chants%20Magn%C3%A9tiques%2C%20Pt.%205.m4a&metadata=false
Dec 11 14:10:34 arpal volumio[1079]: info: URI /mnt/NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-05 Les Chants Magnétiques, Pt. 5.m4a
Dec 11 14:10:34 arpal volumio[1079]: info: No valid Plugin REST Endpoint
Dec 11 14:10:35 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:35 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44.
Dec 11 14:10:35 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:35 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:35 arpal go-librespot[2036]: go-librespot daemon starting...
Dec 11 14:10:35 arpal go-librespot[2036]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:35 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:35 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:36 arpal volumio[1079]: info: Preload queue cleared
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioReplaceandPlayItems
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::ClearQueue
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::stop
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::clearPlayQueue
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::saveQueue
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPushQueue
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::addQueueItems
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::addQueueItems
Dec 11 14:10:36 arpal volumio[1079]: info: Preload queue cleared
Dec 11 14:10:36 arpal volumio[1079]: info: Adding Item to queue: albums://Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques)
Dec 11 14:10:36 arpal volumio[1079]: info: Exploding uri albums://Jean-Michel%20Jarre/Magnetic%20Fields%20(Les%20Chants%20Magn%C3%A9tiques) in service mpd
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPushQueue
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::saveQueue
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::updateTrackBlock
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrackBlock
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPlay
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::play index 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::stop
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::play index undefined
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::startPlaybackTimer
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::clearAddPlayTracks NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand stop
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand stop took 1 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand clear
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces system playlist update
Dec 11 14:10:36 arpal volumio[1079]: info: Ignoring MPD Status Update
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand clear took 2 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand add "NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a"
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces system playlist update
Dec 11 14:10:36 arpal volumio[1079]: info: Ignoring MPD Status Update
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces system playlist update
Dec 11 14:10:36 arpal volumio[1079]: info: Ignoring MPD Status Update
Dec 11 14:10:36 arpal volumio[1079]: error: updateQueue error: null
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces system playlist update
Dec 11 14:10:36 arpal volumio[1079]: info: Ignoring MPD Status Update
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 9ms
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand add "NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a" took 7 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 4ms
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 3ms
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand play
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces system playlist update
Dec 11 14:10:36 arpal volumio[1079]: info: Ignoring MPD Status Update
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces system playlist update
Dec 11 14:10:36 arpal volumio[1079]: info: Ignoring MPD Status Update
Dec 11 14:10:36 arpal volumio[1079]: error: Upnp client error: Error: This socket has been ended by the other party
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 6ms
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand play took 4 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 4ms
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 4ms
Dec 11 14:10:36 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:36 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces state update: player
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::getState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand status
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces state update: player
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::getState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand status
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces state update: player
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::getState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand status
Dec 11 14:10:36 arpal kernel: pcm512x 1-004d: No SCLK, using BCLK: -2
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand status took 18 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces state update: player
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::getState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand status
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand status took 21 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand status took 19 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand playlistinfo took 3 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseTrackInfo
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::servicePushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1070,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"129 Kbps","isStreaming":false,"title":"Les Chants Magnétiques, Pt. 1","artist":"Jean-Michel Jarre","album":"Magnetic Fields (Les Chants Magnétiques)","uri":"NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a","trackType":"m4a"}
Dec 11 14:10:36 arpal volumio[1079]: verbose: CURRENT POSITION 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::syncState stateService play
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::syncState currentStatus stop
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 31ms
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces state update: player
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::getState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand status
Dec 11 14:10:36 arpal volumio[1079]: info:
Dec 11 14:10:36 arpal volumio[1079]: ---------------------------- MPD announces state update: player
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::getState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand status
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand status took 11 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand playlistinfo took 10 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand playlistinfo took 9 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand status took 3 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: info: sendMpdCommand status took 2 milliseconds
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseTrackInfo
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseTrackInfo
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::parseState
Dec 11 14:10:36 arpal volumio[1079]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::servicePushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1070,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"129 Kbps","isStreaming":false,"title":"Les Chants Magnétiques, Pt. 1","artist":"Jean-Michel Jarre","album":"Magnetic Fields (Les Chants Magnétiques)","uri":"NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a","trackType":"m4a"}
Dec 11 14:10:36 arpal volumio[1079]: verbose: CURRENT POSITION 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::syncState stateService play
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::syncState currentStatus play
Dec 11 14:10:36 arpal volumio[1079]: info: Received an update from plugin. extracting info from payload
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:36 arpal volumio[1079]: info: ControllerMpd::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::servicePushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1070,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"129 Kbps","isStreaming":false,"title":"Les Chants Magnétiques, Pt. 1","artist":"Jean-Michel Jarre","album":"Magnetic Fields (Les Chants Magnétiques)","uri":"NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a","trackType":"m4a"}
Dec 11 14:10:36 arpal volumio[1079]: verbose: CURRENT POSITION 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::syncState stateService play
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::syncState currentStatus play
Dec 11 14:10:36 arpal volumio[1079]: info: Received an update from plugin. extracting info from payload
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:36 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:36 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:36 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:36 arpal volumio[1079]: info: ------------------------------ 72ms
Dec 11 14:10:37 arpal volumio[1079]: info: ------------------------------ 72ms
Dec 11 14:10:37 arpal volumio[1079]: info: sendMpdCommand playlistinfo took 45 milliseconds
Dec 11 14:10:37 arpal volumio[1079]: info: sendMpdCommand playlistinfo took 44 milliseconds
Dec 11 14:10:37 arpal volumio[1079]: info: sendMpdCommand playlistinfo took 44 milliseconds
Dec 11 14:10:37 arpal volumio[1079]: verbose: ControllerMpd::parseTrackInfo
Dec 11 14:10:37 arpal volumio[1079]: verbose: ControllerMpd::parseTrackInfo
Dec 11 14:10:37 arpal volumio[1079]: verbose: ControllerMpd::parseTrackInfo
Dec 11 14:10:37 arpal volumio[1079]: info: ControllerMpd::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::servicePushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":879,"duration":1070,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"129 Kbps","isStreaming":false,"title":"Les Chants Magnétiques, Pt. 1","artist":"Jean-Michel Jarre","album":"Magnetic Fields (Les Chants Magnétiques)","uri":"NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a","trackType":"m4a"}
Dec 11 14:10:37 arpal volumio[1079]: verbose: CURRENT POSITION 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::syncState stateService play
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::syncState currentStatus play
Dec 11 14:10:37 arpal volumio[1079]: info: Received an update from plugin. extracting info from payload
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:37 arpal volumio[1079]: info: ControllerMpd::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::servicePushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":879,"duration":1070,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"129 Kbps","isStreaming":false,"title":"Les Chants Magnétiques, Pt. 1","artist":"Jean-Michel Jarre","album":"Magnetic Fields (Les Chants Magnétiques)","uri":"NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a","trackType":"m4a"}
Dec 11 14:10:37 arpal volumio[1079]: verbose: CURRENT POSITION 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::syncState stateService play
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::syncState currentStatus play
Dec 11 14:10:37 arpal volumio[1079]: info: Received an update from plugin. extracting info from payload
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:37 arpal volumio[1079]: info: ControllerMpd::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::servicePushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: verbose: STATE SERVICE {"status":"play","position":0,"seek":879,"duration":1070,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"129 Kbps","isStreaming":false,"title":"Les Chants Magnétiques, Pt. 1","artist":"Jean-Michel Jarre","album":"Magnetic Fields (Les Chants Magnétiques)","uri":"NAS/ARNAS/Music/Jean-Michel Jarre/Magnetic Fields (Les Chants Magnétiques)/1-01 Les Chants Magnétiques, Pt. 1.m4a","trackType":"m4a"}
Dec 11 14:10:37 arpal volumio[1079]: verbose: CURRENT POSITION 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::syncState stateService play
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::syncState currentStatus play
Dec 11 14:10:37 arpal volumio[1079]: info: Received an update from plugin. extracting info from payload
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:37 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:10:37 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:10:37 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:10:37 arpal volumio[1079]: info: ------------------------------ 107ms
Dec 11 14:10:37 arpal volumio[1079]: info: ------------------------------ 97ms
Dec 11 14:10:37 arpal volumio[1079]: info: ------------------------------ 98ms
Dec 11 14:10:38 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:38 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45.
Dec 11 14:10:38 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:38 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:38 arpal go-librespot[2047]: go-librespot daemon starting...
Dec 11 14:10:38 arpal go-librespot[2047]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:38 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:38 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:39 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:39 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:41 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:41 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46.
Dec 11 14:10:41 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:42 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:42 arpal go-librespot[2057]: go-librespot daemon starting...
Dec 11 14:10:42 arpal go-librespot[2057]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:42 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:42 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:42 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:42 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:45 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:45 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47.
Dec 11 14:10:45 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:45 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:45 arpal go-librespot[2103]: go-librespot daemon starting...
Dec 11 14:10:45 arpal go-librespot[2103]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:45 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:45 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:45 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:45 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:48 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:48 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48.
Dec 11 14:10:48 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:48 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:48 arpal go-librespot[2111]: go-librespot daemon starting...
Dec 11 14:10:48 arpal go-librespot[2111]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:48 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:48 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:48 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:48 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:51 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:51 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49.
Dec 11 14:10:51 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:51 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:51 arpal go-librespot[2121]: go-librespot daemon starting...
Dec 11 14:10:51 arpal go-librespot[2121]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:51 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:51 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:51 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:51 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:54 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:54 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:54 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:54 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50.
Dec 11 14:10:54 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:55 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:55 arpal go-librespot[2129]: go-librespot daemon starting...
Dec 11 14:10:55 arpal go-librespot[2129]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:55 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:55 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:10:57 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:10:57 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:10:58 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:10:58 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51.
Dec 11 14:10:58 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:10:58 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:10:58 arpal go-librespot[2137]: go-librespot daemon starting...
Dec 11 14:10:58 arpal go-librespot[2137]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:10:58 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:10:58 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:00 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:00 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:01 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:11:01 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52.
Dec 11 14:11:01 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:11:01 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:11:01 arpal go-librespot[2146]: go-librespot daemon starting...
Dec 11 14:11:01 arpal go-librespot[2146]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:11:01 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:11:01 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:03 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:03 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:04 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:11:04 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53.
Dec 11 14:11:04 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:11:04 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:11:04 arpal go-librespot[2154]: go-librespot daemon starting...
Dec 11 14:11:04 arpal go-librespot[2154]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:11:04 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:11:04 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:06 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:06 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:07 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:11:07 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54.
Dec 11 14:11:07 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:11:08 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:11:08 arpal go-librespot[2164]: go-librespot daemon starting...
Dec 11 14:11:08 arpal go-librespot[2164]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:11:08 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:11:08 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:09 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:09 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:11 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:11:11 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55.
Dec 11 14:11:11 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:11:11 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:11:11 arpal go-librespot[2173]: go-librespot daemon starting...
Dec 11 14:11:11 arpal go-librespot[2173]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:11:11 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:11:11 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:11 arpal volumio[1079]: info: VolumeController::SetAlsaVolume100
Dec 11 14:11:11 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:11:11 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:11:11 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 11 14:11:11 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:11:12 arpal volumio[1079]: info: VolumeController::SetAlsaVolume100
Dec 11 14:11:12 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:11:12 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:11:12 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:11:12 arpal volumio[1079]: info: VolumeController::SetAlsaVolume100
Dec 11 14:11:12 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:11:12 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:11:12 arpal volumio[1079]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 11 14:11:12 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:11:12 arpal volumio[1079]: info: VolumeController::SetAlsaVolume100
Dec 11 14:11:12 arpal volumio[1079]: info: CoreStateMachine::pushState
Dec 11 14:11:12 arpal volumio[1079]: info: CorePlayQueue::getTrack 0
Dec 11 14:11:12 arpal volumio[1079]: info: CoreCommandRouter::volumioPushState
Dec 11 14:11:12 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:12 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:14 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:11:14 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56.
Dec 11 14:11:14 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:11:14 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:11:14 arpal go-librespot[2185]: go-librespot daemon starting...
Dec 11 14:11:14 arpal go-librespot[2185]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:11:14 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:11:14 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:15 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:15 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:17 arpal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 11 14:11:17 arpal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57.
Dec 11 14:11:17 arpal systemd[1]: Stopped go-librespot Daemon.
Dec 11 14:11:17 arpal systemd[1]: Started go-librespot Daemon.
Dec 11 14:11:17 arpal go-librespot[2193]: go-librespot daemon starting...
Dec 11 14:11:17 arpal go-librespot[2193]: /bin/start-go-librespot.sh: 7: /bin/start-go-librespot.sh: /usr/bin/go-librespot: not found
Dec 11 14:11:17 arpal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a
Dec 11 14:11:17 arpal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 11 14:11:18 arpal volumio[1079]: info: Initializing connection to go-librespot Websocket
Dec 11 14:11:18 arpal volumio[1079]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 11 14:11:20 arpal volumio[1079]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 11 14:11:20 arpal volumio[1079]: TypeError: Cannot read property 'slice' of null
Dec 11 14:11:20 arpal volumio[1079]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:714:41)
Dec 11 14:11:20 arpal volumio[1079]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:724:7)
Dec 11 14:11:20 arpal volumio[1079]: at Object.onceWrapper (events.js:422:26)
Dec 11 14:11:20 arpal volumio[1079]: at ClientRequest.emit (events.js:315:20)
Dec 11 14:11:20 arpal volumio[1079]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27)
Dec 11 14:11:20 arpal volumio[1079]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17)
Dec 11 14:11:20 arpal volumio[1079]: at TLSSocket.socketOnData (_http_client.js:509:22)
Dec 11 14:11:20 arpal volumio[1079]: at TLSSocket.emit (events.js:315:20)
Dec 11 14:11:20 arpal volumio[1079]: at addChunk (internal/streams/readable.js:309:12)
Dec 11 14:11:20 arpal volumio[1079]: at readableAddChunk (internal/streams/readable.js:284:9)
Dec 11 14:11:20 arpal volumio[1079]: at TLSSocket.Readable.push (internal/streams/readable.js:223:10)
Dec 11 14:11:20 arpal volumio[1079]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23)
Dec 11 14:11:20 arpal volumio[1079]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 11 14:11:20 arpal sudo[2212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-11 14:10
Dec 11 14:11:20 arpal sudo[2212]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST"
VOLUMIO_VERSION="3.703"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"