May 29 22:24:00 volumio dbus-daemon[602]: [system] Successfully activated service 'org.freedesktop.timedate1' May 29 22:24:00 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 29 22:24:00 volumio setdatetime-helper.sh[3473]: Time is not synchronized. Attempting to sync... May 29 22:24:00 volumio sudo[3482]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 29 May 2025 13:24:01 GMT#015' May 29 22:24:00 volumio sudo[3482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 29 22:24:01 volumio setdatetime-helper.sh[3483]: Thu May 29 22:24:01 JST 2025 May 29 22:24:01 volumio sudo[3482]: pam_unix(sudo:session): session closed for user root May 29 22:24:01 volumio setdatetime-helper.sh[3473]: Time synchronized successfully. May 29 22:24:01 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 29 22:24:01 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 29 22:24:17 volumio volumio[1082]: info: CALLMETHOD: music_service ytmusic configSaveAccount [object Object] May 29 22:24:17 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: ytmusic , configSaveAccount May 29 22:24:17 volumio volumio[1082]: info: CoreCommandRouter::getUIConfigOnPlugin May 29 22:24:17 volumio volumio[1082]: info: [ytmusic] InnertubeLoader: creating Innertube instance... May 29 22:24:24 volumio volumio[1082]: info: CoreCommandRouter::volumioGetState May 29 22:24:24 volumio volumio[1082]: info: CorePlayQueue::getTrack 0 May 29 22:24:24 volumio volumio[1082]: info: [ytmusic] InnertubeLoader: obtaining po_token by datasyncIdToken... May 29 22:24:25 volumio volumio[1082]: info: [ytmusic] InnertubeLoader: obtained po_token (expires in 43200 seconds) May 29 22:24:25 volumio volumio[1082]: info: [ytmusic] InnertubeLoader: re-create Innertube instance with po_token May 29 22:24:25 volumio volumio[1082]: info: [ytmusic] InnertubeLoader: creating Innertube instance with po_token... May 29 22:24:25 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 29 22:24:25 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 29 22:24:30 volumio volumio[1082]: info: [ytmusic] InnertubeLoader: going to refresh po_token in 43100 seconds May 29 22:24:30 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 29 22:24:42 volumio volumio[1082]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf May 29 22:24:44 volumio volumio[1082]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf May 29 22:24:44 volumio volumio[1082]: info: Folder /tmp/plugins removed May 29 22:24:45 volumio volumio[1082]: info: Check plugin dependencies May 29 22:24:45 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 29 22:24:45 volumio volumio[1082]: info: Checking if plugin already exists May 29 22:24:45 volumio volumio[1082]: info: Rename folder May 29 22:24:45 volumio volumio[1082]: info: Folder /tmp/downloaded_plugin.zip removed May 29 22:24:45 volumio volumio[1082]: info: Move to category May 29 22:24:47 volumio volumio[1082]: info: Checking if install.sh is present May 29 22:24:47 volumio volumio[1082]: info: Executing install.sh May 29 22:24:48 volumio sudo[3565]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh May 29 22:24:48 volumio sudo[3565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 29 22:24:48 volumio volumio[1082]: info: Installing Go-librespot May 29 22:24:48 volumio volumio[1082]: info: Checking old vollibrespot installs May 29 22:24:48 volumio systemd[1]: Reloading. May 29 22:24:48 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:48 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:49 volumio systemd[1]: /lib/systemd/system/roonbridge.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:49 volumio systemd[1]: /lib/systemd/system/roonbridge.service:8: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:49 volumio volumio[1082]: info: Downloading daemon May 29 22:24:51 volumio ntpd[861]: CLOCK: time stepped by 0.779406 May 29 22:24:51 volumio ntpd[861]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes May 29 22:24:52 volumio volumio[1082]: info: Creating directories May 29 22:24:52 volumio volumio[1082]: info: Creating data directory May 29 22:24:53 volumio volumio[1082]: info: Creating Start Script May 29 22:24:53 volumio systemd[1]: Reloading. May 29 22:24:53 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:53 volumio systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:54 volumio systemd[1]: /lib/systemd/system/roonbridge.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:54 volumio systemd[1]: /lib/systemd/system/roonbridge.service:8: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:54 volumio sudo[3565]: pam_unix(sudo:session): session closed for user root May 29 22:24:54 volumio volumio[1082]: Plugin install end detected on script May 29 22:24:54 volumio volumio[1082]: info: Install script completed May 29 22:24:54 volumio volumio[1082]: info: Adding reference to registry May 29 22:24:54 volumio volumio[1082]: info: Done installing plugin. May 29 22:24:54 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 29 22:24:54 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 29 22:24:54 volumio volumio[1082]: info: Folder /tmp/plugins removed May 29 22:24:54 volumio volumio[1082]: info: Folder /tmp/downloaded_plugin.zip removed May 29 22:24:54 volumio volumio[1082]: info: Folder /data/temp removed May 29 22:24:55 volumio volumio[1082]: info: Enabling plugin spop May 29 22:24:55 volumio volumio[1082]: info: Loading plugin "spop"... May 29 22:24:56 volumio volumio[1082]: info: PLUGIN START: spop May 29 22:24:56 volumio volumio[1082]: info: Creating Spotify config file May 29 22:24:56 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 22:24:56 volumio volumio[1082]: info: Done. May 29 22:24:56 volumio volumio[1082]: info: Spotify config file written May 29 22:24:56 volumio volumio[1082]: info: No need to fix Spotify hosts May 29 22:24:56 volumio sudo[3636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 29 22:24:56 volumio sudo[3636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 29 22:24:56 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:56 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. May 29 22:24:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 29 22:24:57 volumio go-librespot[3638]: go-librespot daemon starting... May 29 22:24:57 volumio sudo[3636]: pam_unix(sudo:session): session closed for user root May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=info msg="running go-librespot 0.2.0" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=debug msg="no app state found" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=debug msg="stored credentials not found" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=info msg="generated new device id: c6923dca86da355652ea741d54aa5ed469d61636" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=info msg="api server listening on 127.0.0.1:9879" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 29 22:24:57 volumio go-librespot[3639]: time="2025-05-29T22:24:57+09:00" level=info msg="zeroconf server listening on port 36235" May 29 22:24:58 volumio volumio[1082]: info: Enabling plugin spop May 29 22:24:58 volumio volumio[1082]: info: Loading plugin "spop"... May 29 22:24:58 volumio volumio[1082]: info: PLUGIN START: spop May 29 22:24:58 volumio volumio[1082]: info: Creating Spotify config file May 29 22:24:58 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 22:24:58 volumio volumio[1082]: info: Done. May 29 22:24:58 volumio volumio[1082]: info: Spotify config file written May 29 22:24:58 volumio volumio[1082]: info: No need to fix Spotify hosts May 29 22:24:58 volumio sudo[3648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 29 22:24:58 volumio sudo[3648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 29 22:24:58 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 29 22:24:58 volumio systemd[1]: go-librespot-daemon.service: Killing process 3644 (go-librespot) with signal SIGKILL. May 29 22:24:58 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 29 22:24:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 29 22:24:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 29 22:24:58 volumio go-librespot[3651]: go-librespot daemon starting... May 29 22:24:58 volumio sudo[3648]: pam_unix(sudo:session): session closed for user root May 29 22:24:58 volumio go-librespot[3652]: time="2025-05-29T22:24:58+09:00" level=info msg="running go-librespot 0.2.0" May 29 22:24:58 volumio go-librespot[3652]: time="2025-05-29T22:24:58+09:00" level=debug msg="app state loaded" May 29 22:24:58 volumio go-librespot[3652]: time="2025-05-29T22:24:58+09:00" level=debug msg="stored credentials not found" May 29 22:24:58 volumio go-librespot[3652]: time="2025-05-29T22:24:58+09:00" level=info msg="api server listening on 127.0.0.1:9879" May 29 22:24:58 volumio volumio[1082]: info: Enabling plugin spop May 29 22:24:58 volumio volumio[1082]: info: Loading plugin "spop"... May 29 22:24:58 volumio volumio[1082]: info: PLUGIN START: spop May 29 22:24:58 volumio volumio[1082]: info: Creating Spotify config file May 29 22:24:58 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 22:24:58 volumio volumio[1082]: info: Done. May 29 22:24:58 volumio volumio[1082]: info: Spotify config file written May 29 22:24:58 volumio volumio[1082]: info: No need to fix Spotify hosts May 29 22:24:58 volumio sudo[3659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 29 22:24:58 volumio sudo[3659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 29 22:24:58 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 29 22:24:58 volumio systemd[1]: go-librespot-daemon.service: Killing process 3656 (go-librespot) with signal SIGKILL. May 29 22:24:58 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 29 22:24:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 29 22:24:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 29 22:24:58 volumio go-librespot[3661]: go-librespot daemon starting... May 29 22:24:58 volumio sudo[3659]: pam_unix(sudo:session): session closed for user root May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=info msg="running go-librespot 0.2.0" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=debug msg="app state loaded" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=debug msg="stored credentials not found" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=info msg="api server listening on 127.0.0.1:9879" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 29 22:24:58 volumio go-librespot[3662]: time="2025-05-29T22:24:58+09:00" level=info msg="zeroconf server listening on port 37003" May 29 22:25:00 volumio volumio[1082]: info: go-librespot daemon successfully initialized May 29 22:25:01 volumio volumio[1082]: info: go-librespot daemon successfully initialized May 29 22:25:01 volumio volumio[1082]: info: go-librespot daemon successfully initialized May 29 22:25:03 volumio volumio[1082]: info: Initializing connection to go-librespot Websocket May 29 22:25:03 volumio go-librespot[3662]: time="2025-05-29T22:25:03+09:00" level=debug msg="new websocket client" May 29 22:25:03 volumio volumio[1082]: info: Connection to go-librespot Websocket established May 29 22:25:03 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 29 22:25:04 volumio dbus-daemon[602]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.41' (uid=0 pid=3685 comm="timedatectl show --property=NTPSynchronized --valu") May 29 22:25:04 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 29 22:25:04 volumio dbus-daemon[602]: [system] Successfully activated service 'org.freedesktop.timedate1' May 29 22:25:04 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 29 22:25:04 volumio setdatetime-helper.sh[3684]: Time is not synchronized. Attempting to sync... May 29 22:25:04 volumio volumio[1082]: info: Initializing connection to go-librespot Websocket May 29 22:25:04 volumio go-librespot[3662]: time="2025-05-29T22:25:04+09:00" level=debug msg="new websocket client" May 29 22:25:04 volumio volumio[1082]: info: Connection to go-librespot Websocket established May 29 22:25:04 volumio sudo[3693]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 29 May 2025 13:25:03 GMT#015' May 29 22:25:04 volumio sudo[3693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 29 22:25:03 volumio setdatetime-helper.sh[3694]: Thu May 29 22:25:03 JST 2025 May 29 22:25:03 volumio systemd-journald[349]: Time jumped backwards, rotating. May 29 22:25:03 volumio sudo[3693]: pam_unix(sudo:session): session closed for user root May 29 22:25:03 volumio setdatetime-helper.sh[3684]: Time synchronized successfully. May 29 22:25:03 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 29 22:25:03 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 29 22:25:03 volumio volumio[1082]: info: Initializing connection to go-librespot Websocket May 29 22:25:03 volumio go-librespot[3662]: time="2025-05-29T22:25:03+09:00" level=debug msg="new websocket client" May 29 22:25:03 volumio volumio[1082]: info: Connection to go-librespot Websocket established May 29 22:25:04 volumio volumio[1082]: info: Enabling plugin spop May 29 22:25:04 volumio volumio[1082]: info: Loading plugin "spop"... May 29 22:25:04 volumio volumio[1082]: info: PLUGIN START: spop May 29 22:25:04 volumio volumio[1082]: info: Creating Spotify config file May 29 22:25:04 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 22:25:04 volumio volumio[1082]: info: Done. May 29 22:25:04 volumio volumio[1082]: info: Spotify config file written May 29 22:25:04 volumio volumio[1082]: info: No need to fix Spotify hosts May 29 22:25:04 volumio sudo[3697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 29 22:25:04 volumio sudo[3697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 29 22:25:04 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 29 22:25:04 volumio systemd[1]: go-librespot-daemon.service: Killing process 3667 (go-librespot) with signal SIGKILL. May 29 22:25:04 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 29 22:25:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 29 22:25:04 volumio volumio[1082]: info: Connection to go-librespot Websocket closed May 29 22:25:04 volumio volumio[1082]: info: Connection to go-librespot Websocket closed May 29 22:25:04 volumio volumio[1082]: info: Connection to go-librespot Websocket closed May 29 22:25:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 29 22:25:04 volumio go-librespot[3699]: go-librespot daemon starting... May 29 22:25:04 volumio sudo[3697]: pam_unix(sudo:session): session closed for user root May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=info msg="running go-librespot 0.2.0" May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=debug msg="app state loaded" May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=debug msg="stored credentials not found" May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=info msg="api server listening on 127.0.0.1:9879" May 29 22:25:04 volumio volumio[1082]: info: Getting Spotify volume May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 29 22:25:04 volumio go-librespot[3700]: time="2025-05-29T22:25:04+09:00" level=info msg="zeroconf server listening on port 36615" May 29 22:25:04 volumio volumio[1082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 29 22:25:04 volumio volumio[1082]: info: CoreCommandRouter::volumioGetState May 29 22:25:04 volumio volumio[1082]: info: CorePlayQueue::getTrack 0 May 29 22:25:04 volumio volumio[1082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 29 22:25:04 volumio volumio[1082]: SPOTIFY: SPOTIFY VOLUME undefined May 29 22:25:04 volumio volumio[1082]: SPOTIFY: VOLUMIO VOLUME 86 May 29 22:25:04 volumio volumio[1082]: info: Aligning Spotify Volume to Volumio Volume May 29 22:25:04 volumio volumio[1082]: info: CoreCommandRouter::volumioGetState May 29 22:25:04 volumio volumio[1082]: info: CorePlayQueue::getTrack 0 May 29 22:25:04 volumio volumio[1082]: info: Setting Spotify Volume from Volumio: 86 May 29 22:25:05 volumio volumio[1082]: info: Getting Spotify volume May 29 22:25:05 volumio volumio[1082]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 29 22:25:05 volumio volumio[1082]: info: CoreCommandRouter::volumioGetState May 29 22:25:05 volumio volumio[1082]: info: CorePlayQueue::getTrack 0 May 29 22:25:05 volumio volumio[1082]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 29 22:25:06 volumio volumio[1082]: info: Enabling plugin spop May 29 22:25:06 volumio volumio[1082]: info: Loading plugin "spop"... May 29 22:25:06 volumio volumio[1082]: info: PLUGIN START: spop May 29 22:25:06 volumio volumio[1082]: info: Creating Spotify config file May 29 22:25:06 volumio volumio[1082]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 22:25:06 volumio volumio[1082]: info: Done. May 29 22:25:06 volumio volumio[1082]: info: Spotify config file written May 29 22:25:06 volumio sudo[3709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 29 22:25:06 volumio sudo[3709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 29 22:25:06 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 29 22:25:06 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 29 22:25:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 29 22:25:06 volumio volumio[1082]: info: No need to fix Spotify hosts May 29 22:25:06 volumio volumio[1082]: info: Getting Spotify volume May 29 22:25:06 volumio volumio[1082]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 29 22:25:06 volumio volumio[1082]: Error: connect ECONNREFUSED 127.0.0.1:9879 May 29 22:25:06 volumio volumio[1082]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { May 29 22:25:06 volumio volumio[1082]: errno: -111, May 29 22:25:06 volumio volumio[1082]: code: 'ECONNREFUSED', May 29 22:25:06 volumio volumio[1082]: syscall: 'connect', May 29 22:25:06 volumio volumio[1082]: address: '127.0.0.1', May 29 22:25:06 volumio volumio[1082]: port: 9879, May 29 22:25:06 volumio volumio[1082]: response: undefined May 29 22:25:06 volumio volumio[1082]: } May 29 22:25:06 volumio volumio[1082]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 29 22:25:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 29 22:25:06 volumio go-librespot[3711]: go-librespot daemon starting... May 29 22:25:06 volumio sudo[3709]: pam_unix(sudo:session): session closed for user root May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=info msg="running go-librespot 0.2.0" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=debug msg="app state loaded" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=debug msg="stored credentials not found" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=info msg="api server listening on 127.0.0.1:9879" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 29 22:25:06 volumio go-librespot[3715]: time="2025-05-29T22:25:06+09:00" level=info msg="zeroconf server listening on port 42469" May 29 22:25:07 volumio sudo[3734]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-29 22:24' May 29 22:25:07 volumio sudo[3734]: 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="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025" VOLUMIO_VERSION="0.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"