-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-01-16 00:20:39 CET. -- Jan 16 00:19:00 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 16 00:19:00 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 16 00:19:00 networkplayer volumio[897]: info: Discovery: Getting this device information Jan 16 00:19:00 networkplayer volumio[897]: info: CoreCommandRouter::volumioGetState Jan 16 00:19:00 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:00 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 16 00:19:02 networkplayer volumio[897]: info: Preload queue cleared Jan 16 00:19:02 networkplayer volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::ClearQueue Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::stop Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::clearPlayQueue Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::saveQueue Jan 16 00:19:02 networkplayer volumio[897]: info: CoreCommandRouter::volumioPushQueue Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::addQueueItems Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::addQueueItems Jan 16 00:19:02 networkplayer volumio[897]: info: Preload queue cleared Jan 16 00:19:02 networkplayer volumio[897]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s15480 Jan 16 00:19:02 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 16 00:19:02 networkplayer volumio[897]: info: CoreCommandRouter::volumioPushQueue Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::saveQueue Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::updateTrackBlock Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::getTrackBlock Jan 16 00:19:02 networkplayer volumio[897]: info: CoreCommandRouter::volumioPlay Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::play index 0 Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::stop Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::play index undefined Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:02 networkplayer volumio[897]: info: CoreStateMachine::startPlaybackTimer Jan 16 00:19:02 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:02 networkplayer volumio[897]: info: [1736983142526] ControllerWebradio::clearAddPlayTrack Jan 16 00:19:02 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Jan 16 00:19:02 networkplayer volumio[897]: info: sendMpdCommand stop took 4 milliseconds Jan 16 00:19:02 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand clear Jan 16 00:19:02 networkplayer volumio[897]: info: Jan 16 00:19:02 networkplayer volumio[897]: ---------------------------- MPD announces system playlist update Jan 16 00:19:02 networkplayer volumio[897]: info: Ignoring MPD Status Update Jan 16 00:19:02 networkplayer volumio[897]: info: sendMpdCommand clear took 2 milliseconds Jan 16 00:19:02 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand load "https://stream.streambase.ch/rsunshine/mp3-192/tunein/" Jan 16 00:19:02 networkplayer volumio[897]: info: Jan 16 00:19:02 networkplayer volumio[897]: ---------------------------- MPD announces system playlist update Jan 16 00:19:02 networkplayer volumio[897]: info: Ignoring MPD Status Update Jan 16 00:19:02 networkplayer volumio[897]: error: updateQueue error: null Jan 16 00:19:02 networkplayer volumio[897]: info: ------------------------------ 6ms Jan 16 00:19:02 networkplayer volumio[897]: error: Upnp client error: Error: This socket has been ended by the other party Jan 16 00:19:05 networkplayer systemd[1]: Stopping Music Player Daemon... Jan 16 00:19:05 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand add "https://stream.streambase.ch/rsunshine/mp3-192/tunein/" Jan 16 00:19:05 networkplayer volumio[897]: error: Upnp client error: Error: read ECONNRESET Jan 16 00:19:05 networkplayer volumio[897]: error: MPD error: Error: read ECONNRESET Jan 16 00:19:05 networkplayer systemd[1]: mpd.service: Succeeded. Jan 16 00:19:05 networkplayer systemd[1]: Stopped Music Player Daemon. Jan 16 00:19:05 networkplayer systemd[1]: Starting Music Player Daemon... Jan 16 00:19:05 networkplayer sudo[2121]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 16 00:19:05 networkplayer sudo[2121]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 16 00:19:05 networkplayer sudo[2121]: pam_unix(sudo:session): session closed for user root Jan 16 00:19:06 networkplayer mpd[2123]: Jan 16 00:19 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 16 00:19:06 networkplayer systemd[1]: Started Music Player Daemon. Jan 16 00:19:06 networkplayer mpd_monitor.sh[645]: MPD restarted due to no mpc output. Jan 16 00:19:07 networkplayer volumio[897]: info: Preload queue cleared Jan 16 00:19:07 networkplayer volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::ClearQueue Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::stop Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::clearPlayQueue Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::saveQueue Jan 16 00:19:07 networkplayer volumio[897]: info: CoreCommandRouter::volumioPushQueue Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::addQueueItems Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::addQueueItems Jan 16 00:19:07 networkplayer volumio[897]: info: Preload queue cleared Jan 16 00:19:07 networkplayer volumio[897]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s15480 Jan 16 00:19:07 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 16 00:19:07 networkplayer volumio[897]: info: CoreCommandRouter::volumioPushQueue Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::saveQueue Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::updateTrackBlock Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::getTrackBlock Jan 16 00:19:07 networkplayer volumio[897]: info: CoreCommandRouter::volumioPlay Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::play index 0 Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::stop Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::play index undefined Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:07 networkplayer volumio[897]: info: CoreStateMachine::startPlaybackTimer Jan 16 00:19:07 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:07 networkplayer volumio[897]: info: [1736983147317] ControllerWebradio::clearAddPlayTrack Jan 16 00:19:07 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Jan 16 00:19:08 networkplayer volumio[897]: error: Upnp client error: Error: This socket has been ended by the other party Jan 16 00:19:10 networkplayer volumio[897]: error: updateQueue error: null Jan 16 00:19:13 networkplayer ntpd[794]: Soliciting pool server 82.197.162.18 Jan 16 00:19:14 networkplayer ntpd[794]: Soliciting pool server 81.94.123.16 Jan 16 00:19:15 networkplayer volumio[897]: info: Preload queue cleared Jan 16 00:19:15 networkplayer volumio[897]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::ClearQueue Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::stop Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::clearPlayQueue Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::saveQueue Jan 16 00:19:15 networkplayer volumio[897]: info: CoreCommandRouter::volumioPushQueue Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::addQueueItems Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::addQueueItems Jan 16 00:19:15 networkplayer volumio[897]: info: Preload queue cleared Jan 16 00:19:15 networkplayer volumio[897]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s15480 Jan 16 00:19:15 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 16 00:19:15 networkplayer volumio[897]: info: CoreCommandRouter::volumioPushQueue Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::saveQueue Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::updateTrackBlock Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::getTrackBlock Jan 16 00:19:15 networkplayer volumio[897]: info: CoreCommandRouter::volumioPlay Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::play index 0 Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::stop Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::play index undefined Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:15 networkplayer volumio[897]: info: CoreStateMachine::startPlaybackTimer Jan 16 00:19:15 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:15 networkplayer volumio[897]: info: [1736983155856] ControllerWebradio::clearAddPlayTrack Jan 16 00:19:15 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand stop Jan 16 00:19:15 networkplayer volumio[897]: info: sendMpdCommand stop took 4 milliseconds Jan 16 00:19:15 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand clear Jan 16 00:19:15 networkplayer volumio[897]: info: Jan 16 00:19:15 networkplayer volumio[897]: ---------------------------- MPD announces system playlist update Jan 16 00:19:15 networkplayer volumio[897]: info: Ignoring MPD Status Update Jan 16 00:19:15 networkplayer volumio[897]: info: sendMpdCommand clear took 1 milliseconds Jan 16 00:19:15 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand load "https://stream.streambase.ch/rsunshine/mp3-192/tunein/" Jan 16 00:19:15 networkplayer volumio[897]: error: updateQueue error: null Jan 16 00:19:15 networkplayer volumio[897]: info: ------------------------------ 2ms Jan 16 00:19:16 networkplayer ntpd[794]: Soliciting pool server 212.51.144.47 Jan 16 00:19:16 networkplayer ntpd[794]: Soliciting pool server 212.243.96.76 Jan 16 00:19:18 networkplayer systemd[1]: Stopping Music Player Daemon... Jan 16 00:19:18 networkplayer volumio[897]: verbose: ControllerMpd::sendMpdCommand add "https://stream.streambase.ch/rsunshine/mp3-192/tunein/" Jan 16 00:19:18 networkplayer volumio[897]: error: MPD error: Error: read ECONNRESET Jan 16 00:19:18 networkplayer systemd[1]: mpd.service: Succeeded. Jan 16 00:19:18 networkplayer systemd[1]: Stopped Music Player Daemon. Jan 16 00:19:18 networkplayer systemd[1]: Starting Music Player Daemon... Jan 16 00:19:18 networkplayer sudo[2147]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 16 00:19:18 networkplayer sudo[2147]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 16 00:19:18 networkplayer sudo[2147]: pam_unix(sudo:session): session closed for user root Jan 16 00:19:19 networkplayer mpd[2149]: Jan 16 00:19 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 16 00:19:19 networkplayer systemd[1]: Started Music Player Daemon. Jan 16 00:19:19 networkplayer mpd_monitor.sh[645]: MPD restarted due to no mpc output. Jan 16 00:19:23 networkplayer volumio[897]: error: updateQueue error: null Jan 16 00:19:30 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 16 00:19:30 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 16 00:19:30 networkplayer volumio[897]: info: Discovery: Getting this device information Jan 16 00:19:30 networkplayer volumio[897]: info: CoreCommandRouter::volumioGetState Jan 16 00:19:30 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:19:30 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 16 00:19:35 networkplayer volumio[897]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 00:19:35 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 16 00:19:35 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 16 00:19:35 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 16 00:19:35 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jan 16 00:19:35 networkplayer volumio[897]: info: Received Get System Version Jan 16 00:19:35 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 16 00:19:39 networkplayer volumio[897]: info: CALLMETHOD: system_controller system saveGeneralSettings [object Object] Jan 16 00:19:39 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Jan 16 00:19:54 networkplayer volumio[897]: info: CALLMETHOD: system_controller system saveUpdateSettings [object Object] Jan 16 00:19:54 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , saveUpdateSettings Jan 16 00:19:54 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Jan 16 00:19:54 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 16 00:19:54 networkplayer volumio-remote-updater[616]: No test mode Jan 16 00:19:54 networkplayer volumio-remote-updater[616]: No alpha test mode Jan 16 00:19:54 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 16 00:19:54 networkplayer volumio[897]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 16 00:19:54 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 16 00:19:55 networkplayer volumio[897]: info: CALLMETHOD: system_controller system saveUpdateSettings [object Object] Jan 16 00:19:55 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , saveUpdateSettings Jan 16 00:19:55 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Jan 16 00:19:55 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 16 00:19:55 networkplayer volumio-remote-updater[616]: No test mode Jan 16 00:19:55 networkplayer volumio-remote-updater[616]: No alpha test mode Jan 16 00:19:55 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 16 00:19:55 networkplayer volumio[897]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 16 00:19:55 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 16 00:20:00 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 16 00:20:00 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 16 00:20:00 networkplayer volumio[897]: info: Discovery: Getting this device information Jan 16 00:20:00 networkplayer volumio[897]: info: CoreCommandRouter::volumioGetState Jan 16 00:20:00 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:20:00 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 16 00:20:01 networkplayer volumio[897]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 00:20:01 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 16 00:20:01 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 16 00:20:01 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 16 00:20:01 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jan 16 00:20:01 networkplayer volumio[897]: info: Received Get System Version Jan 16 00:20:01 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 16 00:20:04 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 16 00:20:04 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 16 00:20:09 networkplayer volumio[897]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 00:20:13 networkplayer volumio[897]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 16 00:20:13 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 16 00:20:13 networkplayer volumio[897]: info: Creating Spotify config file Jan 16 00:20:13 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 16 00:20:13 networkplayer volumio[897]: info: Spotify config file written Jan 16 00:20:14 networkplayer sudo[2336]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 16 00:20:14 networkplayer sudo[2336]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 16 00:20:14 networkplayer systemd[1]: Stopping go-librespot Daemon... Jan 16 00:20:14 networkplayer systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jan 16 00:20:14 networkplayer systemd[1]: go-librespot-daemon.service: Succeeded. Jan 16 00:20:14 networkplayer systemd[1]: Stopped go-librespot Daemon. Jan 16 00:20:14 networkplayer volumio[897]: info: Connection to go-librespot Websocket closed Jan 16 00:20:14 networkplayer systemd[1]: Started go-librespot Daemon. Jan 16 00:20:14 networkplayer go-librespot[2338]: Librespot-go daemon starting... Jan 16 00:20:14 networkplayer sudo[2336]: pam_unix(sudo:session): session closed for user root Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=info msg="generated new device id: 2c72241c9716dc9b433a7cacb39342d3d6d2bb63" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="stored credentials found for radicalix" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="zeroconf server listening on port 34981" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="obtained new client token: AAD2pZCEnCkCiMQAboL+yhQ6axbQh+5hpUFyjT5Nl0tBUhPS2QWmdAwwEPelLcZv1gBohHjRLzayUCjhMOeKG7uvG3Fe98qRVpAkqk/3+rPB3q+g+hRuJJtitpyHRyXrARmLkP+jK4gVuB+EoZVHJoQbMNTncIVs2p3Kdhi2D4WRXFx05WMJnTYzjMMp50/u3oSPKXCc5ErIyqzwVB3NVyfsTuMPQAhbJ9psk+vJNDGkGOkHrdUMFKj8aw==" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="completed keyexchange" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="completed challenge" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="authenticated as radicalix" Jan 16 00:20:14 networkplayer go-librespot[2338]: time="2025-01-16T00:20:14+01:00" level=debug msg="authenticated as radicalix" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="dealer connection opened" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="initializing zeroconf session, username: radicalix" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="autoplay enabled: false" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="received connection id: MGZhN2RmZmEtZGE0ZC00YThhLThkZmQtOWM1ZjU3NGZkMTMxK2RlYWxlcit0Y3A6Ly8wYWNhNTlhNS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMTQ2QkMwOTEwQzYxREMxQkMwQjg4NjMyNUVCRjJGMUM1MzQ2NDNCNTFGNDM0OTM0RjA1NUJERjc4MzQyOUUxNA==" Jan 16 00:20:15 networkplayer go-librespot[2338]: time="2025-01-16T00:20:15+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 16 00:20:17 networkplayer ntpd[794]: Soliciting pool server 193.134.29.12 Jan 16 00:20:17 networkplayer volumio[897]: info: Initializing connection to go-librespot Websocket Jan 16 00:20:17 networkplayer go-librespot[2338]: time="2025-01-16T00:20:17+01:00" level=debug msg="new websocket client" Jan 16 00:20:17 networkplayer volumio[897]: info: Connection to go-librespot Websocket established Jan 16 00:20:17 networkplayer volumio[897]: info: go-librespot daemon successfully initialized Jan 16 00:20:20 networkplayer volumio[897]: info: Getting Spotify volume Jan 16 00:20:20 networkplayer volumio[897]: info: Spotify volume: 100 Jan 16 00:20:20 networkplayer volumio[897]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jan 16 00:20:20 networkplayer volumio[897]: info: CoreCommandRouter::volumioGetState Jan 16 00:20:20 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:20:20 networkplayer volumio[897]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 16 00:20:20 networkplayer volumio[897]: SPOTIFY: SPOTIFY VOLUME 100 Jan 16 00:20:20 networkplayer volumio[897]: SPOTIFY: VOLUMIO VOLUME 86 Jan 16 00:20:20 networkplayer volumio[897]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 16 00:20:20 networkplayer volumio[897]: info: Setting Spotify Volume from Volumio: 86 Jan 16 00:20:20 networkplayer volumio[897]: info: Initializing connection to go-librespot Websocket Jan 16 00:20:20 networkplayer go-librespot[2338]: time="2025-01-16T00:20:20+01:00" level=debug msg="new websocket client" Jan 16 00:20:20 networkplayer volumio[897]: info: Connection to go-librespot Websocket established Jan 16 00:20:20 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 16 00:20:20 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 16 00:20:21 networkplayer ntpd[794]: Soliciting pool server 84.16.73.33 Jan 16 00:20:21 networkplayer volumio[897]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Jan 16 00:20:21 networkplayer volumio[897]: info: Sending Spotify command with payload to local API: /player/volume Jan 16 00:20:21 networkplayer go-librespot[2338]: time="2025-01-16T00:20:21+01:00" level=debug msg="update volume to 56360/65535" Jan 16 00:20:21 networkplayer go-librespot[2338]: time="2025-01-16T00:20:21+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 00:20:21 networkplayer go-librespot[2338]: time="2025-01-16T00:20:21+01:00" level=trace msg="emitting websocket event: volume" Jan 16 00:20:21 networkplayer volumio[897]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Jan 16 00:20:21 networkplayer volumio[897]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Jan 16 00:20:21 networkplayer volumio[897]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Jan 16 00:20:21 networkplayer volumio[897]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Jan 16 00:20:22 networkplayer ntpd[794]: Soliciting pool server 193.33.30.39 Jan 16 00:20:23 networkplayer ntpd[794]: Soliciting pool server 217.147.223.78 Jan 16 00:20:23 networkplayer volumio[897]: info: Getting Spotify volume Jan 16 00:20:23 networkplayer volumio[897]: info: Spotify volume: 86 Jan 16 00:20:23 networkplayer volumio[897]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jan 16 00:20:23 networkplayer volumio[897]: info: CoreCommandRouter::volumioGetState Jan 16 00:20:23 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:20:23 networkplayer volumio[897]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 16 00:20:24 networkplayer volumio[897]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 00:20:24 networkplayer volumio[897]: info: [ASDebug] Setting UI defaults Jan 16 00:20:24 networkplayer volumio[897]: info: [ASDebug] Port: 24 Jan 16 00:20:24 networkplayer volumio[897]: info: [ASDebug] Inverted: false Jan 16 00:20:24 networkplayer volumio[897]: info: [ASDebug] Latched: false Jan 16 00:20:24 networkplayer volumio[897]: info: [ASDebug] On pulse width: 500 Jan 16 00:20:24 networkplayer volumio[897]: info: [ASDebug] Off pulse width: 500 Jan 16 00:20:27 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 16 00:20:27 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 16 00:20:30 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 16 00:20:30 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 16 00:20:30 networkplayer volumio[897]: info: Discovery: Getting this device information Jan 16 00:20:30 networkplayer volumio[897]: info: CoreCommandRouter::volumioGetState Jan 16 00:20:30 networkplayer volumio[897]: info: CorePlayQueue::getTrack 0 Jan 16 00:20:30 networkplayer volumio[897]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 16 00:20:31 networkplayer volumio[897]: info: Starting Uninstall of plugin system_controller - ampswitch Jan 16 00:20:31 networkplayer volumio[897]: info: Uninstalling plugin ampswitch Jan 16 00:20:31 networkplayer volumio[897]: info: [ASDebug] Port: 24 Jan 16 00:20:31 networkplayer volumio[897]: info: [ASDebug] Inverted: false Jan 16 00:20:31 networkplayer volumio[897]: info: [ASDebug] Delay: 720 Jan 16 00:20:39 networkplayer volumio[897]: info: [ASDebug] Port: 24 Jan 16 00:20:39 networkplayer volumio[897]: info: [ASDebug] Inverted: false Jan 16 00:20:39 networkplayer volumio[897]: info: [ASDebug] Delay: 720 Jan 16 00:20:39 networkplayer volumio[897]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 16 00:20:39 networkplayer volumio[897]: Error: EBADF: bad file descriptor, close Jan 16 00:20:39 networkplayer volumio[897]: at Object.closeSync (fs.js:439:3) Jan 16 00:20:39 networkplayer volumio[897]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Jan 16 00:20:39 networkplayer volumio[897]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Jan 16 00:20:39 networkplayer volumio[897]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Jan 16 00:20:39 networkplayer volumio[897]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Jan 16 00:20:39 networkplayer volumio[897]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Jan 16 00:20:39 networkplayer volumio[897]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Jan 16 00:20:39 networkplayer volumio[897]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Jan 16 00:20:39 networkplayer volumio[897]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1550:29) Jan 16 00:20:39 networkplayer volumio[897]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1395:47) Jan 16 00:20:39 networkplayer volumio[897]: at Socket.emit (events.js:315:20) Jan 16 00:20:39 networkplayer volumio[897]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jan 16 00:20:39 networkplayer volumio[897]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Jan 16 00:20:39 networkplayer volumio[897]: errno: -9, Jan 16 00:20:39 networkplayer volumio[897]: syscall: 'close', Jan 16 00:20:39 networkplayer volumio[897]: code: 'EBADF' Jan 16 00:20:39 networkplayer volumio[897]: } Jan 16 00:20:39 networkplayer volumio[897]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 16 00:20:39 networkplayer sudo[2391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-16 00:19 Jan 16 00:20:39 networkplayer sudo[2391]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"