Apr 13 18:59:00 bestofyou volumio[1188]: info: Apr 13 18:59:00 bestofyou volumio[1188]: ---------------------------- MPD announces state update: player Apr 13 18:59:00 bestofyou volumio[1188]: info: ControllerMpd::getState Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Apr 13 18:59:00 bestofyou volumio[1188]: info: Apr 13 18:59:00 bestofyou volumio[1188]: ---------------------------- MPD announces state update: player Apr 13 18:59:00 bestofyou volumio[1188]: info: sendMpdCommand status took 2 milliseconds Apr 13 18:59:00 bestofyou volumio[1188]: info: ControllerMpd::getState Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::parseState Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 13 18:59:00 bestofyou volumio[1188]: info: sendMpdCommand status took 1 milliseconds Apr 13 18:59:00 bestofyou volumio[1188]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::parseState Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::parseTrackInfo Apr 13 18:59:00 bestofyou volumio[1188]: info: ControllerMpd::pushState Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::servicePushState Apr 13 18:59:00 bestofyou volumio[1188]: info: CorePlayQueue::getTrack 0 Apr 13 18:59:00 bestofyou volumio[1188]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=11100525&eid=294823025&fmt=7&profile=raw&app_id=539451548&cid=3999519&etsp=1776124738&hmac=eYWo4J1P7r9dg8BQDLj1TO-by3E","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11100525&eid=294823025&fmt=7&profile=raw&app_id=539451548&cid=3999519&etsp=1776124738&hmac=eYWo4J1P7r9dg8BQDLj1TO-by3E","trackType":"qobuz"} Apr 13 18:59:00 bestofyou volumio[1188]: verbose: CURRENT POSITION 0 Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreStateMachine::syncState stateService play Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreStateMachine::syncState currentStatus stop Apr 13 18:59:00 bestofyou volumio[1188]: info: ------------------------------ 5ms Apr 13 18:59:00 bestofyou volumio[1188]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 13 18:59:00 bestofyou volumio[1188]: verbose: ControllerMpd::parseTrackInfo Apr 13 18:59:00 bestofyou volumio[1188]: info: ControllerMpd::pushState Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::servicePushState Apr 13 18:59:00 bestofyou volumio[1188]: info: CorePlayQueue::getTrack 0 Apr 13 18:59:00 bestofyou volumio[1188]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"file?uid=11100525&eid=294823025&fmt=7&profile=raw&app_id=539451548&cid=3999519&etsp=1776124738&hmac=eYWo4J1P7r9dg8BQDLj1TO-by3E","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11100525&eid=294823025&fmt=7&profile=raw&app_id=539451548&cid=3999519&etsp=1776124738&hmac=eYWo4J1P7r9dg8BQDLj1TO-by3E","trackType":"qobuz"} Apr 13 18:59:00 bestofyou volumio[1188]: verbose: CURRENT POSITION 0 Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreStateMachine::syncState stateService play Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreStateMachine::syncState currentStatus play Apr 13 18:59:00 bestofyou volumio[1188]: info: Received an update from plugin. extracting info from payload Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreStateMachine::pushState Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::volumioPushState Apr 13 18:59:00 bestofyou volumio[1188]: info: MRS: Pushing multiroomSync output update for this device Apr 13 18:59:00 bestofyou volumio[1188]: info: MRS: Pushing multiroomSync output Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::volumioGetState Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreStateMachine::pushState Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::volumioPushState Apr 13 18:59:00 bestofyou volumio[1188]: info: MRS: Pushing multiroomSync output update for this device Apr 13 18:59:00 bestofyou volumio[1188]: info: MRS: Pushing multiroomSync output Apr 13 18:59:00 bestofyou volumio[1188]: info: CoreCommandRouter::volumioGetState Apr 13 18:59:00 bestofyou volumio[1188]: info: ------------------------------ 9ms Apr 13 18:59:00 bestofyou volumio[1188]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Apr 13 18:59:00 bestofyou volumio[1188]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Apr 13 18:59:05 bestofyou volumio[1188]: info: CoreCommandRouter::volumioGetState Apr 13 18:59:05 bestofyou go-librespot[7012]: time="2026-04-13T18:59:05-04:00" level=trace msg="sent dealer ping" Apr 13 18:59:05 bestofyou go-librespot[7012]: time="2026-04-13T18:59:05-04:00" level=trace msg="received dealer pong" Apr 13 18:59:07 bestofyou volumio[1188]: info: Executing endpoint metavolumio Apr 13 18:59:07 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 13 18:59:07 bestofyou volumio[1188]: info: Executing endpoint metavolumio Apr 13 18:59:07 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 13 18:59:07 bestofyou volumio[1188]: info: Executing endpoint metavolumio Apr 13 18:59:07 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 13 18:59:07 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 18:59:07 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 13 18:59:10 bestofyou volumio[1188]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 18:59:19 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 18:59:19 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 13 18:59:22 bestofyou volumio[1188]: info: CoreCommandRouter::volumioGetState Apr 13 18:59:23 bestofyou go-librespot[7012]: time="2026-04-13T18:59:23-04:00" level=trace msg="received accesspoint ping" Apr 13 18:59:24 bestofyou go-librespot[7012]: time="2026-04-13T18:59:24-04:00" level=trace msg="received accesspoint pong ack" Apr 13 18:59:24 bestofyou volumio[1188]: info: Executing endpoint metavolumio Apr 13 18:59:24 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 13 18:59:24 bestofyou volumio[1188]: info: Executing endpoint metavolumio Apr 13 18:59:24 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 13 18:59:24 bestofyou volumio[1188]: info: Executing endpoint metavolumio Apr 13 18:59:24 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreCommandRouter::volumioPause Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::pause Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::stPlaybackTimer Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::servicePause Apr 13 18:59:26 bestofyou volumio[1188]: info: CorePlayQueue::getTrack 0 Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreCommandRouter::servicePause Apr 13 18:59:26 bestofyou volumio[1188]: info: [1776121166406] ControllerQobuz::pause Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 13 18:59:26 bestofyou volumio[1188]: info: ControllerMpd::pause Apr 13 18:59:26 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand pause Apr 13 18:59:26 bestofyou volumio[1188]: info: Apr 13 18:59:26 bestofyou volumio[1188]: ---------------------------- MPD announces state update: player Apr 13 18:59:26 bestofyou volumio[1188]: info: sendMpdCommand pause took 1 milliseconds Apr 13 18:59:26 bestofyou volumio[1188]: info: ControllerMpd::getState Apr 13 18:59:26 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand status Apr 13 18:59:26 bestofyou volumio[1188]: info: sendMpdCommand status took 0 milliseconds Apr 13 18:59:26 bestofyou volumio[1188]: verbose: ControllerMpd::parseState Apr 13 18:59:26 bestofyou volumio[1188]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 13 18:59:26 bestofyou volumio[1188]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 13 18:59:26 bestofyou volumio[1188]: verbose: ControllerMpd::parseTrackInfo Apr 13 18:59:26 bestofyou volumio[1188]: info: ControllerMpd::pushState Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreCommandRouter::servicePushState Apr 13 18:59:26 bestofyou volumio[1188]: info: CorePlayQueue::getTrack 0 Apr 13 18:59:26 bestofyou volumio[1188]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":27633,"duration":211,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2959 Kbps","isStreaming":false,"title":"file?uid=11100525&eid=294823025&fmt=7&profile=raw&app_id=539451548&cid=3999519&etsp=1776124738&hmac=eYWo4J1P7r9dg8BQDLj1TO-by3E","artist":null,"album":null,"uri":"https://streaming-qobuz-std.akamaized.net/file?uid=11100525&eid=294823025&fmt=7&profile=raw&app_id=539451548&cid=3999519&etsp=1776124738&hmac=eYWo4J1P7r9dg8BQDLj1TO-by3E","trackType":"qobuz"} Apr 13 18:59:26 bestofyou volumio[1188]: verbose: CURRENT POSITION 0 Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::syncState stateService pause Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::syncState currentStatus pause Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::pushState Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreCommandRouter::volumioPushState Apr 13 18:59:26 bestofyou volumio[1188]: info: MRS: Pushing multiroomSync output update for this device Apr 13 18:59:26 bestofyou volumio[1188]: info: MRS: Pushing multiroomSync output Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreCommandRouter::volumioGetState Apr 13 18:59:26 bestofyou volumio[1188]: info: CoreStateMachine::stPlaybackTimer Apr 13 18:59:26 bestofyou volumio[1188]: info: ------------------------------ 5ms Apr 13 18:59:26 bestofyou volumio[1188]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Apr 13 18:59:35 bestofyou go-librespot[7012]: time="2026-04-13T18:59:35-04:00" level=trace msg="sent dealer ping" Apr 13 18:59:35 bestofyou go-librespot[7012]: time="2026-04-13T18:59:35-04:00" level=trace msg="received dealer pong" Apr 13 19:00:05 bestofyou go-librespot[7012]: time="2026-04-13T19:00:05-04:00" level=trace msg="sent dealer ping" Apr 13 19:00:05 bestofyou go-librespot[7012]: time="2026-04-13T19:00:05-04:00" level=trace msg="received dealer pong" Apr 13 19:00:14 bestofyou sshd[96542]: Accepted publickey for volumio from 192.168.1.157 port 63930 ssh2: RSA SHA256:b1pEuqj+B2vKHRZyjFZnv/ui8fDP5Yy0IZfr/qxGYZY Apr 13 19:00:14 bestofyou sshd[96542]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Apr 13 19:00:14 bestofyou systemd-logind[893]: New session 27 of user volumio. Apr 13 19:00:14 bestofyou systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Apr 13 19:00:14 bestofyou systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Apr 13 19:00:14 bestofyou systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Apr 13 19:00:14 bestofyou systemd[1]: Starting user@1000.service - User Manager for UID 1000... Apr 13 19:00:14 bestofyou (systemd)[96545]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Apr 13 19:00:15 bestofyou systemd[96545]: Queued start job for default target default.target. Apr 13 19:00:15 bestofyou systemd[96545]: Created slice app.slice - User Application Slice. Apr 13 19:00:15 bestofyou systemd[96545]: Reached target paths.target - Paths. Apr 13 19:00:15 bestofyou systemd[96545]: Reached target timers.target - Timers. Apr 13 19:00:15 bestofyou systemd[96545]: Starting dbus.socket - D-Bus User Message Bus Socket... Apr 13 19:00:15 bestofyou systemd[96545]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Apr 13 19:00:15 bestofyou systemd[96545]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Apr 13 19:00:15 bestofyou systemd[96545]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Apr 13 19:00:15 bestofyou systemd[96545]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Apr 13 19:00:15 bestofyou systemd[96545]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Apr 13 19:00:15 bestofyou systemd[96545]: Listening on dbus.socket - D-Bus User Message Bus Socket. Apr 13 19:00:15 bestofyou systemd[96545]: Reached target sockets.target - Sockets. Apr 13 19:00:15 bestofyou systemd[96545]: Reached target basic.target - Basic System. Apr 13 19:00:15 bestofyou systemd[1]: Started user@1000.service - User Manager for UID 1000. Apr 13 19:00:15 bestofyou systemd[96545]: Started mpris-proxy.service - Bluetooth mpris proxy. Apr 13 19:00:15 bestofyou systemd[96545]: Reached target default.target - Main User Target. Apr 13 19:00:15 bestofyou systemd[96545]: Startup finished in 169ms. Apr 13 19:00:15 bestofyou systemd[1]: Started session-27.scope - Session 27 of User volumio. Apr 13 19:00:15 bestofyou systemd[96545]: Created slice session.slice - User Core Session Slice. Apr 13 19:00:15 bestofyou systemd[96545]: Starting dbus.service - D-Bus User Message Bus... Apr 13 19:00:15 bestofyou systemd[96545]: Started dbus.service - D-Bus User Message Bus. Apr 13 19:00:15 bestofyou sshd[96542]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 13 19:00:15 bestofyou sshd[96572]: Received disconnect from 192.168.1.157 port 63930:11: disconnected by user Apr 13 19:00:15 bestofyou sshd[96572]: Disconnected from user volumio 192.168.1.157 port 63930 Apr 13 19:00:15 bestofyou sshd[96542]: pam_unix(sshd:session): session closed for user volumio Apr 13 19:00:15 bestofyou systemd[1]: session-27.scope: Deactivated successfully. Apr 13 19:00:15 bestofyou systemd-logind[893]: Session 27 logged out. Waiting for processes to exit. Apr 13 19:00:15 bestofyou systemd-logind[893]: Removed session 27. Apr 13 19:00:23 bestofyou sshd[96599]: Accepted publickey for volumio from 192.168.1.157 port 63935 ssh2: RSA SHA256:b1pEuqj+B2vKHRZyjFZnv/ui8fDP5Yy0IZfr/qxGYZY Apr 13 19:00:23 bestofyou sshd[96599]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Apr 13 19:00:23 bestofyou systemd-logind[893]: New session 29 of user volumio. Apr 13 19:00:23 bestofyou systemd[1]: Started session-29.scope - Session 29 of User volumio. Apr 13 19:00:23 bestofyou sshd[96599]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 13 19:00:23 bestofyou sshd[96610]: Received disconnect from 192.168.1.157 port 63935:11: disconnected by user Apr 13 19:00:23 bestofyou sshd[96610]: Disconnected from user volumio 192.168.1.157 port 63935 Apr 13 19:00:23 bestofyou sshd[96599]: pam_unix(sshd:session): session closed for user volumio Apr 13 19:00:23 bestofyou systemd[1]: session-29.scope: Deactivated successfully. Apr 13 19:00:23 bestofyou systemd-logind[893]: Session 29 logged out. Waiting for processes to exit. Apr 13 19:00:23 bestofyou systemd-logind[893]: Removed session 29. Apr 13 19:00:29 bestofyou sshd[96634]: Accepted publickey for volumio from 192.168.1.157 port 63939 ssh2: RSA SHA256:b1pEuqj+B2vKHRZyjFZnv/ui8fDP5Yy0IZfr/qxGYZY Apr 13 19:00:29 bestofyou sshd[96634]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Apr 13 19:00:29 bestofyou systemd-logind[893]: New session 30 of user volumio. Apr 13 19:00:29 bestofyou systemd[1]: Started session-30.scope - Session 30 of User volumio. Apr 13 19:00:29 bestofyou sshd[96634]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 13 19:00:29 bestofyou sshd[96646]: Received disconnect from 192.168.1.157 port 63939:11: disconnected by user Apr 13 19:00:29 bestofyou sshd[96646]: Disconnected from user volumio 192.168.1.157 port 63939 Apr 13 19:00:29 bestofyou sshd[96634]: pam_unix(sshd:session): session closed for user volumio Apr 13 19:00:29 bestofyou systemd[1]: session-30.scope: Deactivated successfully. Apr 13 19:00:29 bestofyou systemd-logind[893]: Session 30 logged out. Waiting for processes to exit. Apr 13 19:00:29 bestofyou systemd-logind[893]: Removed session 30. Apr 13 19:00:35 bestofyou go-librespot[7012]: time="2026-04-13T19:00:35-04:00" level=trace msg="sent dealer ping" Apr 13 19:00:35 bestofyou go-librespot[7012]: time="2026-04-13T19:00:35-04:00" level=trace msg="received dealer pong" Apr 13 19:00:37 bestofyou sshd[96672]: Accepted publickey for volumio from 192.168.1.157 port 63948 ssh2: RSA SHA256:b1pEuqj+B2vKHRZyjFZnv/ui8fDP5Yy0IZfr/qxGYZY Apr 13 19:00:37 bestofyou sshd[96672]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Apr 13 19:00:37 bestofyou systemd-logind[893]: New session 31 of user volumio. Apr 13 19:00:37 bestofyou systemd[1]: Started session-31.scope - Session 31 of User volumio. Apr 13 19:00:37 bestofyou sshd[96672]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 13 19:00:37 bestofyou sudo[96687]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl restart go-librespot Apr 13 19:00:37 bestofyou sudo[96687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 19:00:37 bestofyou sudo[96687]: pam_unix(sudo:session): session closed for user root Apr 13 19:00:37 bestofyou sudo[96690]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/killall go-librespot Apr 13 19:00:37 bestofyou sudo[96690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 19:00:37 bestofyou sudo[96690]: pam_unix(sudo:session): session closed for user root Apr 13 19:00:37 bestofyou go-librespot[7011]: Terminated Apr 13 19:00:37 bestofyou systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=143/n/a Apr 13 19:00:37 bestofyou systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 19:00:37 bestofyou volumio[1188]: info: Connection to go-librespot Websocket closed Apr 13 19:00:37 bestofyou systemd[1]: go-librespot-daemon.service: Consumed 6.701s CPU time. Apr 13 19:00:37 bestofyou volumio[1188]: info: Connection to go-librespot Websocket closed Apr 13 19:00:39 bestofyou sshd[96684]: Received disconnect from 192.168.1.157 port 63948:11: disconnected by user Apr 13 19:00:39 bestofyou sshd[96684]: Disconnected from user volumio 192.168.1.157 port 63948 Apr 13 19:00:39 bestofyou sshd[96672]: pam_unix(sshd:session): session closed for user volumio Apr 13 19:00:39 bestofyou systemd[1]: session-31.scope: Deactivated successfully. Apr 13 19:00:39 bestofyou systemd-logind[893]: Session 31 logged out. Waiting for processes to exit. Apr 13 19:00:39 bestofyou systemd-logind[893]: Removed session 31. Apr 13 19:00:40 bestofyou volumio[1188]: info: Initializing connection to go-librespot Websocket Apr 13 19:00:40 bestofyou volumio[1188]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 13 19:00:40 bestofyou systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 13 19:00:40 bestofyou systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 13 19:00:40 bestofyou systemd[1]: go-librespot-daemon.service: Consumed 6.701s CPU time. Apr 13 19:00:40 bestofyou systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 13 19:00:40 bestofyou go-librespot[96701]: go-librespot daemon starting... Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=info msg="running go-librespot 0.7.1" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=debug msg="app state loaded" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=info msg="zeroconf server listening on port 33781" Apr 13 19:00:40 bestofyou go-librespot[96702]: time="2026-04-13T19:00:40-04:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="obtained new client token: AAC9ktj4fqRXGb+jFe3NMjaLgSEPihPM5Y4BkrCVAJNdpxXVrbOT7rdTJvG/b3+/4uN9DqY8iYTq1aozO/UAsoHAFE4kf6e5pdGoTMq9VHnj2cxC3zPLyxdode6rj6k4HU2rh7QIBt210e0AtT0VvuAIVmRCkeBbIapfonRKGzajz/O7l4QArEFaQCLJ3f1bPmdPoPs817RB8kGiEm2C9hUJnKCR1nsUzPF9gHsH1gcZZ4ow8g==" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="completed keyexchange" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="completed challenge" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=info msg="authenticated AP" username="31************************3e" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=info msg="authenticated Login5" username="31************************3e" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="initializing zeroconf session" username="31************************3e" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="dealer connection opened" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=trace msg="starting accesspoint recv loop" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=trace msg="starting dealer recv loop" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=trace msg="received accesspoint ping" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 13 19:00:41 bestofyou go-librespot[96702]: time="2026-04-13T19:00:41-04:00" level=debug msg="received connection id: M2UxYWNhYjMtY2I1...NEFFOEE5NkNFMA==" Apr 13 19:00:42 bestofyou go-librespot[96702]: time="2026-04-13T19:00:42-04:00" level=debug msg="put connect state because NEW_DEVICE" Apr 13 19:00:42 bestofyou go-librespot[96702]: time="2026-04-13T19:00:42-04:00" level=trace msg="received accesspoint pong ack" Apr 13 19:00:43 bestofyou volumio[1188]: info: Initializing connection to go-librespot Websocket Apr 13 19:00:43 bestofyou go-librespot[96702]: time="2026-04-13T19:00:43-04:00" level=debug msg="new websocket client" Apr 13 19:00:43 bestofyou volumio[1188]: info: Connection to go-librespot Websocket established Apr 13 19:00:45 bestofyou sshd[96715]: Accepted publickey for volumio from 192.168.1.157 port 63959 ssh2: RSA SHA256:b1pEuqj+B2vKHRZyjFZnv/ui8fDP5Yy0IZfr/qxGYZY Apr 13 19:00:45 bestofyou sshd[96715]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Apr 13 19:00:45 bestofyou systemd-logind[893]: New session 32 of user volumio. Apr 13 19:00:45 bestofyou systemd[1]: Started session-32.scope - Session 32 of User volumio. Apr 13 19:00:45 bestofyou sshd[96715]: pam_env(sshd:session): deprecated reading of user environment enabled Apr 13 19:00:45 bestofyou sudo[96743]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/bin/kill 96702 Apr 13 19:00:45 bestofyou sudo[96743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 19:00:45 bestofyou sudo[96743]: pam_unix(sudo:session): session closed for user root Apr 13 19:00:45 bestofyou go-librespot[96701]: Terminated Apr 13 19:00:45 bestofyou systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=143/n/a Apr 13 19:00:45 bestofyou systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 13 19:00:45 bestofyou volumio[1188]: info: Connection to go-librespot Websocket closed Apr 13 19:00:46 bestofyou volumio[1188]: info: Getting Spotify volume Apr 13 19:00:46 bestofyou volumio[1188]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 19:00:46 bestofyou volumio[1188]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 13 19:00:46 bestofyou volumio[1188]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 13 19:00:46 bestofyou volumio[1188]: errno: -111, Apr 13 19:00:46 bestofyou volumio[1188]: code: 'ECONNREFUSED', Apr 13 19:00:46 bestofyou volumio[1188]: syscall: 'connect', Apr 13 19:00:46 bestofyou volumio[1188]: address: '127.0.0.1', Apr 13 19:00:46 bestofyou volumio[1188]: port: 9879, Apr 13 19:00:46 bestofyou volumio[1188]: response: undefined Apr 13 19:00:46 bestofyou volumio[1188]: } Apr 13 19:00:46 bestofyou volumio[1188]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 19:00:46 bestofyou sudo[96763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-13 18:59' Apr 13 19:00:46 bestofyou sudo[96763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"