-- Logs begin at Sat 2025-12-27 17:39:55 CET, end at Sat 2025-12-27 17:41:49 CET. -- Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 27 17:40:00 volumio ntpd[892]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Dec 27 17:40:00 volumio volumio[935]: 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/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::volumioGetVisibleSources Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:00 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 27 17:40:00 volumio volumio[935]: info: Received Get System Info Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:40:00 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:00 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:00 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:00 volumio volumio[935]: info: Listing playlists Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 27 17:40:00 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 27 17:40:01 volumio volumio-remote-updater[693]: [2025-12-27 17:40:01] [connect] Successful connection Dec 27 17:40:01 volumio volumio-remote-updater[693]: [2025-12-27 17:40:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1766853601 101 Dec 27 17:40:01 volumio volumio[935]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 4 Dec 27 17:40:01 volumio volumio-time-update[701]: volumio-time-update-util: Fetching time from Volumio... Dec 27 17:40:01 volumio volumio-time-update[701]: volumio-time-update-util: Date not found in response Dec 27 17:40:01 volumio volumio-time-update[701]: volumio-time-update-util: Retrying in 5 seconds... Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:01 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 27 17:40:01 volumio volumio[935]: info: CoreStateMachine::getcurrentVolume Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 17:40:01 volumio volumio[935]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Dec 27 17:40:01 volumio volumio[935]: info: VolumeController:: Volume=undefined Mute =false Dec 27 17:40:01 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:01 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:01 volumio volumio[935]: info: CoreStateMachine::updateTrackBlock Dec 27 17:40:01 volumio volumio[935]: info: CorePlayQueue::getTrackBlock Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 17:40:01 volumio volumio[935]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Dec 27 17:40:01 volumio volumio[935]: info: VolumeController:: Volume=undefined Mute =false Dec 27 17:40:01 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:01 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:01 volumio dhcpcd[806]: eth0: leased 192.168.1.16 for 86400 seconds Dec 27 17:40:01 volumio dhcpcd[806]: eth0: adding route to 192.168.1.0/24 Dec 27 17:40:01 volumio dhcpcd[806]: eth0: adding default route via 192.168.1.1 Dec 27 17:40:01 volumio avahi-daemon[703]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.16. Dec 27 17:40:01 volumio avahi-daemon[703]: New relevant interface eth0.IPv4 for mDNS. Dec 27 17:40:01 volumio avahi-daemon[703]: Registering new address record for 192.168.1.16 on eth0.IPv4. Dec 27 17:40:01 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 27 17:40:01 volumio ntpd[892]: ntpd exiting on signal 15 (Terminated) Dec 27 17:40:01 volumio systemd[1]: Stopping Network Time Service... Dec 27 17:40:01 volumio systemd[1]: ntp.service: Succeeded. Dec 27 17:40:01 volumio systemd[1]: Stopped Network Time Service. Dec 27 17:40:01 volumio systemd[1]: Starting Network Time Service... Dec 27 17:40:01 volumio ntpd[1682]: ntpd 4.2.8p12@1.3728-o (1): Starting Dec 27 17:40:01 volumio ntpd[1682]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Dec 27 17:40:01 volumio systemd[1]: Started Network Time Service. Dec 27 17:40:01 volumio ntpd[1688]: proto: precision = 0.074 usec (-24) Dec 27 17:40:01 volumio ntpd[1688]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Dec 27 17:40:01 volumio ntpd[1688]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Dec 27 17:40:01 volumio ntpd[1688]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1096 days ago Dec 27 17:40:01 volumio ntpd[1688]: Listen and drop on 0 v6wildcard [::]:123 Dec 27 17:40:01 volumio ntpd[1688]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Dec 27 17:40:01 volumio ntpd[1688]: Listen normally on 2 lo 127.0.0.1:123 Dec 27 17:40:01 volumio ntpd[1688]: Listen normally on 3 eth0 192.168.1.16:123 Dec 27 17:40:01 volumio ntpd[1688]: Listening on routing socket on fd #20 for interface updates Dec 27 17:40:01 volumio ntpd[1688]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 27 17:40:01 volumio ntpd[1688]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Dec 27 17:40:02 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 17:40:02 volumio volumio[935]: info: Received Get System Info Dec 27 17:40:02 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:40:02 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:40:02 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:40:02 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:02 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:02 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:40:02 volumio volumio[935]: info: go-librespot daemon successfully initialized Dec 27 17:40:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 27 17:40:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 27 17:40:02 volumio systemd[1]: Stopped go-librespot Daemon. Dec 27 17:40:02 volumio systemd[1]: Started go-librespot Daemon. Dec 27 17:40:02 volumio go-librespot[1691]: go-librespot daemon starting... Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01:00" level=info msg="running go-librespot 0.4.0" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01:00" level=debug msg="app state loaded" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 27 17:40:02 volumio sudo[1700]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:40:02 volumio sudo[1700]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:02 volumio sudo[1703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:40:02 volumio sudo[1703]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01: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]" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01: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]" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01: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]" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01:00" level=info msg="zeroconf server listening on port 38947" Dec 27 17:40:02 volumio systemd[1]: Started MPD Monitor Service. Dec 27 17:40:02 volumio sudo[1700]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:02 volumio mpd_monitor.sh[1704]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 17:40:02 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 17:40:02 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 17:40:02 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 17:40:02 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:40:02 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 17:40:02 volumio systemd[1]: Started MPD Monitor Service. Dec 27 17:40:02 volumio sudo[1703]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:02 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:40:02 volumio mpd_monitor.sh[1707]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01:00" level=debug msg="obtained new client token: AAAncltOKdm/xZh176AlbfHjiFtoODy78V2U8gP3HNm5AsCeRW7gu7p92E4ZgJm28iQ//CTFlAaJhETJBc2yTk7Y2yv3MO2kYpZQ78aS+QYvY/PK3BqZo+o050jQQ6qQBmgvPpsnus2+dMAUgKTjm3NQmE/EcqDLilRc9/ItkXGoZn0LcYAuezVO5sftVsCdCymsCfw+aWOL1Pcz/HUnb4dp7LDwTYqzH4NvNgCvu3Lk/E0wlkInbyP7" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 27 17:40:02 volumio go-librespot[1691]: time="2025-12-27T17:40:02+01: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" Dec 27 17:40:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 27 17:40:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 27 17:40:02 volumio volumio[935]: info: Discovery: adding f2e287d1-8d57-4cf4-b87a-7e64c08b0c3a Dec 27 17:40:02 volumio volumio[935]: info: Discovery: Found device Volumio Dec 27 17:40:02 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:02 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:02 volumio ntpd[1688]: Soliciting pool server 31.58.102.164 Dec 27 17:40:03 volumio ntpd[1688]: Soliciting pool server 51.210.104.72 Dec 27 17:40:03 volumio ntpd[1688]: Soliciting pool server 38.242.218.253 Dec 27 17:40:04 volumio volumio[935]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 27 17:40:04 volumio ntpd[1688]: Soliciting pool server 172.233.248.179 Dec 27 17:40:04 volumio ntpd[1688]: Soliciting pool server 194.177.34.116 Dec 27 17:40:04 volumio ntpd[1688]: Soliciting pool server 109.190.177.200 Dec 27 17:40:05 volumio volumio[935]: info: Initializing connection to go-librespot Websocket Dec 27 17:40:05 volumio volumio[935]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 27 17:40:05 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 17:40:05 volumio volumio[935]: info: Received Get System Info Dec 27 17:40:05 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:40:05 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:40:05 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:40:05 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:05 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:05 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:40:05 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 82.67.62.62 Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 82.66.40.79 Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 194.57.169.1 Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 5.39.80.51 Dec 27 17:40:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Dec 27 17:40:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 27 17:40:05 volumio systemd[1]: Stopped go-librespot Daemon. Dec 27 17:40:05 volumio systemd[1]: Started go-librespot Daemon. Dec 27 17:40:05 volumio go-librespot[1711]: go-librespot daemon starting... Dec 27 17:40:05 volumio go-librespot[1711]: time="2025-12-27T17:40:05+01:00" level=info msg="running go-librespot 0.4.0" Dec 27 17:40:05 volumio go-librespot[1711]: time="2025-12-27T17:40:05+01:00" level=debug msg="app state loaded" Dec 27 17:40:05 volumio go-librespot[1711]: time="2025-12-27T17:40:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 27 17:40:06 volumio volumio-time-update[701]: volumio-time-update-util: Fetching time from Volumio... Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=info msg="zeroconf server listening on port 42899" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="obtained new client token: AACjm15jEQGMVJbZWIp+oQ0jJDNs9VTERGoeRcak2LzR00vqWCtUkSdpRdoyI8orMdaenwRCfm36RxShR3iUhfvY7MVPCGslLXNHMm8L4YVVrEhWZ+aXphYUqG5stFzWp/DyMFPg8gBc6vn9qhtlwBJuIAlUxr0nOGsyD07v6j2STJIraoeGeTbHHIaNWCh4TYKOAYY9ixHBjBD9AOu1qJ2QDiDcni7fk5WAf8ldLX7bLr2nVGCJbCzW" Dec 27 17:40:06 volumio volumio-time-update[701]: volumio-time-update-util: Setting system time to: 2025-12-27 17:40:05 Dec 27 17:40:06 volumio sudo[1724]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-12-27 17:40:05 Dec 27 17:40:06 volumio sudo[1724]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:06 volumio dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.14' (uid=0 pid=1725 comm="timedatectl set-time 2025-12-27 17:40:05 ") Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="completed keyexchange" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="completed challenge" Dec 27 17:40:06 volumio systemd[1]: Starting Time & Date Service... Dec 27 17:40:06 volumio dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.timedate1' Dec 27 17:40:06 volumio systemd[1]: Started Time & Date Service. Dec 27 17:40:05 volumio systemd-timedated[1726]: Changed local time to Sat Dec 27 17:40:05 2025 Dec 27 17:40:05 volumio sudo[1724]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:05 volumio volumio-time-update[701]: volumio-time-update-util: System time updated successfully. Dec 27 17:40:05 volumio systemd[1]: Started Volumio Time Update Utility. Dec 27 17:40:05 volumio go-librespot[1711]: time="2025-12-27T17:40:05+01:00" level=info msg="authenticated AP" username="31************************2e" Dec 27 17:40:05 volumio nmbd[848]: [2025/12/27 17:40:05.098100, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 27 17:40:05 volumio nmbd[848]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Dec 27 17:40:05 volumio systemd[1]: Started Samba NMB Daemon. Dec 27 17:40:05 volumio systemd[1]: Starting Samba Winbind Daemon... Dec 27 17:40:05 volumio winbindd[1728]: [2025/12/27 17:40:05.161264, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Dec 27 17:40:05 volumio winbindd[1728]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Dec 27 17:40:05 volumio winbindd[1728]: [2025/12/27 17:40:05.162053, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 27 17:40:05 volumio winbindd[1728]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Dec 27 17:40:05 volumio systemd[1]: Started Samba Winbind Daemon. Dec 27 17:40:05 volumio go-librespot[1711]: time="2025-12-27T17:40:05+01:00" level=info msg="authenticated Login5" username="31************************2e" Dec 27 17:40:05 volumio go-librespot[1711]: time="2025-12-27T17:40:05+01:00" level=debug msg="initializing zeroconf session" username="31************************2e" Dec 27 17:40:05 volumio systemd[1]: Starting Samba SMB Daemon... Dec 27 17:40:05 volumio smbd[1733]: [2025/12/27 17:40:05.241611, 0] ../lib/util/become_daemon.c:138(daemon_ready) Dec 27 17:40:05 volumio smbd[1733]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Dec 27 17:40:05 volumio systemd[1]: Started Samba SMB Daemon. Dec 27 17:40:05 volumio systemd[1]: Reached target Multi-User System. Dec 27 17:40:05 volumio systemd[1]: Reached target Graphical Interface. Dec 27 17:40:05 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Dec 27 17:40:05 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Dec 27 17:40:05 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Dec 27 17:40:05 volumio systemd[1]: Startup finished in 5.032s (firmware) + 540ms (loader) + 4.701s (kernel) + 11.468s (userspace) = 21.742s. Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 82.67.41.119 Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 54.38.114.34 Dec 27 17:40:05 volumio ntpd[1688]: Soliciting pool server 188.165.49.6 Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="dealer connection opened" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=trace msg="starting accesspoint recv loop" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=trace msg="starting dealer recv loop" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=trace msg="received accesspoint ping" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="received connection id: MzA3NTYwMjUtYTMw...RDgyRTZGQkM5MA==" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=trace msg="received accesspoint pong ack" Dec 27 17:40:06 volumio go-librespot[1711]: time="2025-12-27T17:40:06+01:00" level=debug msg="put connect state because NEW_DEVICE" Dec 27 17:40:06 volumio volumio[935]: info: Volumio Network Manager: Network status updated: 1 Dec 27 17:40:06 volumio sudo[1757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 27 17:40:06 volumio sudo[1757]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:06 volumio sudo[1757]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:06 volumio sudo[1759]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 27 17:40:06 volumio sudo[1759]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:06 volumio sudo[1759]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:06 volumio sudo[1764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 27 17:40:06 volumio sudo[1764]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:06 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Dec 27 17:40:06 volumio sudo[1764]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:06 volumio volumio[935]: info: Upmpdcli Daemon Started Dec 27 17:40:06 volumio ntpd[1688]: Soliciting pool server 193.42.63.23 Dec 27 17:40:06 volumio ntpd[1688]: Soliciting pool server 5.196.76.84 Dec 27 17:40:06 volumio volumio[1767]: Generating RSA private key, 4096 bit long modulus (2 primes) Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin bluetooth to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin multiroom to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin metavolumio to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin cd_controller to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 27 17:40:06 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:06 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:06 volumio volumio[935]: info: Starting MyVolumio Remote Streaming Endpoints Dec 27 17:40:06 volumio volumio[935]: info: MyVolumio login type: Token Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 27 17:40:06 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 27 17:40:07 volumio volumio[1767]: ..........................................................++++ Dec 27 17:40:07 volumio volumio[935]: info: Starting Streaming Service Transparent Proxy Dec 27 17:40:07 volumio volumio[935]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 27 17:40:07 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 27 17:40:07 volumio volumio[935]: info: Streaming services startup Dec 27 17:40:07 volumio volumio[935]: info: Starting Streaming Daemon Dec 27 17:40:07 volumio sudo[1790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 27 17:40:07 volumio sudo[1790]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:07 volumio sudo[1790]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:07 volumio volumio[935]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 27 17:40:07 volumio volumio[935]: info: Initializing connection to go-librespot Websocket Dec 27 17:40:07 volumio volumio[935]: error: Cannot start Volumio Streaming Daemon Dec 27 17:40:07 volumio volumio[935]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 27 17:40:07 volumio volumio[935]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 27 17:40:07 volumio go-librespot[1711]: time="2025-12-27T17:40:07+01:00" level=debug msg="new websocket client" Dec 27 17:40:07 volumio volumio[935]: info: Connection to go-librespot Websocket established Dec 27 17:40:07 volumio volumio[935]: STREAMING PROXY: Starting server on port 3245 Dec 27 17:40:07 volumio volumio[935]: Node JS runtime: 14 Dec 27 17:40:07 volumio volumio[935]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 27 17:40:07 volumio ntpd[1688]: Soliciting pool server 79.143.250.33 Dec 27 17:40:07 volumio ntpd[1688]: Soliciting pool server 2a12:8ac1:a0::123:2 Dec 27 17:40:07 volumio volumio[1767]: ......................................................................................................................................................++++ Dec 27 17:40:07 volumio volumio[1767]: e is 65537 (0x010001) Dec 27 17:40:07 volumio volumio[1767]: writing RSA key Dec 27 17:40:07 volumio volumio[935]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.886&uuid=ccb7e8e0b6dee9fcc9b182c2ea29fa40" http://updates.volumio.org/downloader-v1/track-device Dec 27 17:40:07 volumio volumio[935]: % Total % Received % Xferd Average Speed Time Time Time Current Dec 27 17:40:07 volumio volumio[935]: Dload Upload Total Spent Left Speed Dec 27 17:40:07 volumio volumio[935]: [132B blob data] Dec 27 17:40:07 volumio volumio[935]: retrying in 5 seconds, trial 0 Dec 27 17:40:07 volumio volumio[935]: info: Volumio Calling Home Dec 27 17:40:08 volumio volumio[935]: info: MyVolumio token set successfully Dec 27 17:40:08 volumio volumio[935]: info: MYVOLUMIO: Adding device Dec 27 17:40:08 volumio volumio[935]: info: MYVOLUMIO: Evaluating Server Dec 27 17:40:08 volumio volumio[935]: info: Volumio called home Dec 27 17:40:08 volumio volumio[935]: info: MyVolumio Plan changed: premium Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Dec 27 17:40:08 volumio volumio[935]: info: Removing browser output: myVolumio user plan is not superstar Dec 27 17:40:08 volumio volumio[935]: info: Removing audio output: Dec 27 17:40:08 volumio volumio[935]: info: MYVOLUMIO: Adding device Dec 27 17:40:08 volumio volumio[935]: info: MYVOLUMIO: Evaluating Server Dec 27 17:40:08 volumio volumio[935]: info: Remote config written successfully Dec 27 17:40:08 volumio volumio[935]: info: Starting Tunnel 1 Dec 27 17:40:08 volumio volumio[935]: info: Starting Tunnel Connection Checker Dec 27 17:40:08 volumio volumio[935]: info: Completed starting MyVolumio Plugin Dec 27 17:40:08 volumio volumio[935]: info: MYVolumio Device enabled Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Dec 27 17:40:08 volumio volumio[935]: info: MyVolumio status changed Dec 27 17:40:08 volumio volumio[935]: info: Streaming services startup Dec 27 17:40:08 volumio volumio[935]: info: Starting Streaming Daemon Dec 27 17:40:08 volumio sudo[1856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 27 17:40:08 volumio sudo[1856]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Dec 27 17:40:08 volumio sudo[1856]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Dec 27 17:40:08 volumio volumio[935]: info: [1766853608481] Starting BluetoothController Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Dec 27 17:40:08 volumio sudo[1859]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Dec 27 17:40:08 volumio sudo[1859]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio sudo[1859]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: MRS: MultiRoom plugin initialized Dec 27 17:40:08 volumio volumio[935]: info: MRS: STOPPING SNAPCLIENT Dec 27 17:40:08 volumio volumio[935]: info: MRS: Snap server stop Dec 27 17:40:08 volumio sudo[1875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Dec 27 17:40:08 volumio sudo[1875]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio volumio[935]: info: MRS: STOPPING volumioStreaming Dec 27 17:40:08 volumio sudo[1878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Dec 27 17:40:08 volumio sudo[1878]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio sudo[1875]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio sudo[1878]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio sudo[1881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Dec 27 17:40:08 volumio sudo[1881]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Dec 27 17:40:08 volumio sudo[1884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Dec 27 17:40:08 volumio sudo[1884]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio sudo[1884]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio sudo[1881]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Dec 27 17:40:08 volumio volumio[935]: info: Preparing to generate the ALSA configuration file Dec 27 17:40:08 volumio volumio[935]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 27 17:40:08 volumio volumio[935]: info: Reading ALSA contributions from plugins. Dec 27 17:40:08 volumio volumio[935]: info: Setting Geolocation for MyVolumio to eu4 Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: Setting Geolocation for MyVolumio to eu6 Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: MRS: Removed streaming files Dec 27 17:40:08 volumio volumio[935]: info: MRS: volumioStreaming STOPPED Dec 27 17:40:08 volumio volumio[935]: info: MRS: SNAPSERVER STOPPED Dec 27 17:40:08 volumio volumio[935]: info: MRS: SNAPCLIENT STOPPED Dec 27 17:40:08 volumio volumio[935]: error: Cannot start Volumio Streaming Daemon Dec 27 17:40:08 volumio volumio[935]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 27 17:40:08 volumio volumio[935]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 27 17:40:08 volumio volumio[935]: info: Asound.conf file written Dec 27 17:40:08 volumio sudo[1887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 27 17:40:08 volumio sudo[1887]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio sudo[1887]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: Output device has changed, restarting MPD Dec 27 17:40:08 volumio sudo[1892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 17:40:08 volumio sudo[1892]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio sudo[1892]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: Output device has changed, restarting Shairport Sync Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:08 volumio sudo[1895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 17:40:08 volumio sudo[1895]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio systemd[1]: Stopping Music Player Daemon... Dec 27 17:40:08 volumio volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 17:40:08 volumio volumio[935]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 27 17:40:08 volumio systemd[1]: mpd.service: Succeeded. Dec 27 17:40:08 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Dec 27 17:40:08 volumio volumio[935]: info: MRS: Pushing multiroomSync output for this device Dec 27 17:40:08 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:08 volumio sudo[1904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Dec 27 17:40:08 volumio sudo[1904]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio volumio[935]: info: Adding audio output: Dec 27 17:40:08 volumio volumio[935]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Dec 27 17:40:08 volumio volumio[935]: info: Adding METAVOLUMIO REST API Endpoints Dec 27 17:40:08 volumio volumio[935]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Dec 27 17:40:08 volumio volumio[935]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Dec 27 17:40:08 volumio volumio[935]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Dec 27 17:40:08 volumio volumio[935]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Dec 27 17:40:08 volumio volumio[935]: info: Preparing CD Folders Dec 27 17:40:08 volumio sudo[1904]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: Adding CD REST API Endpoints Dec 27 17:40:08 volumio volumio[935]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Dec 27 17:40:08 volumio volumio[935]: info: Starting UDEV Watcher for CD Dec 27 17:40:08 volumio volumio[935]: info: Detecting CD presence with UDEV Dec 27 17:40:08 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Dec 27 17:40:08 volumio systemd[1]: Starting Music Player Daemon... Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Dec 27 17:40:08 volumio volumio[935]: info: Adding inputs REST Endpoints Dec 27 17:40:08 volumio volumio[935]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Dec 27 17:40:08 volumio volumio[935]: info: Scanning Audio Inputs Dec 27 17:40:08 volumio volumio[935]: info: Checking against Known Cards name Dec 27 17:40:08 volumio volumio[935]: info: Checking against Known Cards name Dec 27 17:40:08 volumio volumio[935]: info: Checking against Known Cards name Dec 27 17:40:08 volumio volumio[935]: info: Adding Server instance for streaming Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Dec 27 17:40:08 volumio sudo[1903]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 17:40:08 volumio volumio[935]: error: Hi Res Audio Failed Login: Missing Login Data Dec 27 17:40:08 volumio sudo[1903]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:08 volumio volumio[935]: info: Adding HIGHRESAUDIO REST API Endpoints Dec 27 17:40:08 volumio volumio[935]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 27 17:40:08 volumio volumio[935]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Dec 27 17:40:08 volumio volumio[935]: info: Refreshing TIDAL token Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Dec 27 17:40:08 volumio volumio[935]: info: Refreshing QOBUZ token Dec 27 17:40:08 volumio sudo[1903]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:08 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Dec 27 17:40:09 volumio volumio[935]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Dec 27 17:40:09 volumio volumio[935]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Dec 27 17:40:09 volumio sudo[1914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 27 17:40:09 volumio sudo[1914]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: Starting Qobuz Connect socket and service Dec 27 17:40:09 volumio sudo[1914]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Dec 27 17:40:09 volumio sudo[1921]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 27 17:40:09 volumio sudo[1921]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[1921]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 27 17:40:09 volumio sudo[1923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 27 17:40:09 volumio sudo[1923]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio volumio[935]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Dec 27 17:40:09 volumio volumio[935]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'Volumio' Dec 27 17:40:09 volumio volumio[935]: Can't get device info: No such device Dec 27 17:40:09 volumio volumio[935]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Dec 27 17:40:09 volumio volumio[935]: info: MPD Permissions set Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: Starting Shairport Sync Dec 27 17:40:09 volumio systemd[1]: Started Volumio Qobuz Connect Service. Dec 27 17:40:09 volumio sudo[1923]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Preparing to generate the ALSA configuration file Dec 27 17:40:09 volumio sudo[1933]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 17:40:09 volumio sudo[1933]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio volumio[935]: info: Asound.conf file written Dec 27 17:40:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 17:40:09 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 17:40:09 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 17:40:09 volumio sudo[1933]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio sudo[1937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 27 17:40:09 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Output device has changed, restarting MPD Dec 27 17:40:09 volumio sudo[1945]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 17:40:09 volumio sudo[1945]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[1945]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Output device has changed, restarting Shairport Sync Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio sudo[1948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 17:40:09 volumio sudo[1948]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 27 17:40:09 volumio systemd[1]: mpd.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 17:40:09 volumio volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 17:40:09 volumio volumio[935]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: setDeactiveState invoked Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:09 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:09 volumio volumio[935]: info: Preparing to generate the ALSA configuration file Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 27 17:40:09 volumio volumio[935]: info: Reading ALSA contributions from plugins. Dec 27 17:40:09 volumio volumio[935]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Dec 27 17:40:09 volumio volumio[935]: info: MPD Permissions set Dec 27 17:40:09 volumio volumio[935]: info: Shairport-Sync Started Dec 27 17:40:09 volumio sudo[1960]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 27 17:40:09 volumio sudo[1960]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio systemd[1]: Starting Music Player Daemon... Dec 27 17:40:09 volumio sudo[1960]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio sudo[1962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 27 17:40:09 volumio sudo[1962]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio systemd[1]: Stopping Volumio Qobuz Connect Service... Dec 27 17:40:09 volumio systemd[1]: qobuz-connect.service: Main process exited, code=killed, status=2/INT Dec 27 17:40:09 volumio systemd[1]: qobuz-connect.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Volumio Qobuz Connect Service. Dec 27 17:40:09 volumio systemd[1]: Started Volumio Qobuz Connect Service. Dec 27 17:40:09 volumio sudo[1962]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Executing endpoint qc_getconfig Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 27 17:40:09 volumio sudo[1953]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 17:40:09 volumio sudo[1953]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[1953]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: Executing endpoint qc_getconfig Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.186 [1964.1964] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 27 17:40:09 volumio volumio[935]: info: Starting Shairport Sync Dec 27 17:40:09 volumio sudo[1979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 17:40:09 volumio sudo[1979]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio volumio[935]: info: Asound.conf file written Dec 27 17:40:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 17:40:09 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 17:40:09 volumio sudo[1982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 27 17:40:09 volumio sudo[1982]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.218 [1964.1964] INFO VolumeManager: [0x560cd4291760]: Setting new playback volume: 75 Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.218 [1964.1964] INFO VolumeManager: [0x560cd4291760]: Setting new mute state: 0 Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.218 [1964.1964] INFO QobuzConnect: [0x560cd4292980]: Client initialized! Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.218 [1964.1964] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.220 [1964.1964] INFO LocalConfigManager: [0x560cd4290a50]: Starting Local Configuration server Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.220 [1964.1964] INFO SampleApp: Starting Local configuration server Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.220 [1964.1964] INFO SampleApp: Connected to UNIX socket client 0x560cd4278280 Dec 27 17:40:09 volumio sudo[1982]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Output device has changed, restarting MPD Dec 27 17:40:09 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 17:40:09 volumio sudo[1979]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio sudo[1990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 17:40:09 volumio sudo[1990]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[1990]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Output device has changed, restarting Shairport Sync Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio sudo[1994]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 17:40:09 volumio sudo[1994]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Dec 27 17:40:09 volumio systemd[1]: mpd.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 17:40:09 volumio systemd[1]: Starting Music Player Daemon... Dec 27 17:40:09 volumio volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 17:40:09 volumio volumio[935]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: setDeactiveState invoked Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:09 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio sudo[1999]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 17:40:09 volumio sudo[1999]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[1999]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Access Token successfully retrieved Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 27 17:40:09 volumio volumio[935]: info: [1766853609270] CoreMusicLibrary::Adding element QOBUZ Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:40:09 volumio volumio[935]: Cannot find translation for source QOBUZ Dec 27 17:40:09 volumio sudo[2007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 27 17:40:09 volumio sudo[2007]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio volumio[935]: info: Stopping AccessToken refresher cron for QOBUZ Dec 27 17:40:09 volumio volumio[935]: info: AccessToken refresher cron started for QOBUZ Dec 27 17:40:09 volumio volumio[935]: info: Adding QOBUZ REST API Endpoints Dec 27 17:40:09 volumio volumio[935]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Dec 27 17:40:09 volumio volumio[935]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Dec 27 17:40:09 volumio volumio[935]: info: MPD Permissions set Dec 27 17:40:09 volumio volumio[935]: info: Shairport-Sync Started Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: Starting Shairport Sync Dec 27 17:40:09 volumio sudo[2007]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio sudo[2017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 17:40:09 volumio sudo[2017]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio sudo[2018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 27 17:40:09 volumio sudo[2018]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 17:40:09 volumio systemd[1]: Stopping Volumio Qobuz Connect Service... Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.311 [1964.1964] INFO SampleApp: Stopping Local configuration server Dec 27 17:40:09 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 17:40:09 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 17:40:09 volumio sudo[2017]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Shairport-Sync Started Dec 27 17:40:09 volumio qobuz-connect[1964]: 20251227 17:40:09.321 [1964.1964] INFO SampleApp: shat down connection on UNIX socket Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: setDeactiveState invoked Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:09 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:09 volumio systemd[1]: qobuz-connect.service: Succeeded. Dec 27 17:40:09 volumio systemd[1]: Stopped Volumio Qobuz Connect Service. Dec 27 17:40:09 volumio systemd[1]: Started Volumio Qobuz Connect Service. Dec 27 17:40:09 volumio sudo[2018]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Executing endpoint qc_getconfig Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.338 [2024.2024] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.340 [2024.2024] INFO VolumeManager: [0x559218263760]: Setting new playback volume: 75 Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.340 [2024.2024] INFO VolumeManager: [0x559218263760]: Setting new mute state: 0 Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.340 [2024.2024] INFO QobuzConnect: [0x559218264980]: Client initialized! Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.340 [2024.2024] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 27 17:40:09 volumio volumio[935]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.342 [2024.2024] INFO LocalConfigManager: [0x559218262a50]: Starting Local Configuration server Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.342 [2024.2024] INFO SampleApp: Starting Local configuration server Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.342 [2024.2024] INFO SampleApp: Connected to UNIX socket client 0x55921824a280 Dec 27 17:40:09 volumio volumio[935]: info: Successfully Added MyVolumio device Dec 27 17:40:09 volumio volumio[935]: info: Adding audio output: Dec 27 17:40:09 volumio mpd[2008]: Dec 27 17:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 27 17:40:09 volumio systemd[1]: Started Music Player Daemon. Dec 27 17:40:09 volumio sudo[1895]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio sudo[1994]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio sudo[1948]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:09 volumio volumio[935]: info: Adding audio output: Dec 27 17:40:09 volumio volumio[935]: error: MPD error: The expression evaluated to a falsy value: Dec 27 17:40:09 volumio volumio[935]: assert.ok(self.idling) Dec 27 17:40:09 volumio volumio[935]: error: The expression evaluated to a falsy value: Dec 27 17:40:09 volumio volumio[935]: assert.ok(self.idling) Dec 27 17:40:09 volumio volumio[935]: error: MPD error: The expression evaluated to a falsy value: Dec 27 17:40:09 volumio volumio[935]: assert.ok(self.idling) Dec 27 17:40:09 volumio volumio[935]: error: The expression evaluated to a falsy value: Dec 27 17:40:09 volumio volumio[935]: assert.ok(self.idling) Dec 27 17:40:09 volumio volumio[935]: info: Access Token successfully retrieved Dec 27 17:40:09 volumio volumio[935]: error: updateQueue error: null Dec 27 17:40:09 volumio qobuz-connect[2024]: 20251227 17:40:09.488 [2024.2024] INFO SampleApp: Playback volume changed: 75 Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:09 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:09 volumio volumio[935]: info: Successfully retrieved User Session From TIDAL Dec 27 17:40:09 volumio volumio[935]: info: Successfully Added MyVolumio device Dec 27 17:40:09 volumio volumio[935]: info: Successfully retrieved User Subscription From TIDAL Dec 27 17:40:09 volumio volumio[935]: info: Adding TIDAL to Browse Sources Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 27 17:40:09 volumio volumio[935]: info: [1766853609804] CoreMusicLibrary::Adding element TIDAL Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:40:09 volumio volumio[935]: Cannot find translation for source QOBUZ Dec 27 17:40:09 volumio volumio[935]: Cannot find translation for source TIDAL Dec 27 17:40:09 volumio volumio[935]: info: Adding TIDAL REST API Endpoints Dec 27 17:40:09 volumio volumio[935]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Dec 27 17:40:09 volumio volumio[935]: info: Updating MyVolumio device info Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: Updating MyVolumio device info Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:09 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:10 volumio volumio[935]: info: Successfully Updated MyVolumio device Dec 27 17:40:10 volumio volumio[935]: info: Getting Spotify volume Dec 27 17:40:10 volumio volumio[935]: info: Spotify volume: 100 Dec 27 17:40:10 volumio volumio[935]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 27 17:40:10 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:10 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:11 volumio ntpd[1688]: receive: Unexpected origin timestamp 0xecfa8a6a.b58a5975 does not match aorg 0000000000.00000000 from server@194.177.34.116 xmt 0xecfa8a6b.bef4ee19 Dec 27 17:40:11 volumio ntpd[1688]: receive: Unexpected origin timestamp 0xecfa8a6a.b588ba9a does not match aorg 0000000000.00000000 from server@79.143.250.33 xmt 0xecfa8a6b.bf95face Dec 27 17:40:11 volumio ntpd[1688]: receive: Unexpected origin timestamp 0xecfa8a6a.b5898aa7 does not match aorg 0000000000.00000000 from server@188.165.49.6 xmt 0xecfa8a6b.bf69d82c Dec 27 17:40:11 volumio ntpd[1688]: receive: Unexpected origin timestamp 0xecfa8a6a.b58aada5 does not match aorg 0000000000.00000000 from server@51.210.104.72 xmt 0xecfa8a6b.bf755abe Dec 27 17:40:11 volumio ntpd[1688]: receive: Unexpected origin timestamp 0xecfa8a6a.b58a23a3 does not match aorg 0000000000.00000000 from server@109.190.177.200 xmt 0xecfa8a6b.bfe047d8 Dec 27 17:40:11 volumio ntpd[1688]: receive: Unexpected origin timestamp 0xecfa8a6a.b589ca23 does not match aorg 0000000000.00000000 from server@82.67.62.62 xmt 0xecfa8a6b.c05882ac Dec 27 17:40:11 volumio volumio[935]: info: Successfully Updated MyVolumio device Dec 27 17:40:13 volumio sudo[2032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Dec 27 17:40:13 volumio sudo[2032]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:13 volumio systemd[1]: Started Volumio Bluetooth Module. Dec 27 17:40:13 volumio sudo[2032]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:13 volumio volumio[935]: info: Volumio BT Module successfully started Dec 27 17:40:13 volumio sudo[2035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Dec 27 17:40:13 volumio sudo[2035]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:13 volumio volumiobt[2034]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Dec 27 17:40:13 volumio sudo[2035]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:13 volumio volumio[935]: info: TidalConnect service stoped! Dec 27 17:40:13 volumio volumio[935]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 27 17:40:13 volumio volumio[935]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 27 17:40:13 volumio sudo[2047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 27 17:40:13 volumio sudo[2047]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:13 volumio systemd[1]: Started Volumio Tidal Connect Service. Dec 27 17:40:13 volumio sudo[2047]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:13 volumio volumio[935]: info: Executing endpoint tc_getconfig Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 27 17:40:13 volumio vtcs[2049]: STARTING TidalConnect services, version: 1.5.2.56 Dec 27 17:40:13 volumio vtcs[2049]: STARTED TidalConnect services. Dec 27 17:40:13 volumio volumio[935]: info: Executing endpoint tc_connect Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 27 17:40:13 volumio volumio[935]: info: Connecting to TidalConnect Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::servicePushState Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 27 17:40:13 volumio volumio[935]: verbose: CURRENT POSITION 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::syncState stateService stop Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: No code Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::servicePushState Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 27 17:40:13 volumio volumio[935]: verbose: CURRENT POSITION 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::syncState stateService stop Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: No code Dec 27 17:40:13 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:13 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:13 volumio sudo[2069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:40:13 volumio sudo[2069]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:13 volumio sudo[2072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:40:13 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 17:40:13 volumio sudo[2072]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:13 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 17:40:13 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 17:40:13 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 17:40:13 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:40:13 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:40:13 volumio sudo[2075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:40:13 volumio sudo[2075]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:13 volumio systemd[1]: Started MPD Monitor Service. Dec 27 17:40:13 volumio sudo[2069]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:13 volumio mpd_monitor.sh[2076]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 17:40:13 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:40:13 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:40:13 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 17:40:13 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 17:40:13 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:40:13 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 17:40:13 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 17:40:13 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:40:13 volumio systemd[1]: Started MPD Monitor Service. Dec 27 17:40:13 volumio sudo[2072]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:13 volumio sudo[2075]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:13 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:40:13 volumio mpd_monitor.sh[2080]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 17:40:13 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:40:14 volumio sudo[2084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Dec 27 17:40:14 volumio sudo[2084]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:14 volumio volumiobt[2034]: pulseaudio: no process found Dec 27 17:40:14 volumio sudo[2084]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:14 volumio dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.26' (uid=1000 pid=2088 comm="/usr/bin/pulseaudio --high-priority=true ") Dec 27 17:40:14 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Dec 27 17:40:14 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:40:14 volumio dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Dec 27 17:40:14 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Dec 27 17:40:14 volumio rtkit-daemon[2089]: Successfully called chroot. Dec 27 17:40:14 volumio rtkit-daemon[2089]: Successfully dropped privileges. Dec 27 17:40:14 volumio rtkit-daemon[2089]: Successfully limited resources. Dec 27 17:40:14 volumio rtkit-daemon[2089]: Running. Dec 27 17:40:14 volumio rtkit-daemon[2089]: Canary thread running. Dec 27 17:40:14 volumio rtkit-daemon[2089]: Watchdog thread running. Dec 27 17:40:14 volumio dbus-daemon[705]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.27' (uid=0 pid=2089 comm="/usr/lib/rtkit/rtkit-daemon ") Dec 27 17:40:14 volumio systemd[1]: Starting Authorization Manager... Dec 27 17:40:14 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:40:14 volumio polkitd[2092]: started daemon version 0.105 using authority implementation `local' version `0.105' Dec 27 17:40:14 volumio dbus-daemon[705]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Dec 27 17:40:14 volumio systemd[1]: Started Authorization Manager. Dec 27 17:40:14 volumio pulseaudio[2088]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Dec 27 17:40:14 volumio pulseaudio[2088]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Dec 27 17:40:14 volumio volumiobt[2034]: Applying permissions Dec 27 17:40:14 volumio volumiobt[2034]: Setting BT discoverable and pairable Dec 27 17:40:14 volumio pulseaudio[2088]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Dec 27 17:40:14 volumio volumiobt[2034]: [79B blob data] Dec 27 17:40:14 volumio volumiobt[2034]: Invalid command in menu main: -e Dec 27 17:40:14 volumio volumiobt[2034]: Dec 27 17:40:14 volumio volumiobt[2034]: Use "help" for a list of available commands in a menu. Dec 27 17:40:14 volumio volumiobt[2034]: Use "menu " if you want to enter any submenu. Dec 27 17:40:14 volumio volumiobt[2034]: Use "back" if you want to return to menu main. Dec 27 17:40:14 volumio volumiobt[2034]: [bluetoothctl]> agent on Dec 27 17:40:14 volumio volumiobt[2034]: Failed to register agent object Dec 27 17:40:14 volumio volumiobt[2034]: [bluetoothctl]> discoverable on Dec 27 17:40:14 volumio volumiobt[2034]: No default controller available Dec 27 17:40:14 volumio volumiobt[2034]: [bluetoothctl]> pairable on Dec 27 17:40:14 volumio volumiobt[2034]: No default controller available Dec 27 17:40:14 volumio volumiobt[2034]: [bluetoothctl]> agent NoInputNoOutput Dec 27 17:40:14 volumio volumiobt[2034]: Failed to register agent object Dec 27 17:40:14 volumio volumiobt[2034]: [bluetoothctl]> default-agent Dec 27 17:40:14 volumio volumiobt[2034]: No agent is registered Dec 27 17:40:14 volumio volumiobt[2034]: [bluetoothctl]> quit Dec 27 17:40:14 volumio volumiobt[2034]: [65B blob data] Dec 27 17:40:14 volumio sudo[2105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Dec 27 17:40:14 volumio sudo[2105]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:40:14 volumio systemd[1]: Started MyVolumio SSH Tunnel. Dec 27 17:40:14 volumio sudo[2105]: pam_unix(sudo:session): session closed for user root Dec 27 17:40:14 volumio volumio[935]: info: Remote SSH Started Dec 27 17:40:14 volumio autossh[2108]: port set to 0, monitoring disabled Dec 27 17:40:14 volumio autossh[2108]: starting ssh (count 1) Dec 27 17:40:14 volumio autossh[2108]: ssh child pid is 2111 Dec 27 17:40:14 volumio volumio[935]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 27 17:40:14 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:14 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:14 volumio volumiossh-tunnel[2107]: Warning: Permanently added '[eu6.myvolumio.org]:2222,[207.154.233.230]:2222' (RSA) to the list of known hosts. Dec 27 17:40:14 volumio volumio[935]: info: MRS: Getting audio outputs on start Dec 27 17:40:14 volumio volumio[935]: info: MRS: Requesting all other devices output Dec 27 17:40:16 volumio volumio[935]: info: TidalConnect service started! Dec 27 17:40:16 volumio volumio[935]: [Metrics] CommandRouter: 19s 324.30ms Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::volumiosetStartupVolume Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:16 volumio volumio[935]: info: VolumeController:: Setting startup Volume 80 Dec 27 17:40:16 volumio volumio[935]: info: VolumeController::SetAlsaVolume80 Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::Close All Modals sent Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::Close All Modals sent Dec 27 17:40:16 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:40:16 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:40:16 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:40:16 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:40:16 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:16 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:16 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:40:16 volumio volumio[935]: SPOTIFY: SPOTIFY VOLUME 100 Dec 27 17:40:16 volumio volumio[935]: SPOTIFY: VOLUMIO VOLUME 80 Dec 27 17:40:16 volumio volumio[935]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 27 17:40:16 volumio volumio[935]: info: Setting Spotify Volume from Volumio: 80 Dec 27 17:40:16 volumio volumio[935]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Dec 27 17:40:16 volumio volumio[935]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Dec 27 17:40:16 volumio volumio[935]: No protocol specified Dec 27 17:40:16 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:40:16 volumio volumio[935]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Dec 27 17:40:16 volumio volumio[935]: ALSA lib /home/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Dec 27 17:40:16 volumio volumio[935]: aplay: main:828: audio open error: No such device Dec 27 17:40:17 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 27 17:40:17 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 27 17:40:17 volumio volumio[935]: No protocol specified Dec 27 17:40:17 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:40:17 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Dec 27 17:40:17 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 27 17:40:17 volumio volumio[935]: SPOTIFY: SETTING SPOTIFY VOLUME 80 Dec 27 17:40:17 volumio volumio[935]: info: Sending Spotify command with payload to local API: /player/volume Dec 27 17:40:17 volumio go-librespot[1711]: time="2025-12-27T17:40:17+01:00" level=debug msg="update volume requested to 52428/65535" Dec 27 17:40:17 volumio go-librespot[1711]: time="2025-12-27T17:40:17+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 27 17:40:17 volumio go-librespot[1711]: time="2025-12-27T17:40:17+01:00" level=trace msg="emitting websocket event: volume" Dec 27 17:40:17 volumio volumio[935]: SPOTIFY: received: {"type":"volume","data":{"value":80,"max":100}} Dec 27 17:40:17 volumio volumio[935]: SPOTIFY: RECEIVED SPOTIFY VOLUME 80 Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 27 17:40:18 volumio volumio[935]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 27 17:40:18 volumio volumio[935]: info: Received Get System Version Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 27 17:40:18 volumio volumio[935]: info: Received Get System Info Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:40:18 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:18 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:18 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:40:22 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 27 17:40:22 volumio volumio[935]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 27 17:40:22 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:40:22 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:40:23 volumio volumio[935]: info: BOOT COMPLETED Dec 27 17:40:25 volumio systemd[1]: systemd-fsckd.service: Succeeded. Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 17:40:27 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 27 17:40:28 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 27 17:40:28 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:40:28 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 27 17:40:28 volumio volumio-remote-updater[693]: No test mode Dec 27 17:40:28 volumio volumio-remote-updater[693]: No alpha test mode Dec 27 17:40:28 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 27 17:40:29 volumio volumio[935]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 27 17:40:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 27 17:40:36 volumio systemd[1]: systemd-timedated.service: Succeeded. Dec 27 17:40:37 volumio go-librespot[1711]: time="2025-12-27T17:40:37+01:00" level=trace msg="sent dealer ping" Dec 27 17:40:37 volumio go-librespot[1711]: time="2025-12-27T17:40:37+01:00" level=trace msg="received dealer pong" Dec 27 17:41:07 volumio go-librespot[1711]: time="2025-12-27T17:41:07+01:00" level=trace msg="sent dealer ping" Dec 27 17:41:07 volumio go-librespot[1711]: time="2025-12-27T17:41:07+01:00" level=trace msg="received dealer pong" Dec 27 17:41:13 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16:3000 from 192.168.1.22 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:13 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:13 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16:3000 from 192.168.1.22 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:13 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:13 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:13 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 27 17:41:13 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 27 17:41:13 volumio sudo[2263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 27 17:41:13 volumio sudo[2263]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:13 volumio sudo[2269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 27 17:41:13 volumio sudo[2263]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:13 volumio sudo[2269]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:13 volumio sudo[2278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 27 17:41:13 volumio sudo[2278]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:13 volumio sudo[2269]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:13 volumio sudo[2285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 27 17:41:13 volumio sudo[2285]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:13 volumio sudo[2278]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:13 volumio sudo[2298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 27 17:41:13 volumio sudo[2298]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:13 volumio sudo[2298]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:13 volumio sudo[2285]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:13 volumio sudo[2304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 27 17:41:13 volumio sudo[2304]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:13 volumio sudo[2304]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:14 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:14 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:14 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:14 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:14 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:14 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16:3000 from 192.168.1.22 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:14 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:14 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:14 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16:3000 from 192.168.1.22 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 27 17:41:14 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 27 17:41:20 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 27 17:41:20 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 27 17:41:22 volumio sudo[2323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 27 17:41:22 volumio sudo[2323]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:22 volumio sudo[2323]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:22 volumio sudo[2326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 27 17:41:22 volumio sudo[2326]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:22 volumio sudo[2326]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:22 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.22 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 27 17:41:22 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 27 17:41:22 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 27 17:41:22 volumio sudo[2331]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 27 17:41:22 volumio sudo[2331]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:22 volumio sudo[2331]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:22 volumio sudo[2334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 27 17:41:22 volumio sudo[2334]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:22 volumio sudo[2334]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:22 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.22 UA: Mozilla/5.0 (Linux; Android 10; CLT-L29 Build/HUAWEICLT-L29; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 27 17:41:22 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::volumioGetVisibleSources Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:23 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 27 17:41:23 volumio volumio[935]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 27 17:41:23 volumio volumio[935]: info: Received Get System Info Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:23 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:23 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:23 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:23 volumio volumio[935]: info: Listing playlists Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 27 17:41:23 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 27 17:41:24 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 17:41:24 volumio volumio[935]: info: Received Get System Info Dec 27 17:41:24 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:24 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:24 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:24 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:24 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:24 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:24 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 27 17:41:26 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 17:41:26 volumio volumio[935]: info: Received Get System Info Dec 27 17:41:26 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:26 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:26 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:26 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:26 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:26 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:29 volumio volumio[935]: No protocol specified Dec 27 17:41:29 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 27 17:41:29 volumio volumio[935]: Invalid card number. Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 27 17:41:29 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:32 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:32 volumio volumio[935]: verbose: New Socket.io Connection to 192.168.1.16:3000 from 192.168.1.22 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 27 17:41:32 volumio volumio[935]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 27 17:41:32 volumio volumio[935]: info: Preparing to save Alsa Options, stopping services first Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioPause Dec 27 17:41:32 volumio volumio[935]: info: CoreStateMachine::pause Dec 27 17:41:32 volumio volumio[935]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Expert Pro USB Audio 2.0"}} Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: warn: Unable to locate the device Expert Pro USB Audio 2.0 a reboot may be required. Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 27 17:41:32 volumio volumio[935]: Invalid card number. Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 27 17:41:32 volumio volumio[935]: info: Updating Volume Controller Parameters: Device: 5 Name: Expert Pro USB Audio 2.0 Mixer: Max Vol: 80 Vol Curve; logarithmic Vol Steps: 1 Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 27 17:41:32 volumio volumio[935]: info: Disabling external Volume Control Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:32 volumio volumio[935]: info: Preparing to generate the ALSA configuration file Dec 27 17:41:32 volumio volumio[935]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 27 17:41:32 volumio volumio[935]: info: Reading ALSA contributions from plugins. Dec 27 17:41:32 volumio volumio[935]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 27 17:41:32 volumio volumio[935]: Invalid card number. Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 27 17:41:32 volumio volumio[935]: info: VolumeController:: Volume=undefined Mute =false Dec 27 17:41:32 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:32 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:32 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:32 volumio volumio[935]: info: Asound.conf file written Dec 27 17:41:32 volumio sudo[2371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 27 17:41:32 volumio sudo[2371]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2371]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: Output device has changed, restarting MPD Dec 27 17:41:32 volumio sudo[2377]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 17:41:32 volumio sudo[2377]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2377]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio volumio[935]: info: Output device has changed, restarting Shairport Sync Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:32 volumio sudo[2380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 17:41:32 volumio sudo[2380]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio systemd[1]: Stopping Music Player Daemon... Dec 27 17:41:32 volumio systemd[1]: mpd.service: Succeeded. Dec 27 17:41:32 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: QobuzConnect: setDeactiveState invoked Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio vtcs[2049]: [2025-12-27 17:41:32.879] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 27 17:41:32 volumio vtcs[2049]: [2025-12-27 17:41:32.879] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 27 17:41:32 volumio systemd[1]: Starting Music Player Daemon... Dec 27 17:41:32 volumio sudo[2389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 27 17:41:32 volumio volumio[935]: info: Output device has changed, restarting MPD Dec 27 17:41:32 volumio sudo[2389]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio systemd[1]: Stopping Volumio Tidal Connect Service... Dec 27 17:41:32 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Dec 27 17:41:32 volumio systemd[1]: vtcs.service: Succeeded. Dec 27 17:41:32 volumio systemd[1]: Stopped Volumio Tidal Connect Service. Dec 27 17:41:32 volumio volumio[935]: info: Output device has changed, restarting Shairport Sync Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:32 volumio sudo[2392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 17:41:32 volumio sudo[2392]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2392]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio sudo[2389]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio sudo[2395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 17:41:32 volumio sudo[2395]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Dec 27 17:41:32 volumio systemd[1]: mpd.service: Succeeded. Dec 27 17:41:32 volumio systemd[1]: Stopped Music Player Daemon. Dec 27 17:41:32 volumio systemd[1]: Starting Music Player Daemon... Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 17:41:32 volumio volumio[935]: No protocol specified Dec 27 17:41:32 volumio volumio[935]: xcb_connection_has_error() returned true Dec 27 17:41:32 volumio volumio[935]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: QobuzConnect: setDeactiveState invoked Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio sudo[2405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 27 17:41:32 volumio sudo[2405]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2401]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 17:41:32 volumio sudo[2401]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2401]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio sudo[2409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 27 17:41:32 volumio sudo[2409]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 27 17:41:32 volumio sudo[2413]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio sudo[2409]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio sudo[2405]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:32 volumio sudo[2413]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio sudo[2422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 27 17:41:32 volumio sudo[2422]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:32 volumio sudo[2422]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio sudo[2427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 27 17:41:32 volumio sudo[2427]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:32 volumio sudo[2429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 27 17:41:32 volumio sudo[2429]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:32 volumio systemd[1]: Stopping Volumio Qobuz Connect Service... Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:32 volumio qobuz-connect[2024]: 20251227 17:41:32.972 [2024.2024] INFO SampleApp: Stopping Local configuration server Dec 27 17:41:32 volumio sudo[2429]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:32 volumio sudo[2432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 27 17:41:32 volumio sudo[2432]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:32 volumio qobuz-connect[2024]: 20251227 17:41:32.982 [2024.2024] INFO SampleApp: shat down connection on UNIX socket Dec 27 17:41:32 volumio volumio[935]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Dec 27 17:41:32 volumio volumio[935]: info: MPD Permissions set Dec 27 17:41:32 volumio volumio[935]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Dec 27 17:41:32 volumio volumio[935]: info: MPD Permissions set Dec 27 17:41:32 volumio systemd[1]: qobuz-connect.service: Succeeded. Dec 27 17:41:32 volumio systemd[1]: Stopped Volumio Qobuz Connect Service. Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:32 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:32 volumio volumio[935]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 27 17:41:32 volumio volumio[935]: info: QobuzConnect: setDeactiveState invoked Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:32 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:32 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 27 17:41:33 volumio systemd[1]: Started Volumio Qobuz Connect Service. Dec 27 17:41:33 volumio sudo[2427]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:33 volumio sudo[2432]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 17:41:33 volumio volumio[935]: info: Executing endpoint qc_getconfig Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.029 [2434.2434] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 27 17:41:33 volumio volumio[935]: info: Starting Shairport Sync Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.030 [2434.2434] INFO VolumeManager: [0x558644190760]: Setting new playback volume: 75 Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.030 [2434.2434] INFO VolumeManager: [0x558644190760]: Setting new mute state: 0 Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.030 [2434.2434] INFO QobuzConnect: [0x558644191980]: Client initialized! Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.030 [2434.2434] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.032 [2434.2434] INFO LocalConfigManager: [0x55864418fa50]: Starting Local Configuration server Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.032 [2434.2434] INFO SampleApp: Starting Local configuration server Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.032 [2434.2434] INFO SampleApp: Connected to UNIX socket client 0x558644177280 Dec 27 17:41:33 volumio volumio[935]: info: Starting Shairport Sync Dec 27 17:41:33 volumio sudo[2452]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 17:41:33 volumio sudo[2452]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:33 volumio volumio[935]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 27 17:41:33 volumio volumio[935]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 27 17:41:33 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 17:41:33 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 17:41:33 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 17:41:33 volumio sudo[2455]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 27 17:41:33 volumio sudo[2455]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:33 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:33 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:33 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 17:41:33 volumio sudo[2452]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:33 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Dec 27 17:41:33 volumio volumio[935]: info: Shairport-Sync Started Dec 27 17:41:33 volumio systemd[1]: shairport-sync.service: Succeeded. Dec 27 17:41:33 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Dec 27 17:41:33 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:33 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:33 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Dec 27 17:41:33 volumio sudo[2455]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:33 volumio volumio[935]: info: Shairport-Sync Started Dec 27 17:41:33 volumio mpd[2410]: Dec 27 17:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 27 17:41:33 volumio systemd[1]: Started Music Player Daemon. Dec 27 17:41:33 volumio sudo[2380]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:33 volumio sudo[2395]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:33 volumio volumio[935]: error: MPD error: The expression evaluated to a falsy value: Dec 27 17:41:33 volumio volumio[935]: assert.ok(self.idling) Dec 27 17:41:33 volumio volumio[935]: error: The expression evaluated to a falsy value: Dec 27 17:41:33 volumio volumio[935]: assert.ok(self.idling) Dec 27 17:41:33 volumio volumio[935]: error: updateQueue error: null Dec 27 17:41:33 volumio qobuz-connect[2434]: 20251227 17:41:33.178 [2434.2434] INFO SampleApp: Playback volume changed: 75 Dec 27 17:41:33 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:33 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:35 volumio volumio[935]: info: TidalConnect service stoped! Dec 27 17:41:35 volumio volumio[935]: info: TidalConnect service stoped! Dec 27 17:41:35 volumio volumio[935]: info: TidalConnect service stoped! Dec 27 17:41:35 volumio volumio[935]: info: TidalConnect service stoped! Dec 27 17:41:35 volumio volumio[935]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 27 17:41:35 volumio volumio[935]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 27 17:41:35 volumio volumio[935]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 27 17:41:35 volumio volumio[935]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 27 17:41:35 volumio sudo[2485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 27 17:41:35 volumio sudo[2485]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:35 volumio sudo[2488]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 27 17:41:35 volumio sudo[2488]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:36 volumio systemd[1]: Started Volumio Tidal Connect Service. Dec 27 17:41:36 volumio sudo[2485]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:36 volumio sudo[2488]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:36 volumio volumio[935]: info: Executing endpoint tc_getconfig Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 27 17:41:36 volumio vtcs[2489]: STARTING TidalConnect services, version: 1.5.2.56 Dec 27 17:41:36 volumio vtcs[2489]: STARTED TidalConnect services. Dec 27 17:41:36 volumio volumio[935]: info: Executing endpoint tc_connect Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 27 17:41:36 volumio volumio[935]: info: Connecting to TidalConnect Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::servicePushState Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 27 17:41:36 volumio volumio[935]: verbose: CURRENT POSITION 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::syncState stateService stop Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: No code Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::servicePushState Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Dec 27 17:41:36 volumio volumio[935]: verbose: CURRENT POSITION 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::syncState stateService stop Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: No code Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio sudo[2511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:41:36 volumio sudo[2511]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:36 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 17:41:36 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 17:41:36 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 17:41:36 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 17:41:36 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:36 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:36 volumio sudo[2514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 27 17:41:36 volumio sudo[2514]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:36 volumio systemd[1]: Started MPD Monitor Service. Dec 27 17:41:36 volumio sudo[2511]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:36 volumio mpd_monitor.sh[2515]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 17:41:36 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:41:36 volumio systemd[1]: Stopping MPD Monitor Service... Dec 27 17:41:36 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Dec 27 17:41:36 volumio systemd[1]: mpd_monitor.service: Succeeded. Dec 27 17:41:36 volumio systemd[1]: Stopped MPD Monitor Service. Dec 27 17:41:36 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:36 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Dec 27 17:41:36 volumio systemd[1]: Started MPD Monitor Service. Dec 27 17:41:36 volumio sudo[2514]: pam_unix(sudo:session): session closed for user root Dec 27 17:41:36 volumio volumio[935]: info: Successfully started MPD Monitor Dec 27 17:41:36 volumio mpd_monitor.sh[2518]: MPD Monitor Service: Starting MPD Monitor Service Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::getcurrentVolume Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 17:41:36 volumio volumio[935]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Dec 27 17:41:36 volumio volumio[935]: info: VolumeController:: Volume=undefined Mute =false Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::updateTrackBlock Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrackBlock Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:36 volumio volumio[935]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Dec 27 17:41:36 volumio volumio[935]: info: VolumeController:: Volume=undefined Mute =false Dec 27 17:41:36 volumio volumio[935]: info: CoreStateMachine::pushState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioPushState Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:41:36 volumio volumio[935]: info: MRS: Pushing multiroomSync output Dec 27 17:41:36 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:36 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:36 volumio volumio[935]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Dec 27 17:41:37 volumio go-librespot[1711]: time="2025-12-27T17:41:37+01:00" level=trace msg="sent dealer ping" Dec 27 17:41:37 volumio go-librespot[1711]: time="2025-12-27T17:41:37+01:00" level=trace msg="received dealer pong" Dec 27 17:41:39 volumio volumio[935]: info: TidalConnect service started! Dec 27 17:41:39 volumio volumio[935]: info: TidalConnect service started! Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 27 17:41:40 volumio volumio[935]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 27 17:41:40 volumio volumio[935]: info: Received Get System Version Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 27 17:41:40 volumio volumio[935]: info: Received Get System Info Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:41:40 volumio volumio[935]: info: Discovery: Getting this device information Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::volumioGetState Dec 27 17:41:40 volumio volumio[935]: info: CorePlayQueue::getTrack 0 Dec 27 17:41:40 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:44 volumio volumio[935]: info: Retrieving Cloud Streaming UI Dec 27 17:41:44 volumio volumio[935]: info: Getting Tidal Cloud Configuration Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:44 volumio volumio[935]: info: Getting Qobuz Cloud Configuration Dec 27 17:41:44 volumio volumio[935]: info: Asking plugin for UI Config Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:44 volumio volumio[935]: info: Getting Spotify Cloud Configuration Dec 27 17:41:44 volumio volumio[935]: info: Asking plugin for UI Config Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:44 volumio volumio[935]: info: Saving Spotify Acccount Dec 27 17:41:44 volumio volumio[935]: info: Got it Dec 27 17:41:44 volumio volumio[935]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 27 17:41:44 volumio volumio[935]: info: Got Tidal Cloud Configuration Dec 27 17:41:44 volumio volumio[935]: info: Got it Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::volumioGetBrowseSources Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 27 17:41:44 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 27 17:41:48 volumio volumio[935]: info: Disabling MyMusic plugin upnp Dec 27 17:41:48 volumio sudo[2555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Dec 27 17:41:48 volumio sudo[2555]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 17:41:48 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Dec 27 17:41:48 volumio volumio[935]: error: Upnp client error: Error: This socket has been ended by the other party Dec 27 17:41:48 volumio volumio[935]: ------------------------------------ BT MESSAGE: BT STATUS: running Dec 27 17:41:48 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 27 17:41:49 volumio volumio[935]: info: Enabling MyMusic plugin upnp Dec 27 17:41:49 volumio volumio[935]: info: Enabling plugin upnp Dec 27 17:41:49 volumio volumio[935]: info: Loading plugin "upnp"... Dec 27 17:41:49 volumio volumio[935]: info: [1766853709642] Starting Upmpd Daemon Dec 27 17:41:49 volumio volumio[935]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 27 17:41:49 volumio volumio[935]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 17:41:49 volumio volumio[935]: Error: listen EADDRINUSE: address already in use :::6599 Dec 27 17:41:49 volumio volumio[935]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Dec 27 17:41:49 volumio volumio[935]: at listenInCluster (net.js:1379:12) Dec 27 17:41:49 volumio volumio[935]: at Server.listen (net.js:1465:7) Dec 27 17:41:49 volumio volumio[935]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Dec 27 17:41:49 volumio volumio[935]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Dec 27 17:41:49 volumio volumio[935]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Dec 27 17:41:49 volumio volumio[935]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 27 17:41:49 volumio volumio[935]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Dec 27 17:41:49 volumio volumio[935]: code: 'EADDRINUSE', Dec 27 17:41:49 volumio volumio[935]: errno: -98, Dec 27 17:41:49 volumio volumio[935]: syscall: 'listen', Dec 27 17:41:49 volumio volumio[935]: address: '::', Dec 27 17:41:49 volumio volumio[935]: port: 6599 Dec 27 17:41:49 volumio volumio[935]: } Dec 27 17:41:49 volumio volumio[935]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 17:41:49 volumio sudo[2566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-27 17:40 Dec 27 17:41:49 volumio sudo[2566]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:18:30 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="33f9369b544b4488ff4979d2ee3813a5"