Jun 13 22:50:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:05 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:09 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:13 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:17 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:21 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:25 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:26 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 13 22:50:26 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 13 22:50:26 volumio volumio[1206]: info: Discovery: Getting this device information Jun 13 22:50:26 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState Jun 13 22:50:26 volumio volumio[1206]: info: CorePlayQueue::getTrack 0 Jun 13 22:50:26 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 13 22:50:29 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:33 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:37 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:41 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:45 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:48 volumio volumio[1206]: info: CALLMETHOD: miscellanea my_music updateMusicLibraryBrowseSourcesVisibility [object Object] Jun 13 22:50:48 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibraryBrowseSourcesVisibility Jun 13 22:50:48 volumio volumio[1206]: info: CoreCommandRouter::volumioUpdateToBrowseSources Jun 13 22:50:48 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 13 22:50:48 volumio volumio[1206]: Cannot find translation for source YouTube2 Jun 13 22:50:48 volumio volumio[1206]: Cannot find translation for source YouTube Music Jun 13 22:50:48 volumio volumio[1206]: Cannot find translation for source Spotify Jun 13 22:50:49 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 13 22:50:53 volumio volumio[1206]: info: CoreCommandRouter::volumioPlay Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::play index 7 Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::stop Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::play index undefined Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 22:50:53 volumio volumio[1206]: info: CorePlayQueue::getTrack 7 Jun 13 22:50:53 volumio volumio[1206]: info: CoreStateMachine::startPlaybackTimer Jun 13 22:50:53 volumio volumio[1206]: info: CorePlayQueue::getTrack 7 Jun 13 22:50:53 volumio volumio[1206]: info: [1749880253855] ControllerSpotify::clearAddPlayTrack Jun 13 22:50:53 volumio volumio[1206]: info: Sending Spotify command with payload to local API: /player/play Jun 13 22:50:55 volumio volumio[1206]: info: CoreCommandRouter::volumioPlay Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::play index 7 Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::stop Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::play index undefined Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 13 22:50:55 volumio volumio[1206]: info: CorePlayQueue::getTrack 7 Jun 13 22:50:55 volumio volumio[1206]: info: CoreStateMachine::startPlaybackTimer Jun 13 22:50:55 volumio volumio[1206]: info: CorePlayQueue::getTrack 7 Jun 13 22:50:55 volumio volumio[1206]: info: [1749880255249] ControllerSpotify::clearAddPlayTrack Jun 13 22:50:55 volumio volumio[1206]: info: Sending Spotify command with payload to local API: /player/play Jun 13 22:50:56 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 13 22:50:56 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 13 22:50:56 volumio volumio[1206]: info: Discovery: Getting this device information Jun 13 22:50:56 volumio volumio[1206]: info: CoreCommandRouter::volumioGetState Jun 13 22:50:56 volumio volumio[1206]: info: CorePlayQueue::getTrack 7 Jun 13 22:50:56 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 13 22:51:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 13 22:51:01 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 13 22:51:07 volumio volumio[1206]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 13 22:51:08 volumio volumio[1206]: info: CALLMETHOD: music_service spop logout Jun 13 22:51:08 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: spop , logout Jun 13 22:51:08 volumio volumio[1206]: info: Deleting Spotify credentials File Jun 13 22:51:08 volumio volumio[1206]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Jun 13 22:51:08 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 13 22:51:08 volumio volumio[1206]: Cannot find translation for source YouTube2 Jun 13 22:51:08 volumio volumio[1206]: Cannot find translation for source YouTube Music Jun 13 22:51:09 volumio volumio[1206]: info: Creating Spotify config file Jun 13 22:51:09 volumio volumio[1206]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 13 22:51:09 volumio volumio[1206]: info: Spotify config file written Jun 13 22:51:09 volumio sudo[2498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 13 22:51:09 volumio sudo[2498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 13 22:51:09 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 13 22:51:09 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jun 13 22:51:09 volumio systemd[1]: go-librespot-daemon.service: Killing process 2327 (go-librespot) with signal SIGKILL. Jun 13 22:51:09 volumio systemd[1]: go-librespot-daemon.service: Killing process 2330 (go-librespot) with signal SIGKILL. Jun 13 22:51:09 volumio systemd[1]: go-librespot-daemon.service: Killing process 2331 (go-librespot) with signal SIGKILL. Jun 13 22:51:09 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jun 13 22:51:09 volumio volumio[1206]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Jun 13 22:51:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 13 22:51:09 volumio volumio[1206]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Jun 13 22:51:09 volumio volumio[1206]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 13 22:51:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 13 22:51:09 volumio go-librespot[2504]: go-librespot daemon starting... Jun 13 22:51:09 volumio sudo[2498]: pam_unix(sudo:session): session closed for user root Jun 13 22:51:09 volumio volumio[1206]: Error: socket hang up Jun 13 22:51:09 volumio volumio[1206]: at connResetException (node:internal/errors:720:14) Jun 13 22:51:09 volumio volumio[1206]: at Socket.socketOnEnd (node:_http_client:519:23) Jun 13 22:51:09 volumio volumio[1206]: at Socket.emit (node:events:526:35) Jun 13 22:51:09 volumio volumio[1206]: at endReadableNT (node:internal/streams/readable:1376:12) Jun 13 22:51:09 volumio volumio[1206]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jun 13 22:51:09 volumio volumio[1206]: code: 'ECONNRESET', Jun 13 22:51:09 volumio volumio[1206]: response: undefined Jun 13 22:51:09 volumio volumio[1206]: } Jun 13 22:51:09 volumio volumio[1206]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 13 22:51:09 volumio dbus-daemon[855]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.40' (uid=0 pid=2502 comm="timedatectl show --property=NTPSynchronized --valu") Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=info msg="running go-librespot 0.2.0" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=debug msg="no app state found" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=debug msg="stored credentials not found" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=info msg="generated new device id: e5c741bdbffc9419c6aa553a2254bbe9d065a5b5" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 13 22:51:09 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 13 22:51:09 volumio dbus-daemon[855]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 13 22:51:09 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 13 22:51:09 volumio setdatetime-helper.sh[2501]: Time is not synchronized. Attempting to sync... Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 13 22:51:09 volumio go-librespot[2505]: time="2025-06-13T22:51:09-07:00" level=info msg="zeroconf server listening on port 40193" Jun 13 22:51:09 volumio sudo[2531]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Sat, 14 Jun 2025 05:51:09 GMT#015' Jun 13 22:51:09 volumio sudo[2531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 13 22:51:09 volumio setdatetime-helper.sh[2532]: Fri Jun 13 22:51:09 PDT 2025 Jun 13 22:51:09 volumio sudo[2531]: pam_unix(sudo:session): session closed for user root Jun 13 22:51:09 volumio setdatetime-helper.sh[2501]: Time synchronized successfully. Jun 13 22:51:09 volumio systemd-journald[445]: Time jumped backwards, rotating. Jun 13 22:51:09 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 13 22:51:09 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 13 22:51:09 volumio sudo[2536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-13 22:50' Jun 13 22:51:09 volumio sudo[2536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="4a70cb031e64a8e498efc3e29470650871ff7d54" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 31 04:09:10 UTC 2025" VOLUMIO_VERSION="4.005" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="f9bd4447a30d4b2c74b3880e7a50e48b"