-- Logs begin at Wed 2025-02-19 21:10:31 +07, end at Wed 2025-02-19 21:21:44 +07. -- Feb 19 21:20:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 169. Feb 19 21:20:00 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:00 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:00 volumio go-librespot[4205]: Librespot-go daemon starting... Feb 19 21:20:00 volumio go-librespot[4205]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:01 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:01 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:03 volumio volumio[1218]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Feb 19 21:20:03 volumio volumio[1218]: info: Preparing to save Alsa Options, stopping services first Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:03 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:03 volumio volumio[1218]: info: Saving Audio Output to: {"output_device":{"value":"0,3","label":"HDMI"}} Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 19 21:20:03 volumio volumio[1218]: info: Found match in Cards Database: setting mixer for card HDMI Feb 19 21:20:03 volumio volumio[1218]: info: Setting mixer Master for card HDMI Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::volumioUpdateVolumeSettings Feb 19 21:20:03 volumio volumio[1218]: info: Updating Volume Controller Parameters: Device: 0,3 Name: HDMI Mixer: Master Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Feb 19 21:20:03 volumio volumio[1218]: info: Disabling external Volume Control Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 19 21:20:03 volumio volumio[1218]: info: Preparing to generate the ALSA configuration file Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 19 21:20:03 volumio volumio[1218]: info: Asound.conf file unchanged, so no further update is needed Feb 19 21:20:03 volumio volumio[1218]: info: Output device has changed, restarting MPD Feb 19 21:20:03 volumio sudo[4224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 19 21:20:03 volumio sudo[4224]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 19 21:20:03 volumio sudo[4224]: pam_unix(sudo:session): session closed for user root Feb 19 21:20:03 volumio volumio[1218]: info: Output device has changed, restarting Shairport Sync Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 21:20:03 volumio sudo[4227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 19 21:20:03 volumio sudo[4227]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 19 21:20:03 volumio systemd[1]: Stopping Music Player Daemon... Feb 19 21:20:03 volumio systemd[1]: mpd.service: Succeeded. Feb 19 21:20:03 volumio systemd[1]: Stopped Music Player Daemon. Feb 19 21:20:03 volumio volumio[1218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 19 21:20:03 volumio volumio[1218]: info: MPD Permissions set Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:03 volumio volumio[1218]: info: VolumeController:: Volume=97 Mute =false Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:03 volumio volumio[1218]: info: CoreStateMachine::pushState Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::volumioPushState Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio systemd[1]: Starting Music Player Daemon... Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 19 21:20:03 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 19 21:20:03 volumio volumio[1218]: info: Starting Shairport Sync Feb 19 21:20:03 volumio sudo[4232]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 19 21:20:03 volumio sudo[4232]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 19 21:20:03 volumio sudo[4232]: pam_unix(sudo:session): session closed for user root Feb 19 21:20:03 volumio sudo[4240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 19 21:20:03 volumio sudo[4240]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 19 21:20:03 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 19 21:20:03 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 19 21:20:03 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 19 21:20:03 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 19 21:20:03 volumio sudo[4240]: pam_unix(sudo:session): session closed for user root Feb 19 21:20:03 volumio volumio[1218]: info: Shairport-Sync Started Feb 19 21:20:03 volumio mpd[4242]: Feb 19 21:20 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 19 21:20:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 170. Feb 19 21:20:03 volumio systemd[1]: Started Music Player Daemon. Feb 19 21:20:03 volumio sudo[4227]: pam_unix(sudo:session): session closed for user root Feb 19 21:20:03 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:03 volumio volumio[1218]: error: updateQueue error: null Feb 19 21:20:03 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:03 volumio go-librespot[4249]: Librespot-go daemon starting... Feb 19 21:20:03 volumio go-librespot[4249]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:04 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:04 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:06 volumio volumio[1218]: error: error Feb 19 21:20:07 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:07 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:07 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 171. Feb 19 21:20:07 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:07 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:07 volumio go-librespot[4270]: Librespot-go daemon starting... Feb 19 21:20:07 volumio go-librespot[4270]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:07 volumio volumio[1218]: error: error Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Feb 19 21:20:07 volumio volumio[1218]: info: CoreStateMachine::getcurrentVolume Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 21:20:07 volumio volumio[1218]: info: VolumeController:: Volume=97 Mute =false Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:07 volumio volumio[1218]: info: CoreStateMachine::pushState Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioPushState Feb 19 21:20:07 volumio volumio[1218]: info: CoreStateMachine::updateTrackBlock Feb 19 21:20:07 volumio volumio[1218]: info: CorePlayQueue::getTrackBlock Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioRetrievevolume Feb 19 21:20:07 volumio volumio[1218]: info: VolumeController:: Volume=97 Mute =false Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:07 volumio volumio[1218]: info: CoreStateMachine::pushState Feb 19 21:20:07 volumio volumio[1218]: info: CoreCommandRouter::volumioPushState Feb 19 21:20:10 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:10 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 172. Feb 19 21:20:10 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:10 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:10 volumio go-librespot[4276]: Librespot-go daemon starting... Feb 19 21:20:10 volumio go-librespot[4276]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:11 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:11 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:13 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:13 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 173. Feb 19 21:20:13 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:13 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:13 volumio go-librespot[4278]: Librespot-go daemon starting... Feb 19 21:20:13 volumio go-librespot[4278]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:13 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:13 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:15 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:15 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:16 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:16 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:16 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:16 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 174. Feb 19 21:20:16 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:16 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:16 volumio go-librespot[4283]: Librespot-go daemon starting... Feb 19 21:20:16 volumio go-librespot[4283]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 19 21:20:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 19 21:20:18 volumio volumio[1218]: info: Discovery: Getting this device information Feb 19 21:20:18 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 19 21:20:19 volumio volumio[1218]: info: CoreCommandRouter::volumioNext Feb 19 21:20:19 volumio volumio[1218]: info: CoreStateMachine::next Feb 19 21:20:19 volumio volumio[1218]: info: ControllerMpd::next Feb 19 21:20:19 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand next Feb 19 21:20:19 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:19 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 175. Feb 19 21:20:20 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:20 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:20 volumio go-librespot[4299]: Librespot-go daemon starting... Feb 19 21:20:20 volumio go-librespot[4299]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:22 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:22 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 176. Feb 19 21:20:23 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:23 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:23 volumio go-librespot[4303]: Librespot-go daemon starting... Feb 19 21:20:23 volumio go-librespot[4303]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:24 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:25 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:25 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:25 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:25 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 177. Feb 19 21:20:26 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:26 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:26 volumio go-librespot[4310]: Librespot-go daemon starting... Feb 19 21:20:26 volumio go-librespot[4310]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:26 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:26 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:28 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:28 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 178. Feb 19 21:20:29 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:29 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:29 volumio go-librespot[4326]: Librespot-go daemon starting... Feb 19 21:20:29 volumio go-librespot[4326]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:31 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:31 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:31 volumio volumio[1218]: info: CoreCommandRouter::volumioPause Feb 19 21:20:31 volumio volumio[1218]: info: CoreStateMachine::pause Feb 19 21:20:31 volumio ntpd[1289]: Soliciting pool server 103.70.115.65 Feb 19 21:20:31 volumio ntpd[1289]: Soliciting pool server 103.70.115.65 Feb 19 21:20:31 volumio ntpd[1289]: Soliciting pool server 103.70.115.65 Feb 19 21:20:32 volumio volumio[1218]: info: CoreCommandRouter::volumioNext Feb 19 21:20:32 volumio volumio[1218]: info: CoreStateMachine::next Feb 19 21:20:32 volumio volumio[1218]: info: ControllerMpd::next Feb 19 21:20:32 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand next Feb 19 21:20:33 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 179. Feb 19 21:20:33 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:33 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:33 volumio go-librespot[4348]: Librespot-go daemon starting... Feb 19 21:20:33 volumio go-librespot[4348]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:34 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:34 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 180. Feb 19 21:20:36 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:36 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:36 volumio go-librespot[4378]: Librespot-go daemon starting... Feb 19 21:20:36 volumio go-librespot[4378]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:37 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:37 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:39 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::ClearQueue Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::stop Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::updateTrackBlock Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrackBlock Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::stPlaybackTimer Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::pushState Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::volumioPushState Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::serviceStop Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::serviceStop Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 19 21:20:39 volumio volumio[1218]: info: ControllerMpd::stop Feb 19 21:20:39 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand stop Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::clearPlayQueue Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::saveQueue Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::volumioPushQueue Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::addQueueItems Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::addQueueItems Feb 19 21:20:39 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:20:39 volumio volumio[1218]: info: Adding Item to queue: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Ti%E1%BA%BFng%20H%C3%A1t%20Ng%E1%BB%8Dt%20Qu%C3%A1%20%C4%90%E1%BB%97i%20V%E1%BB%9Bi%20Ca%20Kh%C3%BAc%20Th%C6%B0%20T%C3%ACnh%20Em%20G%C3%A1i%20-%20Thu%20H%C6%B0%E1%BB%9Dng%22%2C%22artist%22%3A%22Gi%E1%BB%8Dng%20Ca%20%C4%90%E1%BB%83%20%C4%90%E1%BB%9Di%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2F4RDOn6cZLPg%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAV98OEkBisnS39aGb4z_MKmlR3wA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%224RDOn6cZLPg%22%2C%22params%22%3A%22qgMMdGh1IGjGsOG7nW5nugMkEiJQTEdSZDhUTlJ4OHN0bERZeXlGbWRVeDMtaV9YMkg4SnBsugMcEhpSREVNQjBiQkstbHVCbVNDVmU3ZGlEWFpYQboDCwic3uTIgq2Y26MBugMLCNL_wPOJu9y5lAG6AwoIxOim6YXkjN5OugMLCKOIwOqxhtzGmwG6AwoIzaDuvoiTl9E1ugMLCPz81LKAiLbcpwG6AwsIoNnK8LrV8-uSAboDCwiCssS15uDtlIoBugMLCJu005u_sZuswQG6AwsIk8iQ8NaV5dmXAboDCgiAmJm21Yzb8kK6AwoIoqi6j4Wcrs4WugMLCNyhpZiXyIu86wG6AwoI-5-h-8qi2NATugMLCJitlLXb-djCpwG6AwsIzbeZ5_y2ndz9AboDCwiB_YCIsL3JxPYB%22%7D%7D%7D Feb 19 21:20:39 volumio volumio[1218]: info: Exploding uri youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Ti%E1%BA%BFng%20H%C3%A1t%20Ng%E1%BB%8Dt%20Qu%C3%A1%20%C4%90%E1%BB%97i%20V%E1%BB%9Bi%20Ca%20Kh%C3%BAc%20Th%C6%B0%20T%C3%ACnh%20Em%20G%C3%A1i%20-%20Thu%20H%C6%B0%E1%BB%9Dng%22%2C%22artist%22%3A%22Gi%E1%BB%8Dng%20Ca%20%C4%90%E1%BB%83%20%C4%90%E1%BB%9Di%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2F4RDOn6cZLPg%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAV98OEkBisnS39aGb4z_MKmlR3wA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%224RDOn6cZLPg%22%2C%22params%22%3A%22qgMMdGh1IGjGsOG7nW5nugMkEiJQTEdSZDhUTlJ4OHN0bERZeXlGbWRVeDMtaV9YMkg4SnBsugMcEhpSREVNQjBiQkstbHVCbVNDVmU3ZGlEWFpYQboDCwic3uTIgq2Y26MBugMLCNL_wPOJu9y5lAG6AwoIxOim6YXkjN5OugMLCKOIwOqxhtzGmwG6AwoIzaDuvoiTl9E1ugMLCPz81LKAiLbcpwG6AwsIoNnK8LrV8-uSAboDCwiCssS15uDtlIoBugMLCJu005u_sZuswQG6AwsIk8iQ8NaV5dmXAboDCgiAmJm21Yzb8kK6AwoIoqi6j4Wcrs4WugMLCNyhpZiXyIu86wG6AwoI-5-h-8qi2NATugMLCJitlLXb-djCpwG6AwsIzbeZ5_y2ndz9AboDCwiB_YCIsL3JxPYB%22%7D%7D%7D in service youtube2 Feb 19 21:20:39 volumio volumio[1218]: info: [youtube2-browse] explodeUri: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Ti%E1%BA%BFng%20H%C3%A1t%20Ng%E1%BB%8Dt%20Qu%C3%A1%20%C4%90%E1%BB%97i%20V%E1%BB%9Bi%20Ca%20Kh%C3%BAc%20Th%C6%B0%20T%C3%ACnh%20Em%20G%C3%A1i%20-%20Thu%20H%C6%B0%E1%BB%9Dng%22%2C%22artist%22%3A%22Gi%E1%BB%8Dng%20Ca%20%C4%90%E1%BB%83%20%C4%90%E1%BB%9Di%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2F4RDOn6cZLPg%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAV98OEkBisnS39aGb4z_MKmlR3wA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%224RDOn6cZLPg%22%2C%22params%22%3A%22qgMMdGh1IGjGsOG7nW5nugMkEiJQTEdSZDhUTlJ4OHN0bERZeXlGbWRVeDMtaV9YMkg4SnBsugMcEhpSREVNQjBiQkstbHVCbVNDVmU3ZGlEWFpYQboDCwic3uTIgq2Y26MBugMLCNL_wPOJu9y5lAG6AwoIxOim6YXkjN5OugMLCKOIwOqxhtzGmwG6AwoIzaDuvoiTl9E1ugMLCPz81LKAiLbcpwG6AwsIoNnK8LrV8-uSAboDCwiCssS15uDtlIoBugMLCJu005u_sZuswQG6AwsIk8iQ8NaV5dmXAboDCgiAmJm21Yzb8kK6AwoIoqi6j4Wcrs4WugMLCNyhpZiXyIu86wG6AwoI-5-h-8qi2NATugMLCJitlLXb-djCpwG6AwsIzbeZ5_y2ndz9AboDCwiB_YCIsL3JxPYB%22%7D%7D%7D Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::volumioPushQueue Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::saveQueue Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::updateTrackBlock Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrackBlock Feb 19 21:20:39 volumio volumio[1218]: info: CoreCommandRouter::volumioPlay Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::play index 0 Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::stop Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::play index undefined Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::startPlaybackTimer Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:39 volumio volumio[1218]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%224RDOn6cZLPg%22%2C%22params%22%3A%22qgMMdGh1IGjGsOG7nW5nugMkEiJQTEdSZDhUTlJ4OHN0bERZeXlGbWRVeDMtaV9YMkg4SnBsugMcEhpSREVNQjBiQkstbHVCbVNDVmU3ZGlEWFpYQboDCwic3uTIgq2Y26MBugMLCNL_wPOJu9y5lAG6AwoIxOim6YXkjN5OugMLCKOIwOqxhtzGmwG6AwoIzaDuvoiTl9E1ugMLCPz81LKAiLbcpwG6AwsIoNnK8LrV8-uSAboDCwiCssS15uDtlIoBugMLCJu005u_sZuswQG6AwsIk8iQ8NaV5dmXAboDCgiAmJm21Yzb8kK6AwoIoqi6j4Wcrs4WugMLCNyhpZiXyIu86wG6AwoI-5-h-8qi2NATugMLCJitlLXb-djCpwG6AwsIzbeZ5_y2ndz9AboDCwiB_YCIsL3JxPYB%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Ti%E1%BA%BFng%20H%C3%A1t%20Ng%E1%BB%8Dt%20Qu%C3%A1%20%C4%90%E1%BB%97i%20V%E1%BB%9Bi%20Ca%20Kh%C3%BAc%20Th%C6%B0%20T%C3%ACnh%20Em%20G%C3%A1i%20-%20Thu%20H%C6%B0%E1%BB%9Dng%22%2C%22artist%22%3A%22Gi%E1%BB%8Dng%20Ca%20%C4%90%E1%BB%83%20%C4%90%E1%BB%9Di%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2F4RDOn6cZLPg%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAV98OEkBisnS39aGb4z_MKmlR3wA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%224RDOn6cZLPg%22%2C%22params%22%3A%22qgMMdGh1IGjGsOG7nW5nugMkEiJQTEdSZDhUTlJ4OHN0bERZeXlGbWRVeDMtaV9YMkg4SnBsugMcEhpSREVNQjBiQkstbHVCbVNDVmU3ZGlEWFpYQboDCwic3uTIgq2Y26MBugMLCNL_wPOJu9y5lAG6AwoIxOim6YXkjN5OugMLCKOIwOqxhtzGmwG6AwoIzaDuvoiTl9E1ugMLCPz81LKAiLbcpwG6AwsIoNnK8LrV8-uSAboDCwiCssS15uDtlIoBugMLCJu005u_sZuswQG6AwsIk8iQ8NaV5dmXAboDCgiAmJm21Yzb8kK6AwoIoqi6j4Wcrs4WugMLCNyhpZiXyIu86wG6AwoI-5-h-8qi2NATugMLCJitlLXb-djCpwG6AwsIzbeZ5_y2ndz9AboDCwiB_YCIsL3JxPYB%22%7D%7D%7D Feb 19 21:20:39 volumio volumio[1218]: info: sendMpdCommand stop took 28 milliseconds Feb 19 21:20:39 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 181. Feb 19 21:20:39 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:39 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:39 volumio go-librespot[4394]: Librespot-go daemon starting... Feb 19 21:20:39 volumio go-librespot[4394]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:39 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:39 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand stop Feb 19 21:20:39 volumio volumio[1218]: info: sendMpdCommand stop took 1 milliseconds Feb 19 21:20:39 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand clear Feb 19 21:20:39 volumio volumio[1218]: info: Feb 19 21:20:39 volumio volumio[1218]: ---------------------------- MPD announces system playlist update Feb 19 21:20:39 volumio volumio[1218]: info: Ignoring MPD Status Update Feb 19 21:20:39 volumio volumio[1218]: info: sendMpdCommand clear took 1 milliseconds Feb 19 21:20:39 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand addid "https://rr3---sn-8qj-i2iez.googlevideo.com/videoplayback?expire=1739996440&ei=uOi1Z7OzAqvJvcAPi5Wu2Ac&ip=14.247.105.16&id=o-ADPEv4e1nJYQaXsNKBiaNqIRNQuK2EpKZwSvhQutVVUp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1739974840%2C&mh=Fb&mm=31%2C29&mn=sn-8qj-i2iez%2Csn-8qj-i5o66&ms=au%2Crdu&mv=m&mvi=3&pl=23&rms=au%2Cau&initcwndbps=2858750&bui=AUWDL3wkGZuE5wlvo-aTMLhNYKz-zSAJVedsKJRvTrj1LIo8Oz5lct_dZn2N7px6bE9GvyKfvj_VKkpD&spc=RjZbSf1ROXr6UJEI93pYTCrIR3nW0SywOot2SV3qQnJ68oZLYpnmBEKl0Zb5hCY&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=Tn0A7kvUshzXKkKzsnpn22UQ&rqh=1&gir=yes&clen=6032376&dur=325.821&lmt=1714454715771429&mt=1739974403&fvip=6&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=4502434&n=n4Xe75ukgk-sLQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgXpzfYwopcICkTXVEBy319Utml0FOqRR8g7ax2jzhvTMCICR8cJ2QBYHALJWkHhA-Fb6iB4teaaqtRUvAtvY2aA8S&sig=AJfQdSswRQIhAO1IJzoRSGKMGMRuOZlvc3xEr2uulOO4NdVtD_lwys_MAiBkteU1j4fU663IWO4s_LELvDPHioZ0xGzxtzxV7FDwHA%3D%3D&pot=Mng3jMELMPVA7TewKRngmwQ3IZPLFr6DcJNKC8_W_E-YVjqaulZqJ0G8p3IgVaQEfqUz5oRgdmEYGTBVe4w_YPMXMpCfiYd96leE_5-y46aL334zIQHcRG5IhYOzCPZUES4biHg3ZzGyJLLhCPrcEdbg7rpL0A1glFE%3D&cver=2.20241121.01.00&t.YouTube" Feb 19 21:20:39 volumio volumio[1218]: error: updateQueue error: null Feb 19 21:20:39 volumio volumio[1218]: info: Feb 19 21:20:39 volumio volumio[1218]: ---------------------------- MPD announces system playlist update Feb 19 21:20:39 volumio volumio[1218]: info: Ignoring MPD Status Update Feb 19 21:20:39 volumio volumio[1218]: info: ------------------------------ 2ms Feb 19 21:20:39 volumio volumio[1218]: info: sendMpdCommand addid "https://rr3---sn-8qj-i2iez.googlevideo.com/videoplayback?expire=1739996440&ei=uOi1Z7OzAqvJvcAPi5Wu2Ac&ip=14.247.105.16&id=o-ADPEv4e1nJYQaXsNKBiaNqIRNQuK2EpKZwSvhQutVVUp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1739974840%2C&mh=Fb&mm=31%2C29&mn=sn-8qj-i2iez%2Csn-8qj-i5o66&ms=au%2Crdu&mv=m&mvi=3&pl=23&rms=au%2Cau&initcwndbps=2858750&bui=AUWDL3wkGZuE5wlvo-aTMLhNYKz-zSAJVedsKJRvTrj1LIo8Oz5lct_dZn2N7px6bE9GvyKfvj_VKkpD&spc=RjZbSf1ROXr6UJEI93pYTCrIR3nW0SywOot2SV3qQnJ68oZLYpnmBEKl0Zb5hCY&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=Tn0A7kvUshzXKkKzsnpn22UQ&rqh=1&gir=yes&clen=6032376&dur=325.821&lmt=1714454715771429&mt=1739974403&fvip=6&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=4502434&n=n4Xe75ukgk-sLQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgXpzfYwopcICkTXVEBy319Utml0FOqRR8g7ax2jzhvTMCICR8cJ2QBYHALJWkHhA-Fb6iB4teaaqtRUvAtvY2aA8S&sig=AJfQdSswRQIhAO1IJzoRSGKMGMRuOZlvc3xEr2uulOO4NdVtD_lwys_MAiBkteU1j4fU663IWO4s_LELvDPHioZ0xGzxtzxV7FDwHA%3D%3D&pot=Mng3jMELMPVA7TewKRngmwQ3IZPLFr6DcJNKC8_W_E-YVjqaulZqJ0G8p3IgVaQEfqUz5oRgdmEYGTBVe4w_YPMXMpCfiYd96leE_5-y46aL334zIQHcRG5IhYOzCPZUES4biHg3ZzGyJLLhCPrcEdbg7rpL0A1glFE%3D&cver=2.20241121.01.00&t.YouTube" took 1 milliseconds Feb 19 21:20:39 volumio volumio[1218]: verbose: MPD COMMAND [object Object] Feb 19 21:20:39 volumio volumio[1218]: verbose: MPD COMMAND [object Object] Feb 19 21:20:39 volumio volumio[1218]: verbose: MPD COMMAND [object Object] Feb 19 21:20:39 volumio volumio[1218]: info: Feb 19 21:20:39 volumio volumio[1218]: ---------------------------- MPD announces system playlist update Feb 19 21:20:39 volumio volumio[1218]: info: Ignoring MPD Status Update Feb 19 21:20:39 volumio volumio[1218]: info: ------------------------------ 1ms Feb 19 21:20:39 volumio volumio[1218]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 19 21:20:39 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand play Feb 19 21:20:39 volumio volumio[1218]: info: ------------------------------ 1ms Feb 19 21:20:39 volumio volumio[1218]: info: sendMpdCommand play took 0 milliseconds Feb 19 21:20:40 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:40 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:40 volumio ntpd[1289]: Soliciting pool server 103.70.115.65 Feb 19 21:20:40 volumio volumio[1218]: info: Feb 19 21:20:40 volumio volumio[1218]: ---------------------------- MPD announces state update: player Feb 19 21:20:40 volumio volumio[1218]: info: ControllerMpd::getState Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand status Feb 19 21:20:40 volumio volumio[1218]: info: sendMpdCommand status took 13 milliseconds Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::parseState Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 19 21:20:40 volumio volumio[1218]: info: Feb 19 21:20:40 volumio volumio[1218]: ---------------------------- MPD announces state update: player Feb 19 21:20:40 volumio volumio[1218]: info: ControllerMpd::getState Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand status Feb 19 21:20:40 volumio volumio[1218]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::parseTrackInfo Feb 19 21:20:40 volumio volumio[1218]: info: ControllerMpd::pushState Feb 19 21:20:40 volumio volumio[1218]: info: CoreCommandRouter::servicePushState Feb 19 21:20:40 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:40 volumio volumio[1218]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":326,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Tiếng Hát Ngọt Quá Đỗi Với Ca Khúc Thư Tình Em Gái - Thu Hường","artist":"Giọng Ca Để Đời","album":"YouTube","uri":"https://rr3---sn-8qj-i2iez.googlevideo.com/videoplayback?expire=1739996440&ei=uOi1Z7OzAqvJvcAPi5Wu2Ac&ip=14.247.105.16&id=o-ADPEv4e1nJYQaXsNKBiaNqIRNQuK2EpKZwSvhQutVVUp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1739974840%2C&mh=Fb&mm=31%2C29&mn=sn-8qj-i2iez%2Csn-8qj-i5o66&ms=au%2Crdu&mv=m&mvi=3&pl=23&rms=au%2Cau&initcwndbps=2858750&bui=AUWDL3wkGZuE5wlvo-aTMLhNYKz-zSAJVedsKJRvTrj1LIo8Oz5lct_dZn2N7px6bE9GvyKfvj_VKkpD&spc=RjZbSf1ROXr6UJEI93pYTCrIR3nW0SywOot2SV3qQnJ68oZLYpnmBEKl0Zb5hCY&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=Tn0A7kvUshzXKkKzsnpn22UQ&rqh=1&gir=yes&clen=6032376&dur=325.821&lmt=1714454715771429&mt=1739974403&fvip=6&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=4502434&n=n4Xe75ukgk-sLQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgXpzfYwopcICkTXVEBy319Utml0FOqRR8g7ax2jzhvTMCICR8cJ2QBYHALJWkHhA-Fb6iB4teaaqtRUvAtvY2aA8S&sig=AJfQdSswRQIhAO1IJzoRSGKMGMRuOZlvc3xEr2uulOO4NdVtD_lwys_MAiBkteU1j4fU663IWO4s_LELvDPHioZ0xGzxtzxV7FDwHA%3D%3D&pot=Mng3jMELMPVA7TewKRngmwQ3IZPLFr6DcJNKC8_W_E-YVjqaulZqJ0G8p3IgVaQEfqUz5oRgdmEYGTBVe4w_YPMXMpCfiYd96leE_5-y46aL334zIQHcRG5IhYOzCPZUES4biHg3ZzGyJLLhCPrcEdbg7rpL0A1glFE%3D&cver=2.20241121.01.00&t.YouTube","trackType":"YouTube"} Feb 19 21:20:40 volumio volumio[1218]: verbose: CURRENT POSITION 0 Feb 19 21:20:40 volumio volumio[1218]: info: CoreStateMachine::syncState stateService play Feb 19 21:20:40 volumio volumio[1218]: info: CoreStateMachine::syncState currentStatus stop Feb 19 21:20:40 volumio volumio[1218]: info: ------------------------------ 17ms Feb 19 21:20:40 volumio volumio[1218]: info: sendMpdCommand status took 3 milliseconds Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::parseState Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 19 21:20:40 volumio volumio[1218]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 19 21:20:40 volumio volumio[1218]: verbose: ControllerMpd::parseTrackInfo Feb 19 21:20:40 volumio volumio[1218]: info: ControllerMpd::pushState Feb 19 21:20:40 volumio volumio[1218]: info: CoreCommandRouter::servicePushState Feb 19 21:20:40 volumio volumio[1218]: info: CorePlayQueue::getTrack 0 Feb 19 21:20:40 volumio volumio[1218]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":326,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Tiếng Hát Ngọt Quá Đỗi Với Ca Khúc Thư Tình Em Gái - Thu Hường","artist":"Giọng Ca Để Đời","album":"YouTube","uri":"https://rr3---sn-8qj-i2iez.googlevideo.com/videoplayback?expire=1739996440&ei=uOi1Z7OzAqvJvcAPi5Wu2Ac&ip=14.247.105.16&id=o-ADPEv4e1nJYQaXsNKBiaNqIRNQuK2EpKZwSvhQutVVUp&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1739974840%2C&mh=Fb&mm=31%2C29&mn=sn-8qj-i2iez%2Csn-8qj-i5o66&ms=au%2Crdu&mv=m&mvi=3&pl=23&rms=au%2Cau&initcwndbps=2858750&bui=AUWDL3wkGZuE5wlvo-aTMLhNYKz-zSAJVedsKJRvTrj1LIo8Oz5lct_dZn2N7px6bE9GvyKfvj_VKkpD&spc=RjZbSf1ROXr6UJEI93pYTCrIR3nW0SywOot2SV3qQnJ68oZLYpnmBEKl0Zb5hCY&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=Tn0A7kvUshzXKkKzsnpn22UQ&rqh=1&gir=yes&clen=6032376&dur=325.821&lmt=1714454715771429&mt=1739974403&fvip=6&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=4502434&n=n4Xe75ukgk-sLQ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgXpzfYwopcICkTXVEBy319Utml0FOqRR8g7ax2jzhvTMCICR8cJ2QBYHALJWkHhA-Fb6iB4teaaqtRUvAtvY2aA8S&sig=AJfQdSswRQIhAO1IJzoRSGKMGMRuOZlvc3xEr2uulOO4NdVtD_lwys_MAiBkteU1j4fU663IWO4s_LELvDPHioZ0xGzxtzxV7FDwHA%3D%3D&pot=Mng3jMELMPVA7TewKRngmwQ3IZPLFr6DcJNKC8_W_E-YVjqaulZqJ0G8p3IgVaQEfqUz5oRgdmEYGTBVe4w_YPMXMpCfiYd96leE_5-y46aL334zIQHcRG5IhYOzCPZUES4biHg3ZzGyJLLhCPrcEdbg7rpL0A1glFE%3D&cver=2.20241121.01.00&t.YouTube","trackType":"YouTube"} Feb 19 21:20:40 volumio volumio[1218]: verbose: CURRENT POSITION 0 Feb 19 21:20:40 volumio volumio[1218]: info: CoreStateMachine::syncState stateService play Feb 19 21:20:40 volumio volumio[1218]: info: CoreStateMachine::syncState currentStatus play Feb 19 21:20:40 volumio volumio[1218]: info: Received an update from plugin. extracting info from payload Feb 19 21:20:40 volumio volumio[1218]: info: CoreStateMachine::pushState Feb 19 21:20:40 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 19 21:20:40 volumio volumio[1218]: info: CoreCommandRouter::volumioPushState Feb 19 21:20:40 volumio volumio[1218]: info: CoreStateMachine::pushState Feb 19 21:20:40 volumio volumio[1218]: info: CoreCommandRouter::volumioPushState Feb 19 21:20:40 volumio volumio[1218]: info: ------------------------------ 20ms Feb 19 21:20:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 182. Feb 19 21:20:42 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:42 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:42 volumio go-librespot[4403]: Librespot-go daemon starting... Feb 19 21:20:42 volumio go-librespot[4403]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:43 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:43 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:46 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:46 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 183. Feb 19 21:20:46 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:46 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:46 volumio go-librespot[4408]: Librespot-go daemon starting... Feb 19 21:20:46 volumio go-librespot[4408]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:48 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 19 21:20:48 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 19 21:20:48 volumio volumio[1218]: info: Discovery: Getting this device information Feb 19 21:20:48 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:48 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 19 21:20:49 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:49 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:49 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:20:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 184. Feb 19 21:20:49 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:49 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:49 volumio go-librespot[4424]: Librespot-go daemon starting... Feb 19 21:20:49 volumio go-librespot[4424]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:52 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:52 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 185. Feb 19 21:20:52 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:52 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:52 volumio go-librespot[4427]: Librespot-go daemon starting... Feb 19 21:20:52 volumio go-librespot[4427]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:55 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:55 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 186. Feb 19 21:20:55 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:55 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:55 volumio go-librespot[4441]: Librespot-go daemon starting... Feb 19 21:20:55 volumio go-librespot[4441]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:20:57 volumio volumio[1218]: error: error Feb 19 21:20:57 volumio volumio[1218]: error: error Feb 19 21:20:58 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:20:58 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:20:59 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:20:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 187. Feb 19 21:20:59 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:20:59 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:20:59 volumio go-librespot[4458]: Librespot-go daemon starting... Feb 19 21:20:59 volumio go-librespot[4458]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:20:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:20:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:01 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:01 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 188. Feb 19 21:21:02 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:02 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:02 volumio go-librespot[4462]: Librespot-go daemon starting... Feb 19 21:21:02 volumio go-librespot[4462]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:04 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:04 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 189. Feb 19 21:21:05 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:05 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:05 volumio go-librespot[4467]: Librespot-go daemon starting... Feb 19 21:21:05 volumio go-librespot[4467]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:07 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:07 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 190. Feb 19 21:21:08 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:08 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:08 volumio go-librespot[4483]: Librespot-go daemon starting... Feb 19 21:21:08 volumio go-librespot[4483]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:10 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:10 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 191. Feb 19 21:21:12 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:12 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:12 volumio go-librespot[4486]: Librespot-go daemon starting... Feb 19 21:21:12 volumio go-librespot[4486]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:13 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:13 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 192. Feb 19 21:21:15 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:15 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:15 volumio go-librespot[4491]: Librespot-go daemon starting... Feb 19 21:21:15 volumio go-librespot[4491]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:16 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:16 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 193. Feb 19 21:21:18 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:18 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:18 volumio go-librespot[4508]: Librespot-go daemon starting... Feb 19 21:21:18 volumio go-librespot[4508]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 19 21:21:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 19 21:21:18 volumio volumio[1218]: info: Discovery: Getting this device information Feb 19 21:21:18 volumio volumio[1218]: info: CoreCommandRouter::volumioGetState Feb 19 21:21:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 19 21:21:18 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 19 21:21:18 volumio volumio[1218]: info: CURURI: music-library Feb 19 21:21:18 volumio volumio[1218]: error: Failed LSINFO: null Feb 19 21:21:19 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:21:19 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:19 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 194. Feb 19 21:21:21 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:21 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:21 volumio go-librespot[4512]: Librespot-go daemon starting... Feb 19 21:21:21 volumio go-librespot[4512]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:22 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:22 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:23 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 19 21:21:23 volumio volumio[1218]: info: CURURI: albums:// Feb 19 21:21:23 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:21:25 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:25 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 195. Feb 19 21:21:25 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:25 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:25 volumio go-librespot[4519]: Librespot-go daemon starting... Feb 19 21:21:25 volumio go-librespot[4519]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:26 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 19 21:21:26 volumio volumio[1218]: info: CURURI: playlists Feb 19 21:21:26 volumio volumio[1218]: info: Listing playlists Feb 19 21:21:26 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:21:28 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:28 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 196. Feb 19 21:21:28 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:28 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:28 volumio go-librespot[4535]: Librespot-go daemon starting... Feb 19 21:21:28 volumio go-librespot[4535]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:31 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:31 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 197. Feb 19 21:21:31 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:31 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:31 volumio go-librespot[4538]: Librespot-go daemon starting... Feb 19 21:21:31 volumio go-librespot[4538]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:32 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 19 21:21:32 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:21:34 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:34 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 198. Feb 19 21:21:34 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:34 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:34 volumio go-librespot[4587]: Librespot-go daemon starting... Feb 19 21:21:34 volumio go-librespot[4587]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:35 volumio ntpd[1289]: Soliciting pool server 103.184.124.254 Feb 19 21:21:35 volumio ntpd[1289]: Soliciting pool server 27.71.27.209 Feb 19 21:21:37 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:37 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:37 volumio ntpd[1289]: Soliciting pool server 103.199.19.135 Feb 19 21:21:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 199. Feb 19 21:21:38 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:38 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:38 volumio go-librespot[4604]: Librespot-go daemon starting... Feb 19 21:21:38 volumio go-librespot[4604]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:39 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 19 21:21:39 volumio volumio[1218]: error: Error browsing0:Error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"801"}],"errorDescription":[{"_":"Access denied"}]}]}]}]}]}} Feb 19 21:21:39 volumio volumio[1218]: error: Failed to execute browseSource: Feb 19 21:21:40 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:40 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 19 21:21:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 200. Feb 19 21:21:41 volumio systemd[1]: Stopped go-librespot Daemon. Feb 19 21:21:41 volumio systemd[1]: Started go-librespot Daemon. Feb 19 21:21:41 volumio go-librespot[4608]: Librespot-go daemon starting... Feb 19 21:21:41 volumio go-librespot[4608]: /bin/start-go-liberspot.sh: 11: /bin/start-go-liberspot.sh: /usr/bin/go-librespot: not found Feb 19 21:21:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=127/n/a Feb 19 21:21:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 19 21:21:41 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 19 21:21:42 volumio volumio[1218]: info: Preload queue cleared Feb 19 21:21:43 volumio volumio[1218]: info: Initializing connection to go-librespot Websocket Feb 19 21:21:43 volumio volumio[1218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 19 21:21:44 volumio volumio[1218]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 19 21:21:44 volumio volumio[1218]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 21:21:44 volumio volumio[1218]: TypeError: Cannot read property 'length' of undefined Feb 19 21:21:44 volumio volumio[1218]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Feb 19 21:21:44 volumio volumio[1218]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Feb 19 21:21:44 volumio volumio[1218]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Feb 19 21:21:44 volumio volumio[1218]: at Parser.emit (events.js:400:28) Feb 19 21:21:44 volumio volumio[1218]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Feb 19 21:21:44 volumio volumio[1218]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Feb 19 21:21:44 volumio volumio[1218]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Feb 19 21:21:44 volumio volumio[1218]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Feb 19 21:21:44 volumio volumio[1218]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Feb 19 21:21:44 volumio volumio[1218]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Feb 19 21:21:44 volumio volumio[1218]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Feb 19 21:21:44 volumio volumio[1218]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Feb 19 21:21:44 volumio volumio[1218]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Feb 19 21:21:44 volumio volumio[1218]: at IncomingMessage.emit (events.js:412:35) Feb 19 21:21:44 volumio volumio[1218]: at endReadableNT (internal/streams/readable.js:1333:12) Feb 19 21:21:44 volumio volumio[1218]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Feb 19 21:21:44 volumio volumio[1218]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 19 21:21:44 volumio sudo[4619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-19 21:20 Feb 19 21:21:44 volumio sudo[4619]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"