Feb 08 00:32:00 volumio go-librespot[1674901]: time="2026-02-08T00:32:00+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:00 volumio volumio[1674834]: info: [1770485520211] CoreMusicLibrary::Adding element YouTube2 Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:00 volumio volumio[1674834]: Cannot find translation for source Jellyfin Feb 08 00:32:00 volumio volumio[1674834]: Cannot find translation for source YouTube2 Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:00 volumio volumio[1674834]: info: [1770485520216] CoreMusicLibrary::Adding element YouTube Music Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:00 volumio volumio[1674834]: Cannot find translation for source Jellyfin Feb 08 00:32:00 volumio volumio[1674834]: Cannot find translation for source YouTube2 Feb 08 00:32:00 volumio volumio[1674834]: Cannot find translation for source YouTube Music Feb 08 00:32:00 volumio volumio[1674834]: info: Volumio Calling Home Feb 08 00:32:00 volumio go-librespot[1674901]: time="2026-02-08T00:32:00+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:00 volumio go-librespot[1674901]: time="2026-02-08T00:32:00+07:00" level=debug msg="completed challenge" Feb 08 00:32:00 volumio volumio[1674834]: info: MPD Permissions set Feb 08 00:32:00 volumio volumio[1674834]: info: MPD Permissions set Feb 08 00:32:00 volumio go-librespot[1674901]: time="2026-02-08T00:32:00+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:00 volumio volumio[1674834]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:00 volumio volumio[1674834]: info: CoreStateMachine::pushState Feb 08 00:32:00 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:00 volumio volumio[1674834]: info: Spotify config file written Feb 08 00:32:00 volumio mpd[1674979]: 2026-02-08T00:32:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 00:32:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 00:32:00 volumio sudo[1674962]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:00 volumio sudo[1675006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 00:32:00 volumio sudo[1674950]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:00 volumio sudo[1675006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 00:32:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 00:32:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:00 volumio volumio[1674834]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:00 volumio go-librespot[1675010]: go-librespot daemon starting... Feb 08 00:32:00 volumio sudo[1675006]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:00 volumio go-librespot[1675013]: time="2026-02-08T00:32:00+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:00 volumio volumio-remote-updater[721]: [2026-02-08 00:32:00] [connect] Successful connection Feb 08 00:32:00 volumio go-librespot[1675013]: time="2026-02-08T00:32:00+07:00" level=debug msg="app state loaded" Feb 08 00:32:00 volumio go-librespot[1675013]: time="2026-02-08T00:32:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:00 volumio volumio[1674834]: info: No need to fix Spotify hosts Feb 08 00:32:00 volumio volumio[1674834]: info: Discovery: adding 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:00 volumio volumio[1674834]: info: Discovery: Found device Volumio Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:00 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:00 volumio volumio[1674834]: info: Completed starting Core Plugins Feb 08 00:32:00 volumio volumio[1674834]: info: ------------------------------------------- Feb 08 00:32:00 volumio volumio[1674834]: info: ----- MyVolumio plugins startup ---- Feb 08 00:32:00 volumio volumio[1674834]: info: ------------------------------------------- Feb 08 00:32:00 volumio volumio[1674834]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 00:32:00 volumio volumio[1674834]: info: Volumio called home Feb 08 00:32:00 volumio volumio[1674834]: info: Discovery: this is already registered, 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:00 volumio volumio[1674834]: info: Discovery: Found device Volumio Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:00 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:00 volumio volumio[1674834]: info: [jellyfin-poller] Polled http://192.168.1.202:8096: online Feb 08 00:32:00 volumio volumio[1674834]: error: MPD error: The expression evaluated to a falsy value: Feb 08 00:32:00 volumio volumio[1674834]: assert.ok(self.idling) Feb 08 00:32:00 volumio volumio[1674834]: error: The expression evaluated to a falsy value: Feb 08 00:32:00 volumio volumio[1674834]: assert.ok(self.idling) Feb 08 00:32:00 volumio volumio-remote-updater[721]: [2026-02-08 00:32:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770485520 101 Feb 08 00:32:00 volumio volumio[1674834]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Feb 08 00:32:00 volumio volumio[1674834]: info: MPD running with PID1674979 Feb 08 00:32:00 volumio volumio[1674834]: ,establishing connection Feb 08 00:32:00 volumio volumio[1674834]: info: Starting Shairport Sync Feb 08 00:32:00 volumio volumio[1674834]: info: Starting Shairport Sync Feb 08 00:32:00 volumio volumio[1674834]: info: Starting Shairport Sync Feb 08 00:32:00 volumio sudo[1675037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:00 volumio sudo[1675037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:00 volumio volumio[1674834]: error: updateQueue error: null Feb 08 00:32:00 volumio sudo[1675041]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:00 volumio sudo[1675041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:00 volumio sudo[1675040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:00 volumio sudo[1675040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:00 volumio sudo[1675037]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:00 volumio sudo[1675041]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:00 volumio sudo[1675040]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:00 volumio volumio[1674834]: info: Shairport-Sync Started Feb 08 00:32:00 volumio volumio[1674834]: Error adding Membership: Error: addMembership EINVAL Feb 08 00:32:00 volumio volumio[1674834]: error: updateQueue error: null Feb 08 00:32:00 volumio volumio[1674834]: info: Shairport-Sync Started Feb 08 00:32:00 volumio volumio[1674834]: info: Shairport-Sync Started Feb 08 00:32:00 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:00 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07: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]" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07: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]" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07: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]" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07:00" level=info msg="zeroconf server listening on port 41113" Feb 08 00:32:01 volumio volumio[1674834]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07:00" level=debug msg="obtained new client token: AABPGp16UILiseJF/FBrqRttUKZ34olAqBTsbgFBaeimOBua5P9N77AmIlHN0T17cmqDkzwbSu19B4yYONsZhIE0Sv9Ikzg9Auydq7QEt2b1d1kUKXjQ84E0jy2abkEiTCvKJ7RpSUEK7uRDpl0KUPlVeUrQV4qsXjlf91xSZaTHCRpIdAV8SkH0Wy4Ex8lKbsEhHg4YMQPgHkV2dkpYXlmfYQKfLt42PvtxeKZl7Xb2xmzKUF91TAGG7w==" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07:00" level=debug msg="completed challenge" Feb 08 00:32:01 volumio go-librespot[1675013]: time="2026-02-08T00:32:01+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:02 volumio go-librespot[1675013]: time="2026-02-08T00:32:02+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:02 volumio go-librespot[1675013]: time="2026-02-08T00:32:02+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:02 volumio go-librespot[1675013]: time="2026-02-08T00:32:02+07:00" level=debug msg="completed challenge" Feb 08 00:32:02 volumio go-librespot[1675013]: time="2026-02-08T00:32:02+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:03 volumio go-librespot[1675013]: time="2026-02-08T00:32:03+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:03 volumio volumio[1674834]: info: go-librespot daemon successfully initialized Feb 08 00:32:04 volumio go-librespot[1675013]: time="2026-02-08T00:32:04+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:04 volumio go-librespot[1675013]: time="2026-02-08T00:32:04+07:00" level=debug msg="completed challenge" Feb 08 00:32:04 volumio go-librespot[1675013]: time="2026-02-08T00:32:04+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:05 volumio go-librespot[1675013]: time="2026-02-08T00:32:05+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 00:32:05 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:05 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:05 volumio volumio[1674834]: info: Listing playlists Feb 08 00:32:05 volumio volumio[1674834]: info: Listing playlists Feb 08 00:32:05 volumio volumio[1674834]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 00:32:05 volumio go-librespot[1675013]: time="2026-02-08T00:32:05+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:05 volumio go-librespot[1675013]: time="2026-02-08T00:32:05+07:00" level=debug msg="completed challenge" Feb 08 00:32:05 volumio go-librespot[1675013]: time="2026-02-08T00:32:05+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:06 volumio go-librespot[1675013]: time="2026-02-08T00:32:06+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 08 00:32:06 volumio volumio[1674834]: info: Initializing connection to go-librespot Websocket Feb 08 00:32:06 volumio volumio[1674834]: info: Connection to go-librespot Websocket established Feb 08 00:32:06 volumio go-librespot[1675013]: time="2026-02-08T00:32:06+07:00" level=debug msg="new websocket client" Feb 08 00:32:06 volumio volumio[1674834]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/139.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetVisibleSources Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:06 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:06 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 08 00:32:06 volumio volumio[1674834]: info: Received Get System Info Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 08 00:32:06 volumio volumio[1674834]: info: Discovery: Getting this device information Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:06 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 08 00:32:06 volumio volumio[1674834]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:06 volumio volumio[1674834]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:06 volumio volumio[1674834]: info: Listing playlists Feb 08 00:32:07 volumio sudo[1675085]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:07 volumio sudo[1675085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:07 volumio sudo[1675087]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:07 volumio sudo[1675087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:07 volumio sudo[1675085]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:07 volumio sudo[1675087]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:07 volumio sudo[1675093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 00:32:07 volumio sudo[1675093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:07 volumio sudo[1675093]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:07 volumio volumio[1674834]: info: Upmpdcli Daemon Started Feb 08 00:32:07 volumio go-librespot[1675013]: time="2026-02-08T00:32:07+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 08 00:32:08 volumio go-librespot[1675013]: time="2026-02-08T00:32:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 00:32:08 volumio volumio[1674834]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 00:32:09 volumio go-librespot[1675013]: time="2026-02-08T00:32:09+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:09 volumio go-librespot[1675013]: time="2026-02-08T00:32:09+07:00" level=debug msg="completed challenge" Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 00:32:09 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:09 volumio volumio[1674834]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:09 volumio volumio[1674834]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 00:32:09 volumio volumio[1674834]: info: MyVolumio login type: Token Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 00:32:09 volumio go-librespot[1675013]: time="2026-02-08T00:32:09+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:09 volumio go-librespot[1675013]: time="2026-02-08T00:32:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 00:32:09 volumio volumio[1674834]: info: Streaming services startup Feb 08 00:32:09 volumio volumio[1674834]: info: Starting Streaming Daemon Feb 08 00:32:09 volumio volumio[1674834]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 00:32:09 volumio sudo[1675099]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 00:32:09 volumio sudo[1675099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:09 volumio sudo[1675099]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:09 volumio volumio[1674834]: info: Getting Spotify volume Feb 08 00:32:09 volumio volumio[1674834]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:09 volumio volumio[1674834]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 00:32:09 volumio volumio[1674834]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 00:32:09 volumio volumio[1674834]: errno: -111, Feb 08 00:32:09 volumio volumio[1674834]: code: 'ECONNREFUSED', Feb 08 00:32:09 volumio volumio[1674834]: syscall: 'connect', Feb 08 00:32:09 volumio volumio[1674834]: address: '127.0.0.1', Feb 08 00:32:09 volumio volumio[1674834]: port: 9879, Feb 08 00:32:09 volumio volumio[1674834]: response: undefined Feb 08 00:32:09 volumio volumio[1674834]: } Feb 08 00:32:09 volumio volumio[1674834]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:10 volumio sudo[1675119]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 00:31' Feb 08 00:32:10 volumio sudo[1675119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:10 volumio sudo[1675119]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:10 volumio volumio-remote-updater[721]: [2026-02-08 00:32:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 00:32:10 volumio volumio-remote-updater[721]: [2026-02-08 00:32:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 00:32:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 00:32:10 volumio systemd[1]: volumio.service: Consumed 3.812s CPU time. Feb 08 00:32:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4710. Feb 08 00:32:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 00:32:10 volumio systemd[1]: volumio.service: Consumed 3.812s CPU time. Feb 08 00:32:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 00:32:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:11 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:11 volumio volumio[1675132]: info: ----- Volumio3 ---- Feb 08 00:32:11 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:11 volumio volumio[1675132]: info: ----- System startup ---- Feb 08 00:32:11 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:11 volumio volumio[1675132]: info: MYVOLUMIO Environment detected Feb 08 00:32:11 volumio volumio[1675132]: info: Plugin folders cleanup Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning into folder /volumio/app/plugins/ Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category audio_interface Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category miscellanea Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category music_service Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category plugins.json Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category system_controller Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category user_interface Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning into folder /data/plugins/ Feb 08 00:32:11 volumio volumio[1675132]: info: Scanning category music_service Feb 08 00:32:11 volumio volumio[1675132]: info: Plugin folders cleanup completed Feb 08 00:32:11 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:11 volumio volumio[1675132]: info: ----- Core plugins startup ---- Feb 08 00:32:11 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 00:32:11 volumio volumio[1675132]: info: Adding plugin upnp to MyMusic Plugins Feb 08 00:32:11 volumio volumio[1675132]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 00:32:11 volumio volumio[1675132]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugins from folder /data/plugins/ Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugin "system"... Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugin "appearance"... Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugin "network"... Feb 08 00:32:11 volumio volumio[1675132]: info: Refreshing Cached IP Addresses Feb 08 00:32:11 volumio sudo[1675161]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:11 volumio sudo[1675163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:11 volumio sudo[1675161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:11 volumio sudo[1675163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:11 volumio sudo[1675161]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:11 volumio sudo[1675163]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugin "services"... Feb 08 00:32:11 volumio volumio[1675132]: info: Loading plugin "alsa_controller"... Feb 08 00:32:11 volumio sudo[1675178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 00:32:11 volumio sudo[1675178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:11 volumio sudo[1675178]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:12 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "wizard"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "networkfs"... Feb 08 00:32:12 volumio volumio[1675132]: info: Starting Udev Watcher for removable devices Feb 08 00:32:12 volumio volumio[1675132]: info: Ignoring mount for partition: boot Feb 08 00:32:12 volumio volumio[1675132]: info: Ignoring mount for partition: volumio Feb 08 00:32:12 volumio volumio[1675132]: info: Ignoring mount for partition: volumio_data Feb 08 00:32:12 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "volumio_command_line_client"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "upnp"... Feb 08 00:32:12 volumio volumio[1675132]: info: [1770485532091] Starting Upmpd Daemon Feb 08 00:32:12 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "my_music"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "mpd"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "upnp_browser"... Feb 08 00:32:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 00:32:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:12 volumio go-librespot[1675199]: go-librespot daemon starting... Feb 08 00:32:12 volumio go-librespot[1675200]: time="2026-02-08T00:32:12+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:12 volumio go-librespot[1675200]: time="2026-02-08T00:32:12+07:00" level=debug msg="app state loaded" Feb 08 00:32:12 volumio go-librespot[1675200]: time="2026-02-08T00:32:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:12 volumio volumio[1675132]: info: Starting UPNP Browser Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "alarm-clock"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "airplay_emulation"... Feb 08 00:32:12 volumio volumio[1675132]: info: Starting Shairport Sync Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "last_100"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "webradio"... Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "i2s_dacs"... Feb 08 00:32:12 volumio volumio[1675132]: info: I2S DAC not set, start Auto-detection Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "volumiodiscovery"... Feb 08 00:32:12 volumio volumio[1675132]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:12 volumio node[1675132]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:12 volumio volumio[1675132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:12 volumio node[1675132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:12 volumio volumio[1675132]: *** WARNING *** For more information see Feb 08 00:32:12 volumio node[1675132]: *** WARNING *** For more information see Feb 08 00:32:12 volumio volumio[1675132]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:12 volumio node[1675132]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:12 volumio volumio[1675132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:12 volumio node[1675132]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:12 volumio volumio[1675132]: *** WARNING *** For more information see Feb 08 00:32:12 volumio node[1675132]: *** WARNING *** For more information see Feb 08 00:32:12 volumio volumio[1675132]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 00:32:12 volumio volumio[1675132]: info: Discovery: Started advertising with name: Volumio Feb 08 00:32:12 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:12 volumio volumio[1675132]: info: Loading plugin "jellyfin"... Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=info msg="zeroconf server listening on port 40979" Feb 08 00:32:13 volumio volumio[1675132]: info: Loading plugin "spop"... Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=debug msg="obtained new client token: AAC7UysaF+JoKWM1+vCTbQYs0EqMQurTMgXt/DMMdoFHW8jQfiX+GQ/kPG6bUcNZK106DhimRbMnZ9EuaE8tx4QNfZpisB7GUVnZA+O+6fTmf8vEcoYGFdUp4XWRajI8flM36R4qaSk11XFla0e9GdhgGHEBdScMS9xPe9iRphmC+Ps1HFBVrFLwLfCdnHSpU6u/kpbAXYNb8+DXHGU0JMzfr75rrM2OgPkA+O2yb4xPPWbRo8vNLp+COg==" Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:13 volumio volumio[1675132]: info: Loading plugin "youtube2"... Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=debug msg="completed challenge" Feb 08 00:32:13 volumio go-librespot[1675200]: time="2026-02-08T00:32:13+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:13 volumio volumio[1675132]: info: Loading plugin "ytmusic"... Feb 08 00:32:14 volumio volumio[1675132]: info: Loading plugin "outputs"... Feb 08 00:32:14 volumio volumio[1675132]: info: Loading plugin "albumart"... Feb 08 00:32:14 volumio volumio[1675132]: info: Plugin example_plugin is not enabled Feb 08 00:32:14 volumio volumio[1675132]: info: Loading plugin "inputs"... Feb 08 00:32:14 volumio volumio[1675132]: info: Loading plugin "updater_comm"... Feb 08 00:32:14 volumio volumio[1675132]: info: Plugin mpdemulation is not enabled Feb 08 00:32:14 volumio volumio[1675132]: info: Loading plugin "rest_api"... Feb 08 00:32:14 volumio volumio[1675132]: info: Loading plugin "websocket"... Feb 08 00:32:14 volumio volumio[1675132]: info: Starting Socket.io Server version 1.7.4 Feb 08 00:32:14 volumio volumio[1675132]: info: Loading i18n strings for locale ru Feb 08 00:32:14 volumio volumio[1675211]: Forking 1 albumart workers Feb 08 00:32:14 volumio volumio[1675132]: Updating browse sources language Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:14 volumio go-librespot[1675200]: time="2026-02-08T00:32:14+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::initPlayerControls Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: Express server listening on port 3000 Feb 08 00:32:14 volumio volumio[1675132]: [Metrics] WebUI: 3s 406.68ms Feb 08 00:32:14 volumio volumio[1675132]: info: Setting Device type: x86 Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::resetVolumioState Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::getcurrentVolume Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Feb 08 00:32:14 volumio volumio[1675132]: info: Completed loading Core Plugins Feb 08 00:32:14 volumio volumio[1675132]: info: Preparing to generate the ALSA configuration file Feb 08 00:32:14 volumio volumio[1675132]: info: Volumio Network Manager: Network status updated: 1 Feb 08 00:32:14 volumio volumio[1675132]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 08 00:32:14 volumio volumio[1675132]: wlan0 Interface doesn't support scanning. Feb 08 00:32:14 volumio volumio[1675132]: info: Cannot use regular scanning, forcing with ap-force Feb 08 00:32:14 volumio sudo[1675235]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 08 00:32:14 volumio sudo[1675235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:14 volumio sudo[1675235]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:14 volumio volumio[1675132]: command failed: No such device (-19) Feb 08 00:32:14 volumio volumio[1675132]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 08 00:32:14 volumio volumio[1675132]: command failed: No such device (-19) Feb 08 00:32:14 volumio volumio[1675132]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Feb 08 00:32:14 volumio volumio[1675132]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::pushState Feb 08 00:32:14 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::updateTrackBlock Feb 08 00:32:14 volumio volumio[1675132]: info: CorePlayQueue::getTrackBlock Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:14 volumio go-librespot[1675200]: time="2026-02-08T00:32:14+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:14 volumio go-librespot[1675200]: time="2026-02-08T00:32:14+07:00" level=debug msg="completed challenge" Feb 08 00:32:14 volumio volumio[1675132]: info: Reloading queue from file Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::setRepeat null single undefined Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::pushState Feb 08 00:32:14 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::setRandom null Feb 08 00:32:14 volumio volumio[1675132]: info: CoreStateMachine::pushState Feb 08 00:32:14 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:14 volumio volumio[1675132]: info: Asound.conf file unchanged, so no further update is needed Feb 08 00:32:14 volumio volumio[1675132]: info: Output device has changed, restarting MPD Feb 08 00:32:14 volumio volumio[1675221]: Starting albumart workers Feb 08 00:32:14 volumio volumio[1675132]: info: Output device has changed, restarting Shairport Sync Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:14 volumio sudo[1675248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:14 volumio sudo[1675250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:14 volumio sudo[1675250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:14 volumio sudo[1675248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:14 volumio go-librespot[1675200]: time="2026-02-08T00:32:14+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:14 volumio volumio[1675132]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:14 volumio sudo[1675248]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 00:32:14 volumio volumio[1675132]: info: ___________ START PLUGINS ___________ Feb 08 00:32:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:14 volumio volumio[1675132]: info: ControllerMpd::onStart: Initializing MPD Feb 08 00:32:14 volumio volumio[1675132]: info: Creating MPD Configuration file Feb 08 00:32:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:14 volumio volumio[1675132]: info: [1770485534855] CoreMusicLibrary::Adding element Медиа-серверы Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:14 volumio volumio[1675132]: info: UPNP Browser: Client initialized successfully Feb 08 00:32:14 volumio sudo[1675258]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:14 volumio sudo[1675261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:14 volumio sudo[1675261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:14 volumio sudo[1675258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:14 volumio sudo[1675258]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:14 volumio sudo[1675262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:14 volumio sudo[1675262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:14 volumio sudo[1675261]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:14 volumio volumio[1675132]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:14 volumio volumio[1675132]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:14 volumio volumio[1675132]: info: [1770485534967] CoreMusicLibrary::Adding element Last_100 Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:14 volumio volumio[1675132]: info: [1770485534968] CoreMusicLibrary::Adding element Webradio Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:14 volumio sudo[1675272]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:14 volumio sudo[1675272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:14 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:14 volumio sudo[1675272]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:14 volumio volumio[1675132]: info: Initializing BBC Radios Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 08 00:32:15 volumio volumio[1675132]: info: Discovery: Getting this device information Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:15 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:15 volumio volumio[1675132]: info: [1770485535096] CoreMusicLibrary::Adding element Jellyfin Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:15 volumio volumio[1675132]: Cannot find translation for source Jellyfin Feb 08 00:32:15 volumio volumio[1675132]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.133","id":"46e269a1-2f26-4df8-b5f6-1749968c4324","name":"Volumio","serviceName":"Volumio","state":{"albumart":"https://i.scdn.co/image/ab67616d0000b2732f2c4ed053b2399461163048","artist":"Ozma","mute":false,"status":"stop","track":"Эхо","volume":48},"type":"device"} Feb 08 00:32:15 volumio volumio[1675132]: info: Creating Spotify config file Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio-remote-updater[721]: [2026-02-08 00:32:15] [connect] Successful connection Feb 08 00:32:15 volumio go-librespot[1675200]: time="2026-02-08T00:32:15+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:15 volumio volumio[1675132]: info: [1770485535332] CoreMusicLibrary::Adding element YouTube2 Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:15 volumio volumio[1675132]: Cannot find translation for source Jellyfin Feb 08 00:32:15 volumio volumio[1675132]: Cannot find translation for source YouTube2 Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:15 volumio volumio[1675132]: info: [1770485535334] CoreMusicLibrary::Adding element YouTube Music Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:15 volumio volumio[1675132]: Cannot find translation for source Jellyfin Feb 08 00:32:15 volumio volumio[1675132]: Cannot find translation for source YouTube2 Feb 08 00:32:15 volumio volumio[1675132]: Cannot find translation for source YouTube Music Feb 08 00:32:15 volumio volumio[1675132]: info: Volumio Calling Home Feb 08 00:32:15 volumio volumio[1675132]: info: MPD Permissions set Feb 08 00:32:15 volumio volumio[1675132]: info: MPD Permissions set Feb 08 00:32:15 volumio volumio[1675132]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:15 volumio volumio[1675132]: info: CoreStateMachine::pushState Feb 08 00:32:15 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:15 volumio volumio-remote-updater[721]: [2026-02-08 00:32:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770485535 101 Feb 08 00:32:15 volumio volumio[1675132]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 08 00:32:15 volumio volumio[1675132]: info: Spotify config file written Feb 08 00:32:15 volumio volumio[1675132]: info: Discovery: adding 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:15 volumio volumio[1675132]: info: Discovery: Found device Volumio Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:15 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:15 volumio mpd[1675278]: 2026-02-08T00:32:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 00:32:15 volumio volumio[1675132]: info: Discovery: this is already registered, 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:15 volumio volumio[1675132]: info: Discovery: Found device Volumio Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:15 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 00:32:15 volumio sudo[1675262]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:15 volumio sudo[1675304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 00:32:15 volumio sudo[1675304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:15 volumio sudo[1675250]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:15 volumio go-librespot[1675200]: time="2026-02-08T00:32:15+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:15 volumio go-librespot[1675200]: time="2026-02-08T00:32:15+07:00" level=debug msg="completed challenge" Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 00:32:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 00:32:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:15 volumio sudo[1675304]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:15 volumio go-librespot[1675313]: go-librespot daemon starting... Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio go-librespot[1675315]: time="2026-02-08T00:32:15+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:15 volumio go-librespot[1675315]: time="2026-02-08T00:32:15+07:00" level=debug msg="app state loaded" Feb 08 00:32:15 volumio go-librespot[1675315]: time="2026-02-08T00:32:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:15 volumio volumio[1675132]: info: No need to fix Spotify hosts Feb 08 00:32:15 volumio volumio[1675132]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 00:32:15 volumio volumio[1675132]: info: Completed starting Core Plugins Feb 08 00:32:15 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:15 volumio volumio[1675132]: info: ----- MyVolumio plugins startup ---- Feb 08 00:32:15 volumio volumio[1675132]: info: ------------------------------------------- Feb 08 00:32:15 volumio volumio[1675132]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 00:32:15 volumio volumio[1675132]: info: Volumio called home Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:15 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:15 volumio volumio[1675132]: info: [jellyfin-poller] Polled http://192.168.1.202:8096: online Feb 08 00:32:15 volumio volumio[1675132]: error: MPD error: The expression evaluated to a falsy value: Feb 08 00:32:15 volumio volumio[1675132]: assert.ok(self.idling) Feb 08 00:32:15 volumio volumio[1675132]: error: The expression evaluated to a falsy value: Feb 08 00:32:15 volumio volumio[1675132]: assert.ok(self.idling) Feb 08 00:32:15 volumio volumio[1675132]: info: MPD running with PID1675278 Feb 08 00:32:15 volumio volumio[1675132]: ,establishing connection Feb 08 00:32:15 volumio volumio[1675132]: info: Starting Shairport Sync Feb 08 00:32:15 volumio volumio[1675132]: info: Starting Shairport Sync Feb 08 00:32:15 volumio volumio[1675132]: info: Starting Shairport Sync Feb 08 00:32:15 volumio volumio[1675132]: error: updateQueue error: null Feb 08 00:32:15 volumio sudo[1675336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:15 volumio sudo[1675337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:15 volumio sudo[1675339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:15 volumio volumio[1675132]: error: updateQueue error: null Feb 08 00:32:15 volumio sudo[1675336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:15 volumio sudo[1675337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:15 volumio sudo[1675339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:15 volumio systemd[1]: shairport-sync.service: Consumed 1.071s CPU time. Feb 08 00:32:15 volumio volumio[1675132]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:15 volumio volumio[1675132]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:15 volumio sudo[1675337]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:15 volumio sudo[1675339]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:15 volumio sudo[1675336]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:15 volumio volumio[1675132]: info: Shairport-Sync Started Feb 08 00:32:15 volumio volumio[1675132]: Error adding Membership: Error: addMembership EINVAL Feb 08 00:32:15 volumio volumio[1675132]: info: Shairport-Sync Started Feb 08 00:32:15 volumio volumio[1675132]: info: Shairport-Sync Started Feb 08 00:32:15 volumio volumio[1675132]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 08 00:32:16 volumio go-librespot[1675315]: time="2026-02-08T00:32:16+07: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]" Feb 08 00:32:16 volumio go-librespot[1675315]: time="2026-02-08T00:32:16+07: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]" Feb 08 00:32:16 volumio go-librespot[1675315]: time="2026-02-08T00:32:16+07: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]" Feb 08 00:32:16 volumio go-librespot[1675315]: time="2026-02-08T00:32:16+07:00" level=info msg="zeroconf server listening on port 42625" Feb 08 00:32:16 volumio go-librespot[1675315]: time="2026-02-08T00:32:16+07:00" level=debug msg="obtained new client token: AABmzy21qKTSInFwgOooMMzuwWmwfYU3LSZzXVCpnlmJauQlVSm5i9Vq1aZVrEJxz2+kCc9s9XggcpQfMYnEOpjW0Bqo8PETLp6kWKa8Kmhx3o+yAQi/9sgaDTGcLvK++MtXZQZIN/deCyDyAWds4Klzlad5qLSot77B42OrSK9r0KtCp/CmrrfcUkYRJ6Jmh3HalsFsRjXJjNscMT+Fi+cA46hu3QslC4mzW/r+X3Es9HTb33tOU0pV5g==" Feb 08 00:32:16 volumio go-librespot[1675315]: time="2026-02-08T00:32:16+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:17 volumio go-librespot[1675315]: time="2026-02-08T00:32:17+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:17 volumio go-librespot[1675315]: time="2026-02-08T00:32:17+07:00" level=debug msg="completed challenge" Feb 08 00:32:17 volumio go-librespot[1675315]: time="2026-02-08T00:32:17+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:17 volumio go-librespot[1675315]: time="2026-02-08T00:32:17+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:17 volumio go-librespot[1675315]: time="2026-02-08T00:32:17+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:17 volumio go-librespot[1675315]: time="2026-02-08T00:32:17+07:00" level=debug msg="completed challenge" Feb 08 00:32:18 volumio go-librespot[1675315]: time="2026-02-08T00:32:18+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:18 volumio go-librespot[1675315]: time="2026-02-08T00:32:18+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:18 volumio volumio[1675132]: info: go-librespot daemon successfully initialized Feb 08 00:32:18 volumio go-librespot[1675315]: time="2026-02-08T00:32:18+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:18 volumio go-librespot[1675315]: time="2026-02-08T00:32:18+07:00" level=debug msg="completed challenge" Feb 08 00:32:18 volumio go-librespot[1675315]: time="2026-02-08T00:32:18+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:19 volumio go-librespot[1675315]: time="2026-02-08T00:32:19+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 00:32:19 volumio go-librespot[1675315]: time="2026-02-08T00:32:19+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:19 volumio go-librespot[1675315]: time="2026-02-08T00:32:19+07:00" level=debug msg="completed challenge" Feb 08 00:32:20 volumio go-librespot[1675315]: time="2026-02-08T00:32:20+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:20 volumio go-librespot[1675315]: time="2026-02-08T00:32:20+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 08 00:32:20 volumio volumio[1675132]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 00:32:21 volumio go-librespot[1675315]: time="2026-02-08T00:32:21+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:21 volumio go-librespot[1675315]: time="2026-02-08T00:32:21+07:00" level=debug msg="completed challenge" Feb 08 00:32:21 volumio go-librespot[1675315]: time="2026-02-08T00:32:21+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:21 volumio go-librespot[1675315]: time="2026-02-08T00:32:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 08 00:32:21 volumio volumio[1675132]: info: Initializing connection to go-librespot Websocket Feb 08 00:32:21 volumio go-librespot[1675315]: time="2026-02-08T00:32:21+07:00" level=debug msg="new websocket client" Feb 08 00:32:21 volumio volumio[1675132]: info: Connection to go-librespot Websocket established Feb 08 00:32:22 volumio sudo[1675380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:22 volumio sudo[1675380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:22 volumio sudo[1675382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:22 volumio sudo[1675382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:22 volumio sudo[1675380]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:22 volumio sudo[1675382]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:22 volumio sudo[1675388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 00:32:22 volumio sudo[1675388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:22 volumio sudo[1675388]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:22 volumio volumio[1675132]: info: Upmpdcli Daemon Started Feb 08 00:32:22 volumio go-librespot[1675315]: time="2026-02-08T00:32:22+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:22 volumio go-librespot[1675315]: time="2026-02-08T00:32:22+07:00" level=debug msg="completed challenge" Feb 08 00:32:22 volumio go-librespot[1675315]: time="2026-02-08T00:32:22+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:22 volumio go-librespot[1675315]: time="2026-02-08T00:32:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:22 volumio volumio[1675132]: info: Connection to go-librespot Websocket closed Feb 08 00:32:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 00:32:24 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:24 volumio volumio[1675132]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:24 volumio volumio[1675132]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 00:32:24 volumio volumio[1675132]: info: MyVolumio login type: Token Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 00:32:24 volumio volumio[1675132]: info: Streaming services startup Feb 08 00:32:24 volumio volumio[1675132]: info: Starting Streaming Daemon Feb 08 00:32:24 volumio volumio[1675132]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 00:32:24 volumio sudo[1675394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 00:32:24 volumio sudo[1675394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:24 volumio sudo[1675394]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:24 volumio volumio[1675132]: error: Cannot start Volumio Streaming Daemon Feb 08 00:32:24 volumio volumio[1675132]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 00:32:24 volumio volumio[1675132]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 00:32:24 volumio volumio[1675132]: info: Getting Spotify volume Feb 08 00:32:24 volumio volumio[1675132]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:24 volumio volumio[1675132]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 00:32:24 volumio volumio[1675132]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 00:32:24 volumio volumio[1675132]: errno: -111, Feb 08 00:32:24 volumio volumio[1675132]: code: 'ECONNREFUSED', Feb 08 00:32:24 volumio volumio[1675132]: syscall: 'connect', Feb 08 00:32:24 volumio volumio[1675132]: address: '127.0.0.1', Feb 08 00:32:24 volumio volumio[1675132]: port: 9879, Feb 08 00:32:24 volumio volumio[1675132]: response: undefined Feb 08 00:32:24 volumio volumio[1675132]: } Feb 08 00:32:24 volumio volumio[1675132]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:25 volumio sudo[1675414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 00:31' Feb 08 00:32:25 volumio sudo[1675414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:25 volumio sudo[1675414]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:25 volumio volumio-remote-updater[721]: [2026-02-08 00:32:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 00:32:25 volumio volumio-remote-updater[721]: [2026-02-08 00:32:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 00:32:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 00:32:25 volumio systemd[1]: volumio.service: Consumed 3.801s CPU time. Feb 08 00:32:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4711. Feb 08 00:32:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 00:32:25 volumio systemd[1]: volumio.service: Consumed 3.801s CPU time. Feb 08 00:32:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 00:32:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 00:32:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:25 volumio go-librespot[1675442]: go-librespot daemon starting... Feb 08 00:32:25 volumio go-librespot[1675443]: time="2026-02-08T00:32:25+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:25 volumio go-librespot[1675443]: time="2026-02-08T00:32:25+07:00" level=debug msg="app state loaded" Feb 08 00:32:25 volumio go-librespot[1675443]: time="2026-02-08T00:32:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:26 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:26 volumio volumio[1675430]: info: ----- Volumio3 ---- Feb 08 00:32:26 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:26 volumio volumio[1675430]: info: ----- System startup ---- Feb 08 00:32:26 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:26 volumio go-librespot[1675443]: time="2026-02-08T00:32:26+07: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 00:32:26 volumio go-librespot[1675443]: time="2026-02-08T00:32:26+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 00:32:26 volumio go-librespot[1675443]: time="2026-02-08T00:32:26+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 00:32:26 volumio go-librespot[1675443]: time="2026-02-08T00:32:26+07:00" level=info msg="zeroconf server listening on port 34267" Feb 08 00:32:26 volumio volumio[1675430]: info: MYVOLUMIO Environment detected Feb 08 00:32:26 volumio volumio[1675430]: info: Plugin folders cleanup Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning into folder /volumio/app/plugins/ Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category audio_interface Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category miscellanea Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category music_service Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category plugins.json Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category system_controller Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category user_interface Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning into folder /data/plugins/ Feb 08 00:32:26 volumio volumio[1675430]: info: Scanning category music_service Feb 08 00:32:26 volumio volumio[1675430]: info: Plugin folders cleanup completed Feb 08 00:32:26 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:26 volumio volumio[1675430]: info: ----- Core plugins startup ---- Feb 08 00:32:26 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:26 volumio volumio[1675430]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 00:32:26 volumio volumio[1675430]: info: Adding plugin upnp to MyMusic Plugins Feb 08 00:32:26 volumio volumio[1675430]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 00:32:26 volumio volumio[1675430]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 00:32:26 volumio volumio[1675430]: info: Loading plugins from folder /data/plugins/ Feb 08 00:32:26 volumio volumio[1675430]: info: Loading plugin "system"... Feb 08 00:32:26 volumio volumio[1675430]: info: Loading plugin "appearance"... Feb 08 00:32:26 volumio go-librespot[1675443]: time="2026-02-08T00:32:26+07:00" level=debug msg="obtained new client token: AAB6TN4RxL2FgfKJuDrKz5c/3IAUwuNHQlsIy4CnuXhB/xzpvKB06MzHlx6nkvg+gMHRxULVPGs5/xd5JBgdCyBUdJ2uedjXV5Md41WzcHB6R32xBM9PzwhYkSX09Hhx65GDqcEm7JX5hOTfKPtDoOQopvza1029gzfUHX7Kr1ZIQONTsIv86uo4LA0OOf4PVSNU+I1gAdFETV59E6nyhCbJ2WjZq6RmFxYblm23OZj405J8ydmBqWoo8w==" Feb 08 00:32:26 volumio go-librespot[1675443]: time="2026-02-08T00:32:26+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "network"... Feb 08 00:32:27 volumio volumio[1675430]: info: Refreshing Cached IP Addresses Feb 08 00:32:27 volumio sudo[1675465]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:27 volumio sudo[1675465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:27 volumio sudo[1675465]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:27 volumio sudo[1675467]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:27 volumio sudo[1675467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "services"... Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "alsa_controller"... Feb 08 00:32:27 volumio sudo[1675467]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:27 volumio sudo[1675476]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 00:32:27 volumio sudo[1675476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:27 volumio sudo[1675476]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:27 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "wizard"... Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "networkfs"... Feb 08 00:32:27 volumio volumio[1675430]: info: Starting Udev Watcher for removable devices Feb 08 00:32:27 volumio volumio[1675430]: info: Ignoring mount for partition: boot Feb 08 00:32:27 volumio volumio[1675430]: info: Ignoring mount for partition: volumio Feb 08 00:32:27 volumio volumio[1675430]: info: Ignoring mount for partition: volumio_data Feb 08 00:32:27 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "volumio_command_line_client"... Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "upnp"... Feb 08 00:32:27 volumio volumio[1675430]: info: [1770485547194] Starting Upmpd Daemon Feb 08 00:32:27 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "my_music"... Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "mpd"... Feb 08 00:32:27 volumio go-librespot[1675443]: time="2026-02-08T00:32:27+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:27 volumio go-librespot[1675443]: time="2026-02-08T00:32:27+07:00" level=debug msg="completed challenge" Feb 08 00:32:27 volumio go-librespot[1675443]: time="2026-02-08T00:32:27+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "upnp_browser"... Feb 08 00:32:27 volumio volumio[1675430]: info: Starting UPNP Browser Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "alarm-clock"... Feb 08 00:32:27 volumio go-librespot[1675443]: time="2026-02-08T00:32:27+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "airplay_emulation"... Feb 08 00:32:27 volumio volumio[1675430]: info: Starting Shairport Sync Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "last_100"... Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "webradio"... Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "i2s_dacs"... Feb 08 00:32:27 volumio volumio[1675430]: info: I2S DAC not set, start Auto-detection Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "volumiodiscovery"... Feb 08 00:32:27 volumio volumio[1675430]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:27 volumio node[1675430]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:27 volumio volumio[1675430]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:27 volumio volumio[1675430]: *** WARNING *** For more information see Feb 08 00:32:27 volumio volumio[1675430]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:27 volumio volumio[1675430]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:27 volumio volumio[1675430]: *** WARNING *** For more information see Feb 08 00:32:27 volumio volumio[1675430]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 00:32:27 volumio volumio[1675430]: info: Discovery: Started advertising with name: Volumio Feb 08 00:32:27 volumio node[1675430]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:27 volumio node[1675430]: *** WARNING *** For more information see Feb 08 00:32:27 volumio node[1675430]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:27 volumio node[1675430]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:27 volumio node[1675430]: *** WARNING *** For more information see Feb 08 00:32:27 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:27 volumio volumio[1675430]: info: Loading plugin "jellyfin"... Feb 08 00:32:28 volumio go-librespot[1675443]: time="2026-02-08T00:32:28+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:28 volumio go-librespot[1675443]: time="2026-02-08T00:32:28+07:00" level=debug msg="completed challenge" Feb 08 00:32:28 volumio go-librespot[1675443]: time="2026-02-08T00:32:28+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:28 volumio volumio[1675430]: info: Loading plugin "spop"... Feb 08 00:32:28 volumio volumio[1675430]: info: Loading plugin "youtube2"... Feb 08 00:32:28 volumio go-librespot[1675443]: time="2026-02-08T00:32:28+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:28 volumio volumio[1675430]: info: Loading plugin "ytmusic"... Feb 08 00:32:29 volumio go-librespot[1675443]: time="2026-02-08T00:32:29+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:29 volumio go-librespot[1675443]: time="2026-02-08T00:32:29+07:00" level=debug msg="completed challenge" Feb 08 00:32:29 volumio volumio[1675430]: info: Loading plugin "outputs"... Feb 08 00:32:29 volumio volumio[1675430]: info: Loading plugin "albumart"... Feb 08 00:32:29 volumio volumio[1675430]: info: Plugin example_plugin is not enabled Feb 08 00:32:29 volumio volumio[1675430]: info: Loading plugin "inputs"... Feb 08 00:32:29 volumio volumio[1675430]: info: Loading plugin "updater_comm"... Feb 08 00:32:29 volumio go-librespot[1675443]: time="2026-02-08T00:32:29+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:29 volumio volumio[1675507]: Forking 1 albumart workers Feb 08 00:32:29 volumio volumio[1675430]: info: Plugin mpdemulation is not enabled Feb 08 00:32:29 volumio volumio[1675430]: info: Loading plugin "rest_api"... Feb 08 00:32:29 volumio volumio[1675430]: info: Loading plugin "websocket"... Feb 08 00:32:29 volumio volumio[1675430]: info: Starting Socket.io Server version 1.7.4 Feb 08 00:32:29 volumio volumio[1675430]: info: Loading i18n strings for locale ru Feb 08 00:32:29 volumio volumio[1675430]: Updating browse sources language Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::initPlayerControls Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: Express server listening on port 3000 Feb 08 00:32:29 volumio volumio[1675430]: [Metrics] WebUI: 3s 384.67ms Feb 08 00:32:29 volumio volumio[1675430]: info: Setting Device type: x86 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::resetVolumioState Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::getcurrentVolume Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Feb 08 00:32:29 volumio volumio[1675430]: info: Completed loading Core Plugins Feb 08 00:32:29 volumio volumio[1675430]: info: Preparing to generate the ALSA configuration file Feb 08 00:32:29 volumio volumio[1675430]: info: Volumio Network Manager: Network status updated: 1 Feb 08 00:32:29 volumio volumio[1675430]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 08 00:32:29 volumio volumio[1675430]: wlan0 Interface doesn't support scanning. Feb 08 00:32:29 volumio volumio[1675430]: info: Cannot use regular scanning, forcing with ap-force Feb 08 00:32:29 volumio sudo[1675532]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 08 00:32:29 volumio sudo[1675532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:29 volumio sudo[1675532]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:29 volumio volumio[1675430]: command failed: No such device (-19) Feb 08 00:32:29 volumio volumio[1675430]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 08 00:32:29 volumio volumio[1675430]: command failed: No such device (-19) Feb 08 00:32:29 volumio volumio[1675517]: Starting albumart workers Feb 08 00:32:29 volumio volumio[1675430]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Feb 08 00:32:29 volumio volumio[1675430]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::pushState Feb 08 00:32:29 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::updateTrackBlock Feb 08 00:32:29 volumio volumio[1675430]: info: CorePlayQueue::getTrackBlock Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:29 volumio volumio[1675430]: info: Reloading queue from file Feb 08 00:32:29 volumio go-librespot[1675443]: time="2026-02-08T00:32:29+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::setRepeat null single undefined Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::pushState Feb 08 00:32:29 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::setRandom null Feb 08 00:32:29 volumio volumio[1675430]: info: CoreStateMachine::pushState Feb 08 00:32:29 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:29 volumio volumio[1675430]: info: Asound.conf file unchanged, so no further update is needed Feb 08 00:32:29 volumio volumio[1675430]: info: Output device has changed, restarting MPD Feb 08 00:32:29 volumio volumio[1675430]: info: Output device has changed, restarting Shairport Sync Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:29 volumio sudo[1675544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:29 volumio sudo[1675544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:29 volumio volumio[1675430]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:29 volumio sudo[1675546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:29 volumio sudo[1675546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:29 volumio volumio[1675430]: info: ___________ START PLUGINS ___________ Feb 08 00:32:29 volumio sudo[1675544]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:29 volumio volumio[1675430]: info: ControllerMpd::onStart: Initializing MPD Feb 08 00:32:29 volumio volumio[1675430]: info: Creating MPD Configuration file Feb 08 00:32:29 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 00:32:29 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:29 volumio volumio[1675430]: info: [1770485549815] CoreMusicLibrary::Adding element Медиа-серверы Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:29 volumio sudo[1675554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:29 volumio sudo[1675554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:29 volumio sudo[1675557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:29 volumio volumio[1675430]: info: UPNP Browser: Client initialized successfully Feb 08 00:32:29 volumio sudo[1675554]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:29 volumio sudo[1675557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio sudo[1675558]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:29 volumio sudo[1675558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:29 volumio sudo[1675558]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:29 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:29 volumio volumio[1675430]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:29 volumio volumio[1675430]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:29 volumio volumio[1675430]: info: [1770485549937] CoreMusicLibrary::Adding element Last_100 Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:29 volumio volumio[1675430]: info: [1770485549938] CoreMusicLibrary::Adding element Webradio Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:29 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:29 volumio volumio[1675430]: info: Initializing BBC Radios Feb 08 00:32:29 volumio sudo[1675568]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:29 volumio sudo[1675568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:29 volumio sudo[1675568]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 08 00:32:30 volumio volumio[1675430]: info: Discovery: Getting this device information Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:30 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:30 volumio volumio[1675430]: info: [1770485550069] CoreMusicLibrary::Adding element Jellyfin Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:30 volumio volumio[1675430]: Cannot find translation for source Jellyfin Feb 08 00:32:30 volumio volumio[1675430]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.133","id":"46e269a1-2f26-4df8-b5f6-1749968c4324","name":"Volumio","serviceName":"Volumio","state":{"albumart":"https://i.scdn.co/image/ab67616d0000b2732f2c4ed053b2399461163048","artist":"Ozma","mute":false,"status":"stop","track":"Эхо","volume":48},"type":"device"} Feb 08 00:32:30 volumio volumio[1675430]: info: Creating Spotify config file Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio go-librespot[1675443]: time="2026-02-08T00:32:30+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:30 volumio go-librespot[1675443]: time="2026-02-08T00:32:30+07:00" level=debug msg="completed challenge" Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:30 volumio volumio[1675430]: info: [1770485550186] CoreMusicLibrary::Adding element YouTube2 Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:30 volumio volumio[1675430]: Cannot find translation for source Jellyfin Feb 08 00:32:30 volumio volumio[1675430]: Cannot find translation for source YouTube2 Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:30 volumio volumio[1675430]: info: [1770485550200] CoreMusicLibrary::Adding element YouTube Music Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:30 volumio volumio[1675430]: Cannot find translation for source Jellyfin Feb 08 00:32:30 volumio volumio[1675430]: Cannot find translation for source YouTube2 Feb 08 00:32:30 volumio volumio[1675430]: Cannot find translation for source YouTube Music Feb 08 00:32:30 volumio volumio[1675430]: info: Volumio Calling Home Feb 08 00:32:30 volumio volumio[1675430]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:30 volumio volumio[1675430]: info: CoreStateMachine::pushState Feb 08 00:32:30 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:30 volumio volumio[1675430]: info: MPD Permissions set Feb 08 00:32:30 volumio volumio[1675430]: info: MPD Permissions set Feb 08 00:32:30 volumio volumio[1675430]: info: Spotify config file written Feb 08 00:32:30 volumio volumio[1675430]: info: Discovery: adding 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:30 volumio volumio[1675430]: info: Discovery: Found device Volumio Feb 08 00:32:30 volumio volumio-remote-updater[721]: [2026-02-08 00:32:30] [connect] Successful connection Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:30 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:30 volumio go-librespot[1675443]: time="2026-02-08T00:32:30+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:30 volumio sudo[1675599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 00:32:30 volumio sudo[1675599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:30 volumio volumio[1675430]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 08 00:32:30 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 00:32:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:30 volumio go-librespot[1675603]: go-librespot daemon starting... Feb 08 00:32:30 volumio sudo[1675599]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=debug msg="app state loaded" Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:30 volumio volumio[1675430]: info: No need to fix Spotify hosts Feb 08 00:32:30 volumio volumio[1675430]: info: Discovery: this is already registered, 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:30 volumio volumio[1675430]: info: Discovery: Found device Volumio Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:30 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:30 volumio volumio-remote-updater[721]: [2026-02-08 00:32:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770485550 101 Feb 08 00:32:30 volumio mpd[1675583]: decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 00:32:30 volumio mpd[1675583]: output: No 'audio_output' defined in config file Feb 08 00:32:30 volumio mpd[1675583]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for 0 Feb 08 00:32:30 volumio mpd[1675583]: couldn't open play stream: No such file or directory Feb 08 00:32:30 volumio mpd[1675583]: sndio_output: Error opening default sndio device Feb 08 00:32:30 volumio mpd[1675583]: output: Successfully detected a alsa audio device Feb 08 00:32:30 volumio volumio[1675430]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Feb 08 00:32:30 volumio volumio[1675430]: info: Volumio called home Feb 08 00:32:30 volumio volumio[1675430]: info: [jellyfin-poller] Polled http://192.168.1.202:8096: online Feb 08 00:32:30 volumio mpd[1675583]: zeroconf: No global port, disabling zeroconf Feb 08 00:32:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 00:32:30 volumio sudo[1675557]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio sudo[1675546]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio volumio[1675430]: info: Starting Shairport Sync Feb 08 00:32:30 volumio volumio[1675430]: info: Starting Shairport Sync Feb 08 00:32:30 volumio sudo[1675629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:30 volumio volumio[1675430]: info: Starting Shairport Sync Feb 08 00:32:30 volumio sudo[1675629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:30 volumio systemd[1]: shairport-sync.service: Consumed 1.142s CPU time. Feb 08 00:32:30 volumio sudo[1675631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:30 volumio sudo[1675631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:30 volumio sudo[1675634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:30 volumio sudo[1675634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:30 volumio sudo[1675629]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:30 volumio volumio[1675430]: info: Completed starting Core Plugins Feb 08 00:32:30 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:30 volumio volumio[1675430]: info: ----- MyVolumio plugins startup ---- Feb 08 00:32:30 volumio volumio[1675430]: info: ------------------------------------------- Feb 08 00:32:30 volumio volumio[1675430]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 00:32:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:30 volumio sudo[1675634]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio sudo[1675631]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:30 volumio volumio[1675430]: info: Shairport-Sync Started Feb 08 00:32:30 volumio volumio[1675430]: Error adding Membership: Error: addMembership EINVAL Feb 08 00:32:30 volumio volumio[1675430]: error: MPD error: The expression evaluated to a falsy value: Feb 08 00:32:30 volumio volumio[1675430]: assert.ok(self.idling) Feb 08 00:32:30 volumio volumio[1675430]: error: The expression evaluated to a falsy value: Feb 08 00:32:30 volumio volumio[1675430]: assert.ok(self.idling) Feb 08 00:32:30 volumio volumio[1675430]: info: Shairport-Sync Started Feb 08 00:32:30 volumio volumio[1675430]: info: Shairport-Sync Started Feb 08 00:32:30 volumio volumio[1675430]: info: MPD running with PID1675583 Feb 08 00:32:30 volumio volumio[1675430]: ,establishing connection Feb 08 00:32:30 volumio volumio[1675430]: error: updateQueue error: null Feb 08 00:32:30 volumio volumio[1675430]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:30 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:30 volumio volumio[1675430]: error: updateQueue error: null Feb 08 00:32:30 volumio volumio[1675430]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 08 00:32:30 volumio go-librespot[1675607]: time="2026-02-08T00:32:30+07:00" level=info msg="zeroconf server listening on port 38397" Feb 08 00:32:31 volumio go-librespot[1675607]: time="2026-02-08T00:32:31+07:00" level=debug msg="obtained new client token: AADI894Nf6OfCti3v7rQPjN4etNUwYSXTgxx/cK0Bk71hSVcIxcXs00E5V/vcNRuNKcmx6QYrsXZAwSytvb2QFwjxbG1JA+AIj2nsNgP8XDtep467yzap+t5/bQBV324MHqcyreS5iR91FkfSSth6eLWLSn0O2A7W1XxLmmdJ11XVdNQRLjre/PgNYRje4qjV6NnD0WLrE+ciZ70Vgh80H1tnK9zZsmcCCo5fFxtwOWMH9PLzlZqv9I=" Feb 08 00:32:31 volumio go-librespot[1675607]: time="2026-02-08T00:32:31+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:31 volumio go-librespot[1675607]: time="2026-02-08T00:32:31+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:31 volumio go-librespot[1675607]: time="2026-02-08T00:32:31+07:00" level=debug msg="completed challenge" Feb 08 00:32:31 volumio go-librespot[1675607]: time="2026-02-08T00:32:31+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:32 volumio go-librespot[1675607]: time="2026-02-08T00:32:32+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:32 volumio go-librespot[1675607]: time="2026-02-08T00:32:32+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:32 volumio go-librespot[1675607]: time="2026-02-08T00:32:32+07:00" level=debug msg="completed challenge" Feb 08 00:32:32 volumio go-librespot[1675607]: time="2026-02-08T00:32:32+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:33 volumio go-librespot[1675607]: time="2026-02-08T00:32:33+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:33 volumio volumio[1675430]: info: go-librespot daemon successfully initialized Feb 08 00:32:33 volumio go-librespot[1675607]: time="2026-02-08T00:32:33+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:33 volumio go-librespot[1675607]: time="2026-02-08T00:32:33+07:00" level=debug msg="completed challenge" Feb 08 00:32:33 volumio go-librespot[1675607]: time="2026-02-08T00:32:33+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:34 volumio go-librespot[1675607]: time="2026-02-08T00:32:34+07:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 08 00:32:34 volumio go-librespot[1675607]: time="2026-02-08T00:32:34+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:34 volumio go-librespot[1675607]: time="2026-02-08T00:32:34+07:00" level=debug msg="completed challenge" Feb 08 00:32:35 volumio go-librespot[1675607]: time="2026-02-08T00:32:35+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:35 volumio volumio[1675430]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:35 volumio volumio[1675430]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:35 volumio volumio[1675430]: info: Listing playlists Feb 08 00:32:35 volumio volumio[1675430]: info: Listing playlists Feb 08 00:32:35 volumio go-librespot[1675607]: time="2026-02-08T00:32:35+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 08 00:32:35 volumio mpd[1675583]: exception: No database Feb 08 00:32:35 volumio mpd[1675583]: exception: No database Feb 08 00:32:35 volumio mpd[1675583]: exception: No database Feb 08 00:32:35 volumio volumio[1675430]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database Feb 08 00:32:35 volumio go-librespot[1675607]: time="2026-02-08T00:32:35+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:35 volumio go-librespot[1675607]: time="2026-02-08T00:32:35+07:00" level=debug msg="completed challenge" Feb 08 00:32:36 volumio go-librespot[1675607]: time="2026-02-08T00:32:36+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:36 volumio go-librespot[1675607]: time="2026-02-08T00:32:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 08 00:32:36 volumio volumio[1675430]: info: Initializing connection to go-librespot Websocket Feb 08 00:32:36 volumio volumio[1675430]: info: Connection to go-librespot Websocket established Feb 08 00:32:36 volumio go-librespot[1675607]: time="2026-02-08T00:32:36+07:00" level=debug msg="new websocket client" Feb 08 00:32:37 volumio sudo[1675678]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:37 volumio sudo[1675678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:37 volumio sudo[1675678]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:37 volumio sudo[1675680]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:37 volumio sudo[1675680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:37 volumio sudo[1675683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 00:32:37 volumio sudo[1675683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:37 volumio sudo[1675680]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:37 volumio sudo[1675683]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:37 volumio volumio[1675430]: info: Upmpdcli Daemon Started Feb 08 00:32:37 volumio go-librespot[1675607]: time="2026-02-08T00:32:37+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:37 volumio go-librespot[1675607]: time="2026-02-08T00:32:37+07:00" level=debug msg="completed challenge" Feb 08 00:32:37 volumio go-librespot[1675607]: time="2026-02-08T00:32:37+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:37 volumio go-librespot[1675607]: time="2026-02-08T00:32:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:37 volumio volumio[1675430]: info: Connection to go-librespot Websocket closed Feb 08 00:32:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 00:32:38 volumio volumio[1675430]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 00:32:39 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:39 volumio volumio[1675430]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:39 volumio volumio[1675430]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 00:32:39 volumio volumio[1675430]: info: MyVolumio login type: Token Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 00:32:39 volumio volumio[1675430]: info: Streaming services startup Feb 08 00:32:39 volumio volumio[1675430]: info: Starting Streaming Daemon Feb 08 00:32:39 volumio sudo[1675691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 00:32:39 volumio volumio[1675430]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 00:32:39 volumio sudo[1675691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:39 volumio sudo[1675691]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:39 volumio volumio[1675430]: error: Cannot start Volumio Streaming Daemon Feb 08 00:32:39 volumio volumio[1675430]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 00:32:39 volumio volumio[1675430]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 00:32:39 volumio volumio[1675430]: info: Getting Spotify volume Feb 08 00:32:39 volumio volumio[1675430]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:39 volumio volumio[1675430]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 00:32:39 volumio volumio[1675430]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 00:32:39 volumio volumio[1675430]: errno: -111, Feb 08 00:32:39 volumio volumio[1675430]: code: 'ECONNREFUSED', Feb 08 00:32:39 volumio volumio[1675430]: syscall: 'connect', Feb 08 00:32:39 volumio volumio[1675430]: address: '127.0.0.1', Feb 08 00:32:39 volumio volumio[1675430]: port: 9879, Feb 08 00:32:39 volumio volumio[1675430]: response: undefined Feb 08 00:32:39 volumio volumio[1675430]: } Feb 08 00:32:39 volumio volumio[1675430]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:39 volumio sudo[1675712]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 00:31' Feb 08 00:32:39 volumio sudo[1675712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:39 volumio sudo[1675712]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:39 volumio volumio-remote-updater[721]: [2026-02-08 00:32:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 00:32:39 volumio volumio-remote-updater[721]: [2026-02-08 00:32:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 00:32:39 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:39 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 00:32:39 volumio systemd[1]: volumio.service: Consumed 3.685s CPU time. Feb 08 00:32:40 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:40 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:40 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4712. Feb 08 00:32:40 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:40 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 00:32:40 volumio systemd[1]: volumio.service: Consumed 3.685s CPU time. Feb 08 00:32:40 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 00:32:40 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 00:32:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:40 volumio go-librespot[1675740]: go-librespot daemon starting... Feb 08 00:32:40 volumio go-librespot[1675741]: time="2026-02-08T00:32:40+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:40 volumio go-librespot[1675741]: time="2026-02-08T00:32:40+07:00" level=debug msg="app state loaded" Feb 08 00:32:40 volumio go-librespot[1675741]: time="2026-02-08T00:32:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:40 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:40 volumio volumio[1675724]: info: ----- Volumio3 ---- Feb 08 00:32:40 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:40 volumio volumio[1675724]: info: ----- System startup ---- Feb 08 00:32:40 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=info msg="zeroconf server listening on port 41041" Feb 08 00:32:41 volumio volumio[1675724]: info: MYVOLUMIO Environment detected Feb 08 00:32:41 volumio volumio[1675724]: info: Plugin folders cleanup Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning into folder /volumio/app/plugins/ Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category audio_interface Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category miscellanea Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category music_service Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category plugins.json Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category system_controller Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category user_interface Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning into folder /data/plugins/ Feb 08 00:32:41 volumio volumio[1675724]: info: Scanning category music_service Feb 08 00:32:41 volumio volumio[1675724]: info: Plugin folders cleanup completed Feb 08 00:32:41 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:41 volumio volumio[1675724]: info: ----- Core plugins startup ---- Feb 08 00:32:41 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 00:32:41 volumio volumio[1675724]: info: Adding plugin upnp to MyMusic Plugins Feb 08 00:32:41 volumio volumio[1675724]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 00:32:41 volumio volumio[1675724]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugins from folder /data/plugins/ Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "system"... Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "appearance"... Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="obtained new client token: AAD1R1oTV46o7muawkZMfKEqDbh9+5rtc5Nr5tUAoJ4/t0rTW37d3tMkHJW4weoNTKeudKjTdf8kDbaI5m2q3vGJKwgfxibFJSkEQGUU0TZNk08SRoqfcaRC/f/Lo588Rx/b8vnLMn5V0PPyMfY4cllfgu5dVwu2+fG+2gO+rpKTGaYjN/E/YlCZA7KM6XWNapsu8WcqVXaB1/TmYUrciU1iZ1G4XMjaN1mHwQUAa8YM1bPSSgLci5j0cQ==" Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "network"... Feb 08 00:32:41 volumio volumio[1675724]: info: Refreshing Cached IP Addresses Feb 08 00:32:41 volumio sudo[1675763]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:41 volumio sudo[1675763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:41 volumio sudo[1675765]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:41 volumio sudo[1675765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:41 volumio sudo[1675763]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "services"... Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "alsa_controller"... Feb 08 00:32:41 volumio sudo[1675765]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:41 volumio sudo[1675775]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 00:32:41 volumio sudo[1675775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:41 volumio sudo[1675775]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:41 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "wizard"... Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "networkfs"... Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:41 volumio go-librespot[1675741]: time="2026-02-08T00:32:41+07:00" level=debug msg="completed challenge" Feb 08 00:32:41 volumio volumio[1675724]: info: Starting Udev Watcher for removable devices Feb 08 00:32:41 volumio volumio[1675724]: info: Ignoring mount for partition: boot Feb 08 00:32:41 volumio volumio[1675724]: info: Ignoring mount for partition: volumio Feb 08 00:32:41 volumio volumio[1675724]: info: Ignoring mount for partition: volumio_data Feb 08 00:32:41 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "volumio_command_line_client"... Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "upnp"... Feb 08 00:32:41 volumio volumio[1675724]: info: [1770485561960] Starting Upmpd Daemon Feb 08 00:32:41 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "my_music"... Feb 08 00:32:41 volumio volumio[1675724]: info: Loading plugin "mpd"... Feb 08 00:32:42 volumio go-librespot[1675741]: time="2026-02-08T00:32:42+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "upnp_browser"... Feb 08 00:32:42 volumio go-librespot[1675741]: time="2026-02-08T00:32:42+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:42 volumio volumio[1675724]: info: Starting UPNP Browser Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "alarm-clock"... Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "airplay_emulation"... Feb 08 00:32:42 volumio volumio[1675724]: info: Starting Shairport Sync Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "last_100"... Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "webradio"... Feb 08 00:32:42 volumio go-librespot[1675741]: time="2026-02-08T00:32:42+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:42 volumio go-librespot[1675741]: time="2026-02-08T00:32:42+07:00" level=debug msg="completed challenge" Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "i2s_dacs"... Feb 08 00:32:42 volumio volumio[1675724]: info: I2S DAC not set, start Auto-detection Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "volumiodiscovery"... Feb 08 00:32:42 volumio volumio[1675724]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:42 volumio volumio[1675724]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:42 volumio volumio[1675724]: *** WARNING *** For more information see Feb 08 00:32:42 volumio volumio[1675724]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:42 volumio node[1675724]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:42 volumio volumio[1675724]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:42 volumio volumio[1675724]: *** WARNING *** For more information see Feb 08 00:32:42 volumio node[1675724]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:42 volumio node[1675724]: *** WARNING *** For more information see Feb 08 00:32:42 volumio node[1675724]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:42 volumio node[1675724]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:42 volumio node[1675724]: *** WARNING *** For more information see Feb 08 00:32:42 volumio volumio[1675724]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 00:32:42 volumio volumio[1675724]: info: Discovery: Started advertising with name: Volumio Feb 08 00:32:42 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:42 volumio volumio[1675724]: info: Loading plugin "jellyfin"... Feb 08 00:32:42 volumio go-librespot[1675741]: time="2026-02-08T00:32:42+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "spop"... Feb 08 00:32:43 volumio go-librespot[1675741]: time="2026-02-08T00:32:43+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "youtube2"... Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "ytmusic"... Feb 08 00:32:43 volumio go-librespot[1675741]: time="2026-02-08T00:32:43+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:43 volumio go-librespot[1675741]: time="2026-02-08T00:32:43+07:00" level=debug msg="completed challenge" Feb 08 00:32:43 volumio go-librespot[1675741]: time="2026-02-08T00:32:43+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "outputs"... Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "albumart"... Feb 08 00:32:43 volumio volumio[1675724]: info: Plugin example_plugin is not enabled Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "inputs"... Feb 08 00:32:43 volumio volumio[1675724]: info: Loading plugin "updater_comm"... Feb 08 00:32:44 volumio volumio[1675724]: info: Plugin mpdemulation is not enabled Feb 08 00:32:44 volumio volumio[1675724]: info: Loading plugin "rest_api"... Feb 08 00:32:44 volumio volumio[1675724]: info: Loading plugin "websocket"... Feb 08 00:32:44 volumio volumio[1675724]: info: Starting Socket.io Server version 1.7.4 Feb 08 00:32:44 volumio volumio[1675724]: info: Loading i18n strings for locale ru Feb 08 00:32:44 volumio volumio[1675724]: Updating browse sources language Feb 08 00:32:44 volumio volumio[1675804]: Forking 1 albumart workers Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::initPlayerControls Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: Express server listening on port 3000 Feb 08 00:32:44 volumio volumio[1675724]: [Metrics] WebUI: 3s 541.29ms Feb 08 00:32:44 volumio volumio[1675724]: info: Setting Device type: x86 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::resetVolumioState Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::getcurrentVolume Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Feb 08 00:32:44 volumio volumio[1675724]: info: Completed loading Core Plugins Feb 08 00:32:44 volumio volumio[1675724]: info: Preparing to generate the ALSA configuration file Feb 08 00:32:44 volumio go-librespot[1675741]: time="2026-02-08T00:32:44+07:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 08 00:32:44 volumio volumio[1675724]: info: Volumio Network Manager: Network status updated: 1 Feb 08 00:32:44 volumio volumio[1675724]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 08 00:32:44 volumio volumio[1675724]: wlan0 Interface doesn't support scanning. Feb 08 00:32:44 volumio volumio[1675724]: info: Cannot use regular scanning, forcing with ap-force Feb 08 00:32:44 volumio sudo[1675828]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 08 00:32:44 volumio sudo[1675828]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:44 volumio sudo[1675828]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:44 volumio volumio[1675724]: command failed: No such device (-19) Feb 08 00:32:44 volumio volumio[1675724]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 08 00:32:44 volumio volumio[1675724]: command failed: No such device (-19) Feb 08 00:32:44 volumio volumio[1675724]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Feb 08 00:32:44 volumio volumio[1675724]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::pushState Feb 08 00:32:44 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::updateTrackBlock Feb 08 00:32:44 volumio volumio[1675724]: info: CorePlayQueue::getTrackBlock Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:44 volumio volumio[1675724]: info: Reloading queue from file Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::setRepeat null single undefined Feb 08 00:32:44 volumio volumio[1675814]: Starting albumart workers Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::pushState Feb 08 00:32:44 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::setRandom null Feb 08 00:32:44 volumio volumio[1675724]: info: CoreStateMachine::pushState Feb 08 00:32:44 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:44 volumio volumio[1675724]: info: Asound.conf file unchanged, so no further update is needed Feb 08 00:32:44 volumio volumio[1675724]: info: Output device has changed, restarting MPD Feb 08 00:32:44 volumio volumio[1675724]: info: Output device has changed, restarting Shairport Sync Feb 08 00:32:44 volumio sudo[1675842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:44 volumio sudo[1675842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:44 volumio sudo[1675842]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:44 volumio sudo[1675844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:44 volumio sudo[1675844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:44 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 00:32:44 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:44 volumio volumio[1675724]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:44 volumio volumio[1675724]: info: ___________ START PLUGINS ___________ Feb 08 00:32:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:44 volumio volumio[1675724]: info: ControllerMpd::onStart: Initializing MPD Feb 08 00:32:44 volumio volumio[1675724]: info: Creating MPD Configuration file Feb 08 00:32:44 volumio sudo[1675854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:44 volumio volumio[1675724]: info: [1770485564739] CoreMusicLibrary::Adding element Медиа-серверы Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:44 volumio volumio[1675724]: info: UPNP Browser: Client initialized successfully Feb 08 00:32:44 volumio sudo[1675852]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:44 volumio sudo[1675852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:44 volumio sudo[1675856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:44 volumio sudo[1675856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:44 volumio sudo[1675852]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:44 volumio sudo[1675854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:44 volumio sudo[1675854]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:44 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:44 volumio volumio[1675724]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:44 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:44 volumio volumio[1675724]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:44 volumio volumio[1675724]: info: [1770485564854] CoreMusicLibrary::Adding element Last_100 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:44 volumio go-librespot[1675741]: time="2026-02-08T00:32:44+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:44 volumio go-librespot[1675741]: time="2026-02-08T00:32:44+07:00" level=debug msg="completed challenge" Feb 08 00:32:44 volumio volumio[1675724]: info: [1770485564874] CoreMusicLibrary::Adding element Webradio Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:44 volumio volumio[1675724]: info: Initializing BBC Radios Feb 08 00:32:44 volumio sudo[1675870]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:44 volumio sudo[1675870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:44 volumio sudo[1675870]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 08 00:32:44 volumio volumio[1675724]: info: Discovery: Getting this device information Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:44 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:44 volumio volumio[1675724]: info: [1770485564953] CoreMusicLibrary::Adding element Jellyfin Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:44 volumio volumio[1675724]: Cannot find translation for source Jellyfin Feb 08 00:32:44 volumio volumio[1675724]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.133","id":"46e269a1-2f26-4df8-b5f6-1749968c4324","name":"Volumio","serviceName":"Volumio","state":{"albumart":"https://i.scdn.co/image/ab67616d0000b2732f2c4ed053b2399461163048","artist":"Ozma","mute":false,"status":"stop","track":"Эхо","volume":48},"type":"device"} Feb 08 00:32:44 volumio volumio[1675724]: info: Creating Spotify config file Feb 08 00:32:44 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:44 volumio volumio-remote-updater[721]: [2026-02-08 00:32:44] [connect] Successful connection Feb 08 00:32:45 volumio go-librespot[1675741]: time="2026-02-08T00:32:45+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:45 volumio volumio[1675724]: info: [1770485565212] CoreMusicLibrary::Adding element YouTube2 Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:45 volumio volumio[1675724]: Cannot find translation for source Jellyfin Feb 08 00:32:45 volumio volumio[1675724]: Cannot find translation for source YouTube2 Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:45 volumio volumio[1675724]: info: [1770485565220] CoreMusicLibrary::Adding element YouTube Music Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:45 volumio volumio[1675724]: Cannot find translation for source Jellyfin Feb 08 00:32:45 volumio volumio[1675724]: Cannot find translation for source YouTube2 Feb 08 00:32:45 volumio volumio[1675724]: Cannot find translation for source YouTube Music Feb 08 00:32:45 volumio volumio[1675724]: info: Volumio Calling Home Feb 08 00:32:45 volumio volumio[1675724]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:45 volumio volumio[1675724]: info: CoreStateMachine::pushState Feb 08 00:32:45 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:45 volumio volumio[1675724]: info: MPD Permissions set Feb 08 00:32:45 volumio volumio[1675724]: info: MPD Permissions set Feb 08 00:32:45 volumio volumio-remote-updater[721]: [2026-02-08 00:32:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770485564 101 Feb 08 00:32:45 volumio volumio[1675724]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 08 00:32:45 volumio volumio[1675724]: info: Spotify config file written Feb 08 00:32:45 volumio volumio[1675724]: info: Discovery: adding 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:45 volumio volumio[1675724]: info: Discovery: Found device Volumio Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:45 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:45 volumio sudo[1675897]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 00:32:45 volumio sudo[1675897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 00:32:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 00:32:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:45 volumio sudo[1675897]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:45 volumio go-librespot[1675904]: go-librespot daemon starting... Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=debug msg="app state loaded" Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:45 volumio mpd[1675880]: 2026-02-08T00:32:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 00:32:45 volumio sudo[1675844]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:45 volumio sudo[1675856]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:45 volumio volumio[1675724]: info: No need to fix Spotify hosts Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:45 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:45 volumio volumio[1675724]: info: Discovery: this is already registered, 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:32:45 volumio volumio[1675724]: info: Discovery: Found device Volumio Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:45 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:45 volumio volumio[1675724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 00:32:45 volumio volumio[1675724]: info: Volumio called home Feb 08 00:32:45 volumio volumio[1675724]: info: Completed starting Core Plugins Feb 08 00:32:45 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:45 volumio volumio[1675724]: info: ----- MyVolumio plugins startup ---- Feb 08 00:32:45 volumio volumio[1675724]: info: ------------------------------------------- Feb 08 00:32:45 volumio volumio[1675724]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 00:32:45 volumio volumio[1675724]: error: MPD error: The expression evaluated to a falsy value: Feb 08 00:32:45 volumio volumio[1675724]: assert.ok(self.idling) Feb 08 00:32:45 volumio volumio[1675724]: error: The expression evaluated to a falsy value: Feb 08 00:32:45 volumio volumio[1675724]: assert.ok(self.idling) Feb 08 00:32:45 volumio volumio[1675724]: error: updateQueue error: null Feb 08 00:32:45 volumio volumio[1675724]: info: Starting Shairport Sync Feb 08 00:32:45 volumio volumio[1675724]: info: Starting Shairport Sync Feb 08 00:32:45 volumio volumio[1675724]: info: Starting Shairport Sync Feb 08 00:32:45 volumio sudo[1675929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:45 volumio sudo[1675929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:45 volumio sudo[1675932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:45 volumio systemd[1]: shairport-sync.service: Consumed 1.084s CPU time. Feb 08 00:32:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:45 volumio sudo[1675932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:45 volumio sudo[1675929]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:45 volumio sudo[1675934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:32:45 volumio sudo[1675934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:45 volumio volumio[1675724]: info: MPD running with PID1675880 Feb 08 00:32:45 volumio volumio[1675724]: ,establishing connection Feb 08 00:32:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:32:45 volumio volumio[1675724]: info: Shairport-Sync Started Feb 08 00:32:45 volumio volumio[1675724]: Error adding Membership: Error: addMembership EINVAL Feb 08 00:32:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:32:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:45 volumio volumio[1675724]: error: updateQueue error: null Feb 08 00:32:45 volumio volumio[1675724]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:32:45 volumio sudo[1675934]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:45 volumio sudo[1675932]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:45 volumio volumio[1675724]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:45 volumio volumio[1675724]: info: Shairport-Sync Started Feb 08 00:32:45 volumio volumio[1675724]: info: Shairport-Sync Started Feb 08 00:32:45 volumio volumio[1675724]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 08 00:32:45 volumio go-librespot[1675905]: time="2026-02-08T00:32:45+07:00" level=info msg="zeroconf server listening on port 45231" Feb 08 00:32:46 volumio volumio[1675724]: info: [jellyfin-poller] Polled http://192.168.1.202:8096: online Feb 08 00:32:46 volumio go-librespot[1675905]: time="2026-02-08T00:32:46+07:00" level=debug msg="obtained new client token: AACH+e+jfvSv/ERfIkbvhoeZt+W4lrqdKjV/8JZrlXnKfZ/XrFSsWH8yZ2JQ+xv9WCnLLUjUfbFsR2pQpCQDOn5cAEODKde8mOlxzPJMwBHjQji6kBN8AjJIzV+TDued9i2U4WOdtZ21YCnmTDklcILGR+eMnTv0O7g9hyDK1vWXywzxXkcaPB+ndQfpF49XsIXiobESGb4I6s2AJDAuIMnZtS+4whGupDMbA0NdhVLN9mQUEmbiUGImOg==" Feb 08 00:32:46 volumio go-librespot[1675905]: time="2026-02-08T00:32:46+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:46 volumio go-librespot[1675905]: time="2026-02-08T00:32:46+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:46 volumio go-librespot[1675905]: time="2026-02-08T00:32:46+07:00" level=debug msg="completed challenge" Feb 08 00:32:46 volumio go-librespot[1675905]: time="2026-02-08T00:32:46+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:47 volumio go-librespot[1675905]: time="2026-02-08T00:32:47+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:47 volumio go-librespot[1675905]: time="2026-02-08T00:32:47+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:47 volumio go-librespot[1675905]: time="2026-02-08T00:32:47+07:00" level=debug msg="completed challenge" Feb 08 00:32:47 volumio go-librespot[1675905]: time="2026-02-08T00:32:47+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:48 volumio go-librespot[1675905]: time="2026-02-08T00:32:48+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:48 volumio go-librespot[1675905]: time="2026-02-08T00:32:48+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:48 volumio go-librespot[1675905]: time="2026-02-08T00:32:48+07:00" level=debug msg="completed challenge" Feb 08 00:32:48 volumio volumio[1675724]: info: go-librespot daemon successfully initialized Feb 08 00:32:48 volumio go-librespot[1675905]: time="2026-02-08T00:32:48+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:49 volumio go-librespot[1675905]: time="2026-02-08T00:32:49+07:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Feb 08 00:32:49 volumio go-librespot[1675905]: time="2026-02-08T00:32:49+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:49 volumio go-librespot[1675905]: time="2026-02-08T00:32:49+07:00" level=debug msg="completed challenge" Feb 08 00:32:50 volumio go-librespot[1675905]: time="2026-02-08T00:32:50+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:50 volumio go-librespot[1675905]: time="2026-02-08T00:32:50+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 08 00:32:50 volumio volumio[1675724]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 00:32:50 volumio go-librespot[1675905]: time="2026-02-08T00:32:50+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:50 volumio go-librespot[1675905]: time="2026-02-08T00:32:50+07:00" level=debug msg="completed challenge" Feb 08 00:32:50 volumio go-librespot[1675905]: time="2026-02-08T00:32:50+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:51 volumio go-librespot[1675905]: time="2026-02-08T00:32:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 08 00:32:51 volumio volumio[1675724]: info: Initializing connection to go-librespot Websocket Feb 08 00:32:51 volumio go-librespot[1675905]: time="2026-02-08T00:32:51+07:00" level=debug msg="new websocket client" Feb 08 00:32:51 volumio volumio[1675724]: info: Connection to go-librespot Websocket established Feb 08 00:32:51 volumio sudo[1675992]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:51 volumio sudo[1675992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:51 volumio sudo[1675992]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:51 volumio sudo[1675990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:51 volumio sudo[1675990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:51 volumio sudo[1675990]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:52 volumio sudo[1675998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 00:32:52 volumio sudo[1675998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:52 volumio sudo[1675998]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:52 volumio volumio[1675724]: info: Upmpdcli Daemon Started Feb 08 00:32:52 volumio go-librespot[1675905]: time="2026-02-08T00:32:52+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 08 00:32:52 volumio go-librespot[1675905]: time="2026-02-08T00:32:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 08 00:32:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 00:32:52 volumio volumio[1675724]: info: Connection to go-librespot Websocket closed Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 00:32:53 volumio volumio[1675724]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 00:32:54 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:54 volumio volumio[1675724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:54 volumio volumio[1675724]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 00:32:54 volumio volumio[1675724]: info: MyVolumio login type: Token Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 00:32:54 volumio volumio[1675724]: info: Streaming services startup Feb 08 00:32:54 volumio volumio[1675724]: info: Starting Streaming Daemon Feb 08 00:32:54 volumio sudo[1676003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 00:32:54 volumio sudo[1676003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:54 volumio sudo[1676003]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:54 volumio volumio[1675724]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 00:32:54 volumio volumio[1675724]: error: Cannot start Volumio Streaming Daemon Feb 08 00:32:54 volumio volumio[1675724]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 00:32:54 volumio volumio[1675724]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 00:32:54 volumio volumio[1675724]: info: Getting Spotify volume Feb 08 00:32:54 volumio volumio[1675724]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:54 volumio volumio[1675724]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 00:32:54 volumio volumio[1675724]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 00:32:54 volumio volumio[1675724]: errno: -111, Feb 08 00:32:54 volumio volumio[1675724]: code: 'ECONNREFUSED', Feb 08 00:32:54 volumio volumio[1675724]: syscall: 'connect', Feb 08 00:32:54 volumio volumio[1675724]: address: '127.0.0.1', Feb 08 00:32:54 volumio volumio[1675724]: port: 9879, Feb 08 00:32:54 volumio volumio[1675724]: response: undefined Feb 08 00:32:54 volumio volumio[1675724]: } Feb 08 00:32:54 volumio volumio[1675724]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:32:54 volumio sudo[1676024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 00:31' Feb 08 00:32:54 volumio sudo[1676024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:55 volumio sudo[1676024]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:55 volumio volumio-remote-updater[721]: [2026-02-08 00:32:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 00:32:55 volumio volumio-remote-updater[721]: [2026-02-08 00:32:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 00:32:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:32:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 00:32:55 volumio systemd[1]: volumio.service: Consumed 3.779s CPU time. Feb 08 00:32:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 00:32:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4713. Feb 08 00:32:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 00:32:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:55 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 00:32:55 volumio systemd[1]: volumio.service: Consumed 3.779s CPU time. Feb 08 00:32:55 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 00:32:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:32:55 volumio go-librespot[1676040]: go-librespot daemon starting... Feb 08 00:32:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07:00" level=debug msg="app state loaded" Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07: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]" Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07: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]" Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07: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]" Feb 08 00:32:55 volumio go-librespot[1676043]: time="2026-02-08T00:32:55+07:00" level=info msg="zeroconf server listening on port 34703" Feb 08 00:32:55 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:32:55 volumio volumio[1676036]: info: ----- Volumio3 ---- Feb 08 00:32:55 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:32:55 volumio volumio[1676036]: info: ----- System startup ---- Feb 08 00:32:55 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:32:56 volumio volumio[1676036]: info: MYVOLUMIO Environment detected Feb 08 00:32:56 volumio go-librespot[1676043]: time="2026-02-08T00:32:56+07:00" level=debug msg="obtained new client token: AAB5a2ssinF+hU2hkfZ9FhL8ya8u1Wj/1T/RLTA1o6cpLhNwB30t8x9RVCELWKeti76rjYLav0HbDICwyPvxjK+jorhnxxHb7ScTnZAQ3Vyx6nd5BilZyGhV1R1R2aXawGq5m84me9Ny2zLDe+VZbgEjKKtOmDvfOCta19oavW2G3KrGtPnNWGNfbbrAyM57QgFM33SGyNvNLWPug59d+s7t4+TgPxsjQVNG25EIDO/QW9xn2efaM+o=" Feb 08 00:32:56 volumio go-librespot[1676043]: time="2026-02-08T00:32:56+07:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 08 00:32:56 volumio volumio[1676036]: info: Plugin folders cleanup Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning into folder /volumio/app/plugins/ Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category audio_interface Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category miscellanea Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category music_service Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category plugins.json Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category system_controller Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category user_interface Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning into folder /data/plugins/ Feb 08 00:32:56 volumio volumio[1676036]: info: Scanning category music_service Feb 08 00:32:56 volumio volumio[1676036]: info: Plugin folders cleanup completed Feb 08 00:32:56 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:32:56 volumio volumio[1676036]: info: ----- Core plugins startup ---- Feb 08 00:32:56 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 00:32:56 volumio volumio[1676036]: info: Adding plugin upnp to MyMusic Plugins Feb 08 00:32:56 volumio volumio[1676036]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 00:32:56 volumio volumio[1676036]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugins from folder /data/plugins/ Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "system"... Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "appearance"... Feb 08 00:32:56 volumio go-librespot[1676043]: time="2026-02-08T00:32:56+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:56 volumio go-librespot[1676043]: time="2026-02-08T00:32:56+07:00" level=debug msg="completed challenge" Feb 08 00:32:56 volumio go-librespot[1676043]: time="2026-02-08T00:32:56+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "network"... Feb 08 00:32:56 volumio volumio[1676036]: info: Refreshing Cached IP Addresses Feb 08 00:32:56 volumio sudo[1676075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:32:56 volumio sudo[1676075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:56 volumio sudo[1676075]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:56 volumio sudo[1676078]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:32:56 volumio sudo[1676078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:56 volumio sudo[1676085]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "services"... Feb 08 00:32:56 volumio sudo[1676085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "alsa_controller"... Feb 08 00:32:56 volumio sudo[1676085]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:56 volumio sudo[1676078]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:56 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "wizard"... Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "networkfs"... Feb 08 00:32:56 volumio volumio[1676036]: info: Starting Udev Watcher for removable devices Feb 08 00:32:56 volumio volumio[1676036]: info: Ignoring mount for partition: boot Feb 08 00:32:56 volumio volumio[1676036]: info: Ignoring mount for partition: volumio Feb 08 00:32:56 volumio volumio[1676036]: info: Ignoring mount for partition: volumio_data Feb 08 00:32:56 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "volumio_command_line_client"... Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "upnp"... Feb 08 00:32:56 volumio volumio[1676036]: info: [1770485576872] Starting Upmpd Daemon Feb 08 00:32:56 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "my_music"... Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "mpd"... Feb 08 00:32:56 volumio volumio[1676036]: info: Loading plugin "upnp_browser"... Feb 08 00:32:57 volumio go-librespot[1676043]: time="2026-02-08T00:32:57+07:00" level=debug msg="connected to ap-gew4.spotify.com:443" Feb 08 00:32:57 volumio go-librespot[1676043]: time="2026-02-08T00:32:57+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:57 volumio go-librespot[1676043]: time="2026-02-08T00:32:57+07:00" level=debug msg="completed challenge" Feb 08 00:32:57 volumio volumio[1676036]: info: Starting UPNP Browser Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "alarm-clock"... Feb 08 00:32:57 volumio go-librespot[1676043]: time="2026-02-08T00:32:57+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "airplay_emulation"... Feb 08 00:32:57 volumio volumio[1676036]: info: Starting Shairport Sync Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "last_100"... Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "webradio"... Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "i2s_dacs"... Feb 08 00:32:57 volumio volumio[1676036]: info: I2S DAC not set, start Auto-detection Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "volumiodiscovery"... Feb 08 00:32:57 volumio volumio[1676036]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:57 volumio volumio[1676036]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:57 volumio volumio[1676036]: *** WARNING *** For more information see Feb 08 00:32:57 volumio volumio[1676036]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:57 volumio node[1676036]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:57 volumio volumio[1676036]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:57 volumio volumio[1676036]: *** WARNING *** For more information see Feb 08 00:32:57 volumio node[1676036]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:57 volumio node[1676036]: *** WARNING *** For more information see Feb 08 00:32:57 volumio node[1676036]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 00:32:57 volumio node[1676036]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 00:32:57 volumio node[1676036]: *** WARNING *** For more information see Feb 08 00:32:57 volumio volumio[1676036]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 00:32:57 volumio volumio[1676036]: info: Discovery: Started advertising with name: Volumio Feb 08 00:32:57 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:57 volumio volumio[1676036]: info: Loading plugin "jellyfin"... Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "spop"... Feb 08 00:32:58 volumio go-librespot[1676043]: time="2026-02-08T00:32:58+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Feb 08 00:32:58 volumio go-librespot[1676043]: time="2026-02-08T00:32:58+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:58 volumio go-librespot[1676043]: time="2026-02-08T00:32:58+07:00" level=debug msg="completed challenge" Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "youtube2"... Feb 08 00:32:58 volumio go-librespot[1676043]: time="2026-02-08T00:32:58+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "ytmusic"... Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "outputs"... Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "albumart"... Feb 08 00:32:58 volumio volumio[1676036]: info: Plugin example_plugin is not enabled Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "inputs"... Feb 08 00:32:58 volumio volumio[1676036]: info: Loading plugin "updater_comm"... Feb 08 00:32:59 volumio go-librespot[1676043]: time="2026-02-08T00:32:59+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 00:32:59 volumio volumio[1676116]: Forking 1 albumart workers Feb 08 00:32:59 volumio volumio[1676036]: info: Plugin mpdemulation is not enabled Feb 08 00:32:59 volumio volumio[1676036]: info: Loading plugin "rest_api"... Feb 08 00:32:59 volumio volumio[1676036]: info: Loading plugin "websocket"... Feb 08 00:32:59 volumio volumio[1676036]: info: Starting Socket.io Server version 1.7.4 Feb 08 00:32:59 volumio volumio[1676036]: info: Loading i18n strings for locale ru Feb 08 00:32:59 volumio volumio[1676036]: Updating browse sources language Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::initPlayerControls Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: Express server listening on port 3000 Feb 08 00:32:59 volumio volumio[1676036]: [Metrics] WebUI: 3s 507.27ms Feb 08 00:32:59 volumio volumio[1676036]: info: Setting Device type: x86 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::resetVolumioState Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::getcurrentVolume Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Feb 08 00:32:59 volumio volumio[1676036]: info: Completed loading Core Plugins Feb 08 00:32:59 volumio volumio[1676036]: info: Preparing to generate the ALSA configuration file Feb 08 00:32:59 volumio volumio[1676036]: info: Volumio Network Manager: Network status updated: 1 Feb 08 00:32:59 volumio volumio[1676036]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 08 00:32:59 volumio volumio[1676036]: wlan0 Interface doesn't support scanning. Feb 08 00:32:59 volumio volumio[1676036]: info: Cannot use regular scanning, forcing with ap-force Feb 08 00:32:59 volumio sudo[1676140]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 08 00:32:59 volumio sudo[1676140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:59 volumio sudo[1676140]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:59 volumio volumio[1676036]: command failed: No such device (-19) Feb 08 00:32:59 volumio volumio[1676036]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 08 00:32:59 volumio volumio[1676036]: command failed: No such device (-19) Feb 08 00:32:59 volumio volumio[1676036]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Feb 08 00:32:59 volumio volumio[1676036]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::pushState Feb 08 00:32:59 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::updateTrackBlock Feb 08 00:32:59 volumio volumio[1676036]: info: CorePlayQueue::getTrackBlock Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 00:32:59 volumio volumio[1676036]: info: Reloading queue from file Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::setRepeat null single undefined Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::pushState Feb 08 00:32:59 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::setRandom null Feb 08 00:32:59 volumio volumio[1676036]: info: CoreStateMachine::pushState Feb 08 00:32:59 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioPushState Feb 08 00:32:59 volumio volumio[1676036]: info: Asound.conf file unchanged, so no further update is needed Feb 08 00:32:59 volumio volumio[1676036]: info: Output device has changed, restarting MPD Feb 08 00:32:59 volumio volumio[1676036]: info: Output device has changed, restarting Shairport Sync Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:59 volumio sudo[1676154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:59 volumio sudo[1676154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:59 volumio sudo[1676152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:59 volumio sudo[1676152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:59 volumio sudo[1676152]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:59 volumio volumio[1676036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:59 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 00:32:59 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:59 volumio volumio[1676036]: info: ___________ START PLUGINS ___________ Feb 08 00:32:59 volumio volumio[1676036]: info: ControllerMpd::onStart: Initializing MPD Feb 08 00:32:59 volumio volumio[1676036]: info: Creating MPD Configuration file Feb 08 00:32:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:59 volumio volumio[1676036]: info: [1770485579570] CoreMusicLibrary::Adding element Медиа-серверы Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:59 volumio sudo[1676163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 00:32:59 volumio sudo[1676163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:59 volumio sudo[1676166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 00:32:59 volumio sudo[1676166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:32:59 volumio volumio[1676036]: info: UPNP Browser: Client initialized successfully Feb 08 00:32:59 volumio sudo[1676163]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:59 volumio volumio[1676126]: Starting albumart workers Feb 08 00:32:59 volumio sudo[1676164]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:59 volumio sudo[1676164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:59 volumio sudo[1676164]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:59 volumio go-librespot[1676043]: time="2026-02-08T00:32:59+07:00" level=debug msg="completed keyexchange" Feb 08 00:32:59 volumio go-librespot[1676043]: time="2026-02-08T00:32:59+07:00" level=debug msg="completed challenge" Feb 08 00:32:59 volumio volumio[1676036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:59 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 08 00:32:59 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 00:32:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 00:32:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 00:32:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 00:32:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 00:32:59 volumio volumio[1676036]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:59 volumio volumio[1676036]: info: [1770485579715] CoreMusicLibrary::Adding element Last_100 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:59 volumio volumio[1676036]: info: [1770485579716] CoreMusicLibrary::Adding element Webradio Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 00:32:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:59 volumio volumio[1676036]: info: Initializing BBC Radios Feb 08 00:32:59 volumio sudo[1676184]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 00:32:59 volumio sudo[1676184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 00:32:59 volumio sudo[1676184]: pam_unix(sudo:session): session closed for user root Feb 08 00:32:59 volumio go-librespot[1676043]: time="2026-02-08T00:32:59+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 08 00:32:59 volumio volumio[1676036]: info: Discovery: Getting this device information Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:32:59 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:32:59 volumio volumio[1676036]: info: [1770485579874] CoreMusicLibrary::Adding element Jellyfin Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:32:59 volumio volumio[1676036]: Cannot find translation for source Jellyfin Feb 08 00:32:59 volumio volumio[1676036]: info: [jellyfin] Initialized plugin with device info: {"host":"http://192.168.1.133","id":"46e269a1-2f26-4df8-b5f6-1749968c4324","name":"Volumio","serviceName":"Volumio","state":{"albumart":"https://i.scdn.co/image/ab67616d0000b2732f2c4ed053b2399461163048","artist":"Ozma","mute":false,"status":"stop","track":"Эхо","volume":48},"type":"device"} Feb 08 00:32:59 volumio volumio[1676036]: info: Creating Spotify config file Feb 08 00:32:59 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:33:00 volumio volumio[1676036]: info: [1770485580105] CoreMusicLibrary::Adding element YouTube2 Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:33:00 volumio volumio[1676036]: Cannot find translation for source Jellyfin Feb 08 00:33:00 volumio volumio[1676036]: Cannot find translation for source YouTube2 Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 00:33:00 volumio volumio[1676036]: info: [1770485580119] CoreMusicLibrary::Adding element YouTube Music Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 00:33:00 volumio volumio[1676036]: Cannot find translation for source Jellyfin Feb 08 00:33:00 volumio volumio[1676036]: Cannot find translation for source YouTube2 Feb 08 00:33:00 volumio volumio[1676036]: Cannot find translation for source YouTube Music Feb 08 00:33:00 volumio volumio[1676036]: info: Volumio Calling Home Feb 08 00:33:00 volumio volumio-remote-updater[721]: [2026-02-08 00:33:00] [connect] Successful connection Feb 08 00:33:00 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 08 00:33:00 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 08 00:33:00 volumio volumio[1676036]: info: MPD Permissions set Feb 08 00:33:00 volumio volumio[1676036]: info: MPD Permissions set Feb 08 00:33:00 volumio volumio[1676036]: info: VolumeController:: Volume=48 Mute =false Feb 08 00:33:00 volumio volumio[1676036]: info: CoreStateMachine::pushState Feb 08 00:33:00 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::volumioPushState Feb 08 00:33:00 volumio go-librespot[1676043]: time="2026-02-08T00:33:00+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 08 00:33:00 volumio volumio-remote-updater[721]: [2026-02-08 00:33:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770485580 101 Feb 08 00:33:00 volumio volumio[1676036]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 08 00:33:00 volumio volumio[1676036]: info: Spotify config file written Feb 08 00:33:00 volumio sudo[1676234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 00:33:00 volumio sudo[1676234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:00 volumio volumio[1676036]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:33:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 00:33:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 00:33:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 00:33:00 volumio go-librespot[1676241]: go-librespot daemon starting... Feb 08 00:33:00 volumio sudo[1676234]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:00 volumio mpd[1676200]: 2026-02-08T00:33:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 00:33:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 00:33:00 volumio go-librespot[1676245]: time="2026-02-08T00:33:00+07:00" level=info msg="running go-librespot 0.6.2" Feb 08 00:33:00 volumio go-librespot[1676245]: time="2026-02-08T00:33:00+07:00" level=debug msg="app state loaded" Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio sudo[1676154]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:00 volumio sudo[1676166]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:00 volumio go-librespot[1676245]: time="2026-02-08T00:33:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 00:33:00 volumio volumio[1676036]: info: No need to fix Spotify hosts Feb 08 00:33:00 volumio volumio[1676036]: info: Discovery: adding 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:33:00 volumio volumio[1676036]: info: Discovery: Found device Volumio Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:00 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:00 volumio volumio[1676036]: info: Volumio called home Feb 08 00:33:00 volumio volumio[1676036]: info: Completed starting Core Plugins Feb 08 00:33:00 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:33:00 volumio volumio[1676036]: info: ----- MyVolumio plugins startup ---- Feb 08 00:33:00 volumio volumio[1676036]: info: ------------------------------------------- Feb 08 00:33:00 volumio volumio[1676036]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 00:33:00 volumio volumio[1676036]: info: [jellyfin-poller] Polled http://192.168.1.202:8096: online Feb 08 00:33:00 volumio volumio[1676036]: info: MPD running with PID1676200 Feb 08 00:33:00 volumio volumio[1676036]: ,establishing connection Feb 08 00:33:00 volumio volumio[1676036]: info: Starting Shairport Sync Feb 08 00:33:00 volumio volumio[1676036]: info: Starting Shairport Sync Feb 08 00:33:00 volumio volumio[1676036]: info: Starting Shairport Sync Feb 08 00:33:00 volumio sudo[1676269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:33:00 volumio sudo[1676269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:00 volumio sudo[1676268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:33:00 volumio sudo[1676268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:33:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:33:00 volumio sudo[1676271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 00:33:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:33:00 volumio sudo[1676271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:33:00 volumio sudo[1676269]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:00 volumio volumio[1676036]: error: MPD error: The expression evaluated to a falsy value: Feb 08 00:33:00 volumio volumio[1676036]: assert.ok(self.idling) Feb 08 00:33:00 volumio volumio[1676036]: error: The expression evaluated to a falsy value: Feb 08 00:33:00 volumio volumio[1676036]: assert.ok(self.idling) Feb 08 00:33:00 volumio volumio[1676036]: error: MPD error: The expression evaluated to a falsy value: Feb 08 00:33:00 volumio volumio[1676036]: assert.ok(self.idling) Feb 08 00:33:00 volumio volumio[1676036]: error: The expression evaluated to a falsy value: Feb 08 00:33:00 volumio volumio[1676036]: assert.ok(self.idling) Feb 08 00:33:00 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 00:33:00 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 00:33:00 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:33:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 00:33:00 volumio sudo[1676271]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:00 volumio sudo[1676268]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:00 volumio volumio[1676036]: info: Shairport-Sync Started Feb 08 00:33:00 volumio volumio[1676036]: Error adding Membership: Error: addMembership EINVAL Feb 08 00:33:00 volumio volumio[1676036]: error: updateQueue error: null Feb 08 00:33:00 volumio volumio[1676036]: info: Shairport-Sync Started Feb 08 00:33:00 volumio volumio[1676036]: info: Shairport-Sync Started Feb 08 00:33:00 volumio volumio[1676036]: info: An error occurred while refreshing Spotify Token Error: Bad Request Feb 08 00:33:00 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:00 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:03 volumio volumio[1676036]: info: go-librespot daemon successfully initialized Feb 08 00:33:05 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:05 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:05 volumio volumio[1676036]: info: Listing playlists Feb 08 00:33:05 volumio volumio[1676036]: info: Listing playlists Feb 08 00:33:05 volumio volumio[1676036]: info: Discovery: this is already registered, 46e269a1-2f26-4df8-b5f6-1749968c4324 Feb 08 00:33:05 volumio volumio[1676036]: info: Discovery: Found device Volumio Feb 08 00:33:05 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:05 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:05 volumio volumio[1676036]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 00:33:05 volumio go-librespot[1676245]: time="2026-02-08T00:33:05+07:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 00:33:05 volumio go-librespot[1676245]: time="2026-02-08T00:33:05+07:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 00:33:05 volumio go-librespot[1676245]: time="2026-02-08T00:33:05+07:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 00:33:05 volumio go-librespot[1676245]: time="2026-02-08T00:33:05+07:00" level=info msg="zeroconf server listening on port 37365" Feb 08 00:33:06 volumio go-librespot[1676245]: time="2026-02-08T00:33:06+07:00" level=debug msg="obtained new client token: AADRcxWl25HQlpig/meAP1eRS/k4aK0gn1wNzL4q8Z1G5UTEDoR6iaBw7Thz9wGb0q3eFvGOdLNCI9jRhDGXI0BIu2R77sId7M1fFGlI9ET+TjfMeAg2VcOsZqFAHufjl/tnp2r8t2zYrDUQ5WfNVwRRDrfaFKeznBgOQRPTbDmXBzhUAaSPfHeEEh1jk/mOnVJfpWWwN77QqMlIfQPcZQi1CmgCpPPqOL069kR/ZQRO++vCeJy5Rjo=" Feb 08 00:33:06 volumio go-librespot[1676245]: time="2026-02-08T00:33:06+07:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 08 00:33:06 volumio go-librespot[1676245]: time="2026-02-08T00:33:06+07:00" level=debug msg="completed keyexchange" Feb 08 00:33:06 volumio go-librespot[1676245]: time="2026-02-08T00:33:06+07:00" level=debug msg="completed challenge" Feb 08 00:33:06 volumio volumio[1676036]: info: Initializing connection to go-librespot Websocket Feb 08 00:33:06 volumio go-librespot[1676245]: time="2026-02-08T00:33:06+07:00" level=debug msg="new websocket client" Feb 08 00:33:06 volumio volumio[1676036]: info: Connection to go-librespot Websocket established Feb 08 00:33:06 volumio go-librespot[1676245]: time="2026-02-08T00:33:06+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:06 volumio sudo[1676313]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 00:33:06 volumio sudo[1676315]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 00:33:06 volumio sudo[1676313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:06 volumio sudo[1676315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:06 volumio sudo[1676315]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:06 volumio sudo[1676313]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:06 volumio sudo[1676321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 00:33:06 volumio sudo[1676321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:06 volumio sudo[1676321]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:06 volumio volumio[1676036]: info: Upmpdcli Daemon Started Feb 08 00:33:07 volumio go-librespot[1676245]: time="2026-02-08T00:33:07+07:00" level=debug msg="connected to ap-gew1.spotify.com:443" Feb 08 00:33:07 volumio go-librespot[1676245]: time="2026-02-08T00:33:07+07:00" level=debug msg="completed keyexchange" Feb 08 00:33:07 volumio go-librespot[1676245]: time="2026-02-08T00:33:07+07:00" level=debug msg="completed challenge" Feb 08 00:33:07 volumio go-librespot[1676245]: time="2026-02-08T00:33:07+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:08 volumio go-librespot[1676245]: time="2026-02-08T00:33:08+07:00" level=debug msg="connected to ap-gew1.spotify.com:80" Feb 08 00:33:08 volumio go-librespot[1676245]: time="2026-02-08T00:33:08+07:00" level=debug msg="completed keyexchange" Feb 08 00:33:08 volumio go-librespot[1676245]: time="2026-02-08T00:33:08+07:00" level=debug msg="completed challenge" Feb 08 00:33:08 volumio go-librespot[1676245]: time="2026-02-08T00:33:08+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 00:33:08 volumio volumio[1676036]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 00:33:09 volumio go-librespot[1676245]: time="2026-02-08T00:33:09+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 00:33:09 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:09 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:09 volumio volumio[1676036]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 00:33:09 volumio volumio[1676036]: info: MyVolumio login type: Token Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 00:33:09 volumio volumio[1676036]: info: Streaming services startup Feb 08 00:33:09 volumio volumio[1676036]: info: Starting Streaming Daemon Feb 08 00:33:09 volumio sudo[1676327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 00:33:09 volumio sudo[1676327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:09 volumio volumio[1676036]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 00:33:09 volumio sudo[1676327]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:09 volumio volumio[1676036]: error: Cannot start Volumio Streaming Daemon Feb 08 00:33:09 volumio volumio[1676036]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 00:33:09 volumio volumio[1676036]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 00:33:09 volumio go-librespot[1676245]: time="2026-02-08T00:33:09+07:00" level=debug msg="completed keyexchange" Feb 08 00:33:09 volumio go-librespot[1676245]: time="2026-02-08T00:33:09+07:00" level=debug msg="completed challenge" Feb 08 00:33:09 volumio volumio[1676036]: info: Getting Spotify volume Feb 08 00:33:09 volumio volumio[1676036]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 08 00:33:09 volumio go-librespot[1676245]: time="2026-02-08T00:33:09+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:09 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:09 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:09 volumio volumio[1676036]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Feb 08 00:33:09 volumio volumio[1676036]: SPOTIFY: SPOTIFY VOLUME undefined Feb 08 00:33:09 volumio volumio[1676036]: SPOTIFY: VOLUMIO VOLUME 48 Feb 08 00:33:09 volumio volumio[1676036]: info: Aligning Spotify Volume to Volumio Volume Feb 08 00:33:09 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:09 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:09 volumio volumio[1676036]: info: Setting Spotify Volume from Volumio: 48 Feb 08 00:33:10 volumio go-librespot[1676245]: time="2026-02-08T00:33:10+07:00" level=debug msg="connected to ap-gue1.spotify.com:443" Feb 08 00:33:10 volumio volumio[1676036]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 08 00:33:10 volumio go-librespot[1676245]: time="2026-02-08T00:33:10+07:00" level=debug msg="completed keyexchange" Feb 08 00:33:10 volumio go-librespot[1676245]: time="2026-02-08T00:33:10+07:00" level=debug msg="completed challenge" Feb 08 00:33:10 volumio go-librespot[1676245]: time="2026-02-08T00:33:10+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:11 volumio volumio[1676036]: info: MyVolumio token set successfully Feb 08 00:33:11 volumio volumio[1676036]: info: MYVOLUMIO: Adding device Feb 08 00:33:11 volumio volumio[1676036]: info: MYVOLUMIO: Evaluating Server Feb 08 00:33:11 volumio volumio[1676036]: SPOTIFY: SETTING SPOTIFY VOLUME 48 Feb 08 00:33:11 volumio volumio[1676036]: info: Sending Spotify command with payload to local API: /player/volume Feb 08 00:33:11 volumio volumio[1676036]: info: MyVolumio status changed Feb 08 00:33:11 volumio volumio[1676036]: info: Streaming services startup Feb 08 00:33:11 volumio volumio[1676036]: info: Starting Streaming Daemon Feb 08 00:33:11 volumio volumio[1676036]: info: Removing browser output: myVolumio user plan is not superstar Feb 08 00:33:11 volumio volumio[1676036]: info: Removing audio output: Feb 08 00:33:11 volumio volumio[1676036]: info: Stoppping Tunnel 1 Feb 08 00:33:11 volumio sudo[1676356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 00:33:11 volumio sudo[1676356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:11 volumio sudo[1676359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 08 00:33:11 volumio sudo[1676359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio sudo[1676356]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:11 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 00:33:11 volumio sudo[1676359]: pam_unix(sudo:session): session closed for user root Feb 08 00:33:11 volumio volumio[1676036]: info: Remote SSH Stopped Feb 08 00:33:11 volumio volumio[1676036]: error: Cannot start Volumio Streaming Daemon Feb 08 00:33:11 volumio volumio[1676036]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 00:33:11 volumio volumio[1676036]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 00:33:15 volumio volumio[1676036]: info: CoreCommandRouter::volumioGetState Feb 08 00:33:15 volumio volumio[1676036]: info: CorePlayQueue::getTrack 0 Feb 08 00:33:16 volumio go-librespot[1676245]: time="2026-02-08T00:33:16+07:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Feb 08 00:33:16 volumio go-librespot[1676245]: time="2026-02-08T00:33:16+07:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Feb 08 00:33:16 volumio volumio[1676036]: info: Setting Geolocation for MyVolumio to eu6 Feb 08 00:33:16 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:16 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:16 volumio volumio[1676036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 00:33:16 volumio go-librespot[1676245]: time="2026-02-08T00:33:16+07:00" level=debug msg="completed keyexchange" Feb 08 00:33:16 volumio go-librespot[1676245]: time="2026-02-08T00:33:16+07:00" level=debug msg="completed challenge" Feb 08 00:33:17 volumio go-librespot[1676245]: time="2026-02-08T00:33:17+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:17 volumio go-librespot[1676245]: time="2026-02-08T00:33:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 00:33:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 00:33:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 00:33:17 volumio volumio[1676036]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Feb 08 00:33:17 volumio volumio[1676036]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:33:17 volumio volumio[1676036]: Error: socket hang up Feb 08 00:33:17 volumio volumio[1676036]: at connResetException (node:internal/errors:720:14) Feb 08 00:33:17 volumio volumio[1676036]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 00:33:17 volumio volumio[1676036]: at Socket.emit (node:events:526:35) Feb 08 00:33:17 volumio volumio[1676036]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 00:33:17 volumio volumio[1676036]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 00:33:17 volumio volumio[1676036]: code: 'ECONNRESET', Feb 08 00:33:17 volumio volumio[1676036]: response: undefined Feb 08 00:33:17 volumio volumio[1676036]: } Feb 08 00:33:17 volumio volumio[1676036]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 00:33:17 volumio sudo[1676395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 00:32' Feb 08 00:33:17 volumio sudo[1676395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:38:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="00e933ebe3692ad8aea9910d2289bf23"