Dec 22 18:28:01 volumio-erg volumiossh-tunnel[20354]: Connection to eu10.myvolumio.org closed by remote host. Dec 22 18:28:01 volumio-erg autossh[20351]: ssh exited prematurely with status 255; autossh exiting Dec 22 18:28:01 volumio-erg systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Dec 22 18:28:01 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:01 volumio-erg systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 1. Dec 22 18:28:01 volumio-erg systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:01 volumio-erg systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:01 volumio-erg autossh[20390]: port set to 0, monitoring disabled Dec 22 18:28:01 volumio-erg autossh[20390]: starting ssh (count 1) Dec 22 18:28:01 volumio-erg autossh[20390]: ssh child pid is 20393 Dec 22 18:28:02 volumio-erg volumiossh-tunnel[20393]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 22 18:28:02 volumio-erg autossh[20390]: ssh exited prematurely with status 255; autossh exiting Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 2. Dec 22 18:28:02 volumio-erg systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:02 volumio-erg systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:02 volumio-erg autossh[20395]: port set to 0, monitoring disabled Dec 22 18:28:02 volumio-erg autossh[20395]: starting ssh (count 1) Dec 22 18:28:02 volumio-erg autossh[20395]: ssh child pid is 20398 Dec 22 18:28:02 volumio-erg volumiossh-tunnel[20398]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 22 18:28:02 volumio-erg autossh[20395]: ssh exited prematurely with status 255; autossh exiting Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 3. Dec 22 18:28:02 volumio-erg systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:02 volumio-erg systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:02 volumio-erg autossh[20400]: port set to 0, monitoring disabled Dec 22 18:28:02 volumio-erg autossh[20400]: starting ssh (count 1) Dec 22 18:28:02 volumio-erg autossh[20400]: ssh child pid is 20403 Dec 22 18:28:02 volumio-erg volumiossh-tunnel[20403]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 22 18:28:02 volumio-erg autossh[20400]: ssh exited prematurely with status 255; autossh exiting Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Dec 22 18:28:02 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 4. Dec 22 18:28:03 volumio-erg systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:03 volumio-erg systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:03 volumio-erg autossh[20405]: port set to 0, monitoring disabled Dec 22 18:28:03 volumio-erg autossh[20405]: starting ssh (count 1) Dec 22 18:28:03 volumio-erg autossh[20405]: ssh child pid is 20408 Dec 22 18:28:03 volumio-erg volumiossh-tunnel[20408]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 22 18:28:03 volumio-erg autossh[20405]: ssh exited prematurely with status 255; autossh exiting Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 5. Dec 22 18:28:03 volumio-erg systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:03 volumio-erg systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:03 volumio-erg autossh[20410]: port set to 0, monitoring disabled Dec 22 18:28:03 volumio-erg autossh[20410]: starting ssh (count 1) Dec 22 18:28:03 volumio-erg autossh[20410]: ssh child pid is 20413 Dec 22 18:28:03 volumio-erg volumiossh-tunnel[20413]: ssh: connect to host eu10.myvolumio.org port 2222: Connection refused Dec 22 18:28:03 volumio-erg autossh[20410]: ssh exited prematurely with status 255; autossh exiting Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Main process exited, code=exited, status=1/FAILURE Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Scheduled restart job, restart counter is at 6. Dec 22 18:28:03 volumio-erg systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Start request repeated too quickly. Dec 22 18:28:03 volumio-erg systemd[1]: sshtunnel.service: Failed with result 'exit-code'. Dec 22 18:28:03 volumio-erg systemd[1]: Failed to start sshtunnel.service - MyVolumio SSH Tunnel. Dec 22 18:28:11 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:11+02:00" level=trace msg="received accesspoint ping" Dec 22 18:28:11 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:11+02:00" level=trace msg="received accesspoint pong ack" Dec 22 18:28:12 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:12+02:00" level=trace msg="sent dealer ping" Dec 22 18:28:12 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:12+02:00" level=trace msg="received dealer pong" Dec 22 18:28:12 volumio-erg volumio[7693]: verbose: New Socket.io Connection to 192.168.1.3:3000 from 192.168.1.5 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Dec 22 18:28:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 22 18:28:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 22 18:28:12 volumio-erg volumio[7693]: info: Discovery: Getting this device information Dec 22 18:28:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:12 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 1 Dec 22 18:28:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 22 18:28:13 volumio-erg volumio[7693]: verbose: New Socket.io Connection to 192.168.1.3 from 192.168.1.5 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetVisibleSources Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 1 Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetQueue Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreStateMachine::getQueue Dec 22 18:28:13 volumio-erg volumio[7693]: info: CorePlayQueue::getQueue Dec 22 18:28:13 volumio-erg volumio[7693]: info: Listing playlists Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 22 18:28:13 volumio-erg volumio[7693]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 22 18:28:13 volumio-erg volumio[7693]: info: Received Get System Info Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 22 18:28:13 volumio-erg volumio[7693]: info: Discovery: Getting this device information Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 1 Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 1 Dec 22 18:28:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 22 18:28:16 volumio-erg volumio[7693]: info: Executing endpoint metavolumio Dec 22 18:28:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 18:28:16 volumio-erg volumio[7693]: info: Executing endpoint metavolumio Dec 22 18:28:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 22 18:28:21 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 22 18:28:21 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 22 18:28:24 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 1 Dec 22 18:28:24 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:24 volumio-erg volumio[7693]: info: Prefetching next song Dec 22 18:28:24 volumio-erg volumio[7693]: info: [1766420904535] ControllerSpotify::prefetch Dec 22 18:28:24 volumio-erg volumio[7693]: info: Sending Spotify command with payload to local API: /player/add_to_queue Dec 22 18:28:24 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 22 18:28:24 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:24+02:00" level=debug msg="prefetching next track" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:24 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:24+02:00" level=debug msg="selected format OGG_VORBIS_320 (4d55330e27cf2670cfa5402eedd07021b0ccada5)" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:24 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:24+02:00" level=debug msg="requested aes key for file 4d55330e27cf2670cfa5402eedd07021b0ccada5, gid: 6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:24 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:24+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:25 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:25+02:00" level=debug msg="fetched first chunk of 30, total size is 15563021 bytes" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:25 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:25+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Dec 22 18:28:25 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:25+02:00" level=info msg="prefetched track \"Young Bean - 2025 Remaster\" (duration: 366148ms)" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:25 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:25+02:00" level=debug msg="fetched chunk 2/29, size: 524288" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:25 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:25+02:00" level=debug msg="fetched chunk 1/29, size: 524288" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:25 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:25+02:00" level=debug msg="fetched chunk 3/29, size: 524288" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:28 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:28+02:00" level=trace msg="emitting websocket event: not_playing" Dec 22 18:28:28 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:28+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:28 volumio-erg volumio[7693]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:1UUnlHidGvazCoHVwFfdzQ","uri":"spotify:track:1UUnlHidGvazCoHVwFfdzQ","play_origin":"go-librespot"}} Dec 22 18:28:28 volumio-erg volumio[7693]: error: Failed to decode event: not_playing Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=trace msg="emitting websocket event: will_play" Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=info msg="loaded track \"Young Bean - 2025 Remaster\" (paused: false, position: 0ms, duration: 366148ms, prefetched: true)" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1UUnlHidGvazCoHVwFfdzQ","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","play_origin":"go-librespot"}} Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::startPlaybackTimer Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=trace msg="scheduling prefetch in 336s" Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=trace msg="emitting websocket event: metadata" Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","name":"Young Bean - 2025 Remaster","artist_names":["Ben Webster"],"album_name":"Ben Webster And Associates (2025 Remaster)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","position":0,"duration":366148,"release_date":"year:1959 month:11 day:1","track_number":3,"disc_number":1}} Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 22 18:28:29 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:29+02:00" level=trace msg="emitting websocket event: playing" Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1UUnlHidGvazCoHVwFfdzQ","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","resume":false,"play_origin":"go-librespot"}} Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: PUSH STATE SPOTIFY Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: {"status":"play","service":"spop","title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","seek":0,"duration":366,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","seek":0,"duration":366,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 22 18:28:29 volumio-erg volumio[7693]: verbose: CURRENT POSITION 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::syncState stateService play Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::syncState currentStatus play Dec 22 18:28:29 volumio-erg volumio[7693]: info: Received an update from plugin. extracting info from payload Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: PUSH STATE SPOTIFY Dec 22 18:28:29 volumio-erg volumio[7693]: SPOTIFY: {"status":"play","service":"spop","title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","seek":1000,"duration":366,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","seek":1000,"duration":366,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 22 18:28:29 volumio-erg volumio[7693]: verbose: CURRENT POSITION 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::syncState stateService play Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::syncState currentStatus play Dec 22 18:28:29 volumio-erg volumio[7693]: info: Received an update from plugin. extracting info from payload Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:29 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:29 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:29 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 22 18:28:32 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 22 18:28:41 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:41+02:00" level=debug msg="fetched chunk 4/29, size: 524288" uri="spotify:track:6ZIH1LwKuPhKW0iLRXXNNu" Dec 22 18:28:42 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:42+02:00" level=trace msg="sent dealer ping" Dec 22 18:28:42 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:42+02:00" level=trace msg="received dealer pong" Dec 22 18:28:43 volumio-erg volumio[7693]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 22 18:28:43 volumio-erg volumio[7693]: info: Preparing to save Alsa Options, stopping services first Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPause Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::pause Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::stPlaybackTimer Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::servicePause Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePause Dec 22 18:28:43 volumio-erg volumio[7693]: info: Spotify Received pause Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: SPOTIFY PAUSE Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: {"status":"play","position":2,"title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d0000b2736fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","codec":"ogg","seek":1000,"duration":366,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Dec 22 18:28:43 volumio-erg volumio[7693]: info: Sending Spotify command to local API: /player/pause Dec 22 18:28:43 volumio-erg volumio[7693]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI Out"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:28:43 volumio-erg volumio[7693]: info: Enabling PI HDMI Output Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:28:43 volumio-erg volumio[7693]: info: Found match in Cards Database: setting mixer PCM for card HDMI Out Dec 22 18:28:43 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg sudo[20504]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:28:43 volumio-erg sudo[20504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:43 volumio-erg vtcs[8482]: [2025-12-22 18:28:43.287] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 22 18:28:43 volumio-erg vtcs[8482]: [2025-12-22 18:28:43.350] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 22 18:28:43 volumio-erg volumio[7693]: info: Updating Volume Controller Parameters: Device: 0 Name: HDMI Out Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 22 18:28:43 volumio-erg systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 22 18:28:43 volumio-erg volumio[7693]: info: Disabling external Volume Control Dec 22 18:28:43 volumio-erg systemd[1]: vtcs.service: Deactivated successfully. Dec 22 18:28:43 volumio-erg systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 22 18:28:43 volumio-erg systemd[1]: vtcs.service: Consumed 3.119s CPU time. Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 22 18:28:43 volumio-erg volumio[7693]: info: Preparing to generate the ALSA configuration file Dec 22 18:28:43 volumio-erg sudo[20504]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:43 volumio-erg sudo[20513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:28:43 volumio-erg sudo[20513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:43 volumio-erg volumio[7693]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 22 18:28:43 volumio-erg volumio[7693]: info: Reading ALSA contributions from plugins. Dec 22 18:28:43 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:43+02:00" level=debug msg="pause track at 14397ms" Dec 22 18:28:43 volumio-erg sudo[20521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:28:43 volumio-erg sudo[20521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:43 volumio-erg volumio[7693]: info: Raspberry PI HDMI Output Enabled Dec 22 18:28:43 volumio-erg sudo[20513]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:43 volumio-erg sudo[20521]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:43 volumio-erg sudo[20525]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl store Dec 22 18:28:43 volumio-erg sudo[20525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:43 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:43+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 22 18:28:43 volumio-erg sudo[20528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:28:43 volumio-erg sudo[20528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:28:43 volumio-erg systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 18:28:43 volumio-erg sudo[20525]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 22 18:28:43 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:43+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Dec 22 18:28:43 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:43+02:00" level=trace msg="emitting websocket event: paused" Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 22 18:28:43 volumio-erg volumio[7693]: info: VolumeController:: Volume=86 Mute =false Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:43 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:43 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:1UUnlHidGvazCoHVwFfdzQ","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","play_origin":"go-librespot"}} Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: PUSH STATE SPOTIFY Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: {"status":"pause","service":"spop","title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","seek":15000,"duration":366,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Young Bean - 2025 Remaster","artist":"Ben Webster","album":"Ben Webster And Associates (2025 Remaster)","albumart":"https://i.scdn.co/image/ab67616d00001e026fa7b26fa2868c99669a8dd4","uri":"spotify:track:6ZIH1LwKuPhKW0iLRXXNNu","trackType":"spotify","seek":15000,"duration":366,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Dec 22 18:28:43 volumio-erg volumio[7693]: verbose: CURRENT POSITION 2 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::syncState stateService pause Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::syncState currentStatus pause Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:43 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:43 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:43 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:43 volumio-erg volumio[7693]: info: CoreStateMachine::stPlaybackTimer Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: SPOTIFY VOLUME 100 Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: VOLUMIO VOLUME 86 Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: DELTA VOLUME ENOUGH: true Dec 22 18:28:43 volumio-erg volumio[7693]: info: Setting Spotify Volume from Volumio: 86 Dec 22 18:28:43 volumio-erg volumio[7693]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 22 18:28:43 volumio-erg volumio[7693]: info: Alsa Settings successfully stored Dec 22 18:28:43 volumio-erg volumio[7693]: info: Asound.conf file written Dec 22 18:28:43 volumio-erg qobuz-connect[8429]: 20251222 18:28:43.987 [8429.8429] INFO SampleApp: Stopping Local configuration server Dec 22 18:28:44 volumio-erg sudo[20545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 22 18:28:44 volumio-erg sudo[20545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20545]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 22 18:28:44 volumio-erg volumio[7693]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 22 18:28:44 volumio-erg volumio[7693]: info: Output device has changed, restarting MPD Dec 22 18:28:44 volumio-erg volumio[7693]: info: Output device has changed, restarting Shairport Sync Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 18:28:44 volumio-erg sudo[20551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20551]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 18:28:44 volumio-erg volumio[7693]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 18:28:44 volumio-erg sudo[20554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:44 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:44 volumio-erg volumio[7693]: info: Output device has changed, restarting MPD Dec 22 18:28:44 volumio-erg systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 22 18:28:44 volumio-erg sudo[20563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:28:44 volumio-erg sudo[20563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: Output device has changed, restarting Shairport Sync Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 18:28:44 volumio-erg sudo[20566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 18:28:44 volumio-erg sudo[20566]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg sudo[20568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 18:28:44 volumio-erg volumio[7693]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20563]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:44 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:44 volumio-erg sudo[20579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:28:44 volumio-erg sudo[20579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:28:44 volumio-erg sudo[20581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:28:44 volumio-erg sudo[20584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20592]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:28:44 volumio-erg sudo[20592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: MPD Permissions set Dec 22 18:28:44 volumio-erg sudo[20600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:28:44 volumio-erg volumio[7693]: info: MPD Permissions set Dec 22 18:28:44 volumio-erg sudo[20600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20581]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20592]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg sudo[20579]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20584]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20600]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:28:44 volumio-erg sudo[20612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:28:44 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:44 volumio-erg sudo[20629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg volumio[7693]: info: Starting Shairport Sync Dec 22 18:28:44 volumio-erg volumio[7693]: info: Starting Shairport Sync Dec 22 18:28:44 volumio-erg sudo[20640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 22 18:28:44 volumio-erg sudo[20640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg sudo[20642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 22 18:28:44 volumio-erg sudo[20642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:44 volumio-erg systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 22 18:28:44 volumio-erg systemd[1]: shairport-sync.service: Deactivated successfully. Dec 22 18:28:44 volumio-erg systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:28:44 volumio-erg systemd[1]: shairport-sync.service: Consumed 22.789s CPU time. Dec 22 18:28:44 volumio-erg systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:28:44 volumio-erg sudo[20640]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: Shairport-Sync Started Dec 22 18:28:44 volumio-erg sudo[20642]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:44 volumio-erg volumio[7693]: info: Shairport-Sync Started Dec 22 18:28:45 volumio-erg volumio[7693]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Dec 22 18:28:45 volumio-erg volumio[7693]: info: Sending Spotify command with payload to local API: /player/volume Dec 22 18:28:45 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:45+02:00" level=debug msg="update volume requested to 56360/65535" Dec 22 18:28:45 volumio-erg qobuz-connect[8429]: 20251222 18:28:45.669 [8429.8429] INFO SampleApp: shat down connection on UNIX socket Dec 22 18:28:45 volumio-erg volumio[7693]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 22 18:28:45 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:28:45 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:45 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:45 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:45+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 22 18:28:45 volumio-erg go-librespot[7971]: time="2025-12-22T18:28:45+02:00" level=trace msg="emitting websocket event: volume" Dec 22 18:28:45 volumio-erg volumio[7693]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Dec 22 18:28:45 volumio-erg volumio[7693]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Dec 22 18:28:45 volumio-erg systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 18:28:45 volumio-erg systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:28:45 volumio-erg systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:28:46 volumio-erg sudo[20612]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:46 volumio-erg sudo[20629]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:46 volumio-erg sudo[20528]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:46 volumio-erg volumio[7693]: info: Executing endpoint qc_getconfig Dec 22 18:28:46 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.196 [20664.20664] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 22 18:28:46 volumio-erg volumio[7693]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 22 18:28:46 volumio-erg volumio[7693]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.223 [20664.20664] INFO VolumeManager: [0x5f5258]: Setting new playback volume: 75 Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.224 [20664.20664] INFO VolumeManager: [0x5f5258]: Setting new mute state: 0 Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.224 [20664.20664] INFO QobuzConnect: [0x5f5c28]: Client initialized! Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.224 [20664.20664] INFO SampleApp: Starting Avahi advertising, name: Volumio erg, service name: _qobuz-connect._tcp Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.253 [20664.20664] INFO LocalConfigManager: [0x5f4b38]: Starting Local Configuration server Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.253 [20664.20664] INFO SampleApp: Starting Local configuration server Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.254 [20664.20664] INFO SampleApp: Connected to UNIX socket client 0x5df818 Dec 22 18:28:46 volumio-erg qobuz-connect[20664]: 20251222 18:28:46.346 [20664.20664] INFO SampleApp: Playback volume changed: 75 Dec 22 18:28:46 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:46 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:46 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:28:46 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:28:46 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:28:46 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:28:46 volumio-erg sudo[20682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:28:46 volumio-erg sudo[20682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:47 volumio-erg systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 22 18:28:47 volumio-erg sudo[20682]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:47 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreStateMachine::getcurrentVolume Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 18:28:47 volumio-erg volumio[7693]: info: VolumeController:: Volume=86 Mute =false Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:47 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:47 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:47 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:47 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreStateMachine::updateTrackBlock Dec 22 18:28:47 volumio-erg volumio[7693]: info: CorePlayQueue::getTrackBlock Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 18:28:47 volumio-erg volumio[7693]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 22 18:28:47 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:28:47 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:28:47 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:28:47 volumio-erg volumio[7693]: info: VolumeController:: Volume=86 Mute =false Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:47 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:47 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:47 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:47 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:47 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:47 volumio-erg volumio[7693]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 22 18:28:47 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:28:47 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:28:47 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:28:47 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:28:47 volumio-erg sudo[20708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:28:47 volumio-erg sudo[20708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:47 volumio-erg sudo[20710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:28:47 volumio-erg sudo[20710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:28:47 volumio-erg sudo[20710]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:47 volumio-erg sudo[20708]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:48 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:28:49 volumio-erg volumio[7693]: info: Executing endpoint tc_getconfig Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 22 18:28:49 volumio-erg vtcs[20685]: STARTING TidalConnect services, version: 1.5.2.56 Dec 22 18:28:49 volumio-erg vtcs[20685]: [2025-12-22 18:28:49.456] [tisoc] [critical] [DeviceInfo.cpp:52] ioctl error. ret=-1, errno="No such device" Dec 22 18:28:49 volumio-erg vtcs[20685]: [2025-12-22 18:28:49.456] [tisoc] [critical] [DeviceInfo.cpp:53] [ASSERT] generateDeviceId(0) Dec 22 18:28:49 volumio-erg vtcs[20685]: STARTED TidalConnect services. Dec 22 18:28:49 volumio-erg volumio[7693]: info: Executing endpoint tc_connect Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 22 18:28:49 volumio-erg volumio[7693]: info: Connecting to TidalConnect Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:49 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:49 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:49 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:49 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:49 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:49 volumio-erg volumio[7693]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:28:49 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:28:49 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:28:49 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:28:49 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:28:49 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:49 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:28:49 volumio-erg volumio[7693]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Dec 22 18:28:49 volumio-erg volumio[7693]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 22 18:28:49 volumio-erg volumio[7693]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Dec 22 18:28:49 volumio-erg systemd[1]: mpd.service: Deactivated successfully. Dec 22 18:28:49 volumio-erg systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 18:28:49 volumio-erg systemd[1]: mpd.service: Consumed 5.328s CPU time. Dec 22 18:28:49 volumio-erg systemd[1]: mpd.socket: Deactivated successfully. Dec 22 18:28:49 volumio-erg mpd_monitor.sh[20672]: MPD error: Connection reset by peer Dec 22 18:28:49 volumio-erg systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 18:28:49 volumio-erg systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 18:28:49 volumio-erg mpd_monitor.sh[8513]: MPD Monitor Service: MPD Appears to be inactive, restarting Dec 22 18:28:49 volumio-erg mpd_monitor.sh[20731]: mpd: no process found Dec 22 18:28:49 volumio-erg systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 18:28:49 volumio-erg systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 18:28:49 volumio-erg systemd[1]: mpd.service: Deactivated successfully. Dec 22 18:28:49 volumio-erg systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 18:28:49 volumio-erg systemd[1]: mpd.socket: Deactivated successfully. Dec 22 18:28:49 volumio-erg systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 18:28:49 volumio-erg systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 18:28:49 volumio-erg systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 18:28:49 volumio-erg systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 18:28:50 volumio-erg sudo[20736]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 22 18:28:50 volumio-erg sudo[20736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 22 18:28:50 volumio-erg volumio[7693]: info: TidalConnect service started! Dec 22 18:28:50 volumio-erg sudo[20736]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:50 volumio-erg volumio[7693]: info: TidalConnect service started! Dec 22 18:28:50 volumio-erg volumio[7693]: info: TidalConnect service started! Dec 22 18:28:56 volumio-erg mpd[20738]: 2025-12-22T18:28:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 18:28:57 volumio-erg systemd[1]: Started mpd.service - Music Player Daemon. Dec 22 18:28:57 volumio-erg mpd_monitor.sh[8513]: MPD Monitor Service: MPD restarted due to no mpc output. Dec 22 18:28:57 volumio-erg sudo[20568]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:57 volumio-erg sudo[20554]: pam_unix(sudo:session): session closed for user root Dec 22 18:28:57 volumio-erg volumio[7693]: error: MPD error: The expression evaluated to a falsy value: Dec 22 18:28:57 volumio-erg volumio[7693]: assert.ok(self.idling) Dec 22 18:28:57 volumio-erg volumio[7693]: error: The expression evaluated to a falsy value: Dec 22 18:28:57 volumio-erg volumio[7693]: assert.ok(self.idling) Dec 22 18:28:57 volumio-erg volumio[7693]: error: updateQueue error: null Dec 22 18:29:00 volumio-erg sudo[20760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 22 18:29:00 volumio-erg sudo[20758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 22 18:29:00 volumio-erg sudo[20758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:00 volumio-erg sudo[20760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:00 volumio-erg systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 22 18:29:00 volumio-erg systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 22 18:29:00 volumio-erg systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 22 18:29:00 volumio-erg systemd[1]: mpd_monitor.service: Consumed 3.825s CPU time. Dec 22 18:29:00 volumio-erg systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 22 18:29:00 volumio-erg sudo[20760]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:00 volumio-erg sudo[20758]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:00 volumio-erg volumio[7693]: info: Successfully started MPD Monitor Dec 22 18:29:00 volumio-erg volumio[7693]: info: Successfully started MPD Monitor Dec 22 18:29:00 volumio-erg mpd_monitor.sh[20763]: MPD Monitor Service: Starting MPD Monitor Service Dec 22 18:29:09 volumio-erg volumio[7693]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 22 18:29:09 volumio-erg volumio[7693]: info: Preparing to save Alsa Options, stopping services first Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:09 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPause Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreStateMachine::pause Dec 22 18:29:09 volumio-erg volumio[7693]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"FiiO USB Audio Class 2.0 DAC"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:09 volumio-erg volumio[7693]: info: Device 5 does not have any Mixer Control Available Dec 22 18:29:09 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:09 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:09 volumio-erg vtcs[20685]: [2025-12-22 18:29:09.479] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 22 18:29:09 volumio-erg vtcs[20685]: [2025-12-22 18:29:09.480] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 22 18:29:09 volumio-erg sudo[20794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:09 volumio-erg sudo[20794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 22 18:29:09 volumio-erg volumio[7693]: info: Updating Volume Controller Parameters: Device: 5 Name: FiiO USB Audio Class 2.0 DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 22 18:29:09 volumio-erg systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 22 18:29:09 volumio-erg systemd[1]: vtcs.service: Killing process 20721 (vtcs) with signal SIGKILL. Dec 22 18:29:09 volumio-erg systemd[1]: vtcs.service: Deactivated successfully. Dec 22 18:29:09 volumio-erg systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 22 18:29:09 volumio-erg sudo[20794]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 22 18:29:09 volumio-erg volumio[7693]: info: Disabling external Volume Control Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:09 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:09 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:09 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:09 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:09 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:09 volumio-erg volumio[7693]: info: Preparing to generate the ALSA configuration file Dec 22 18:29:10 volumio-erg sudo[20802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:10 volumio-erg sudo[20802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg volumio[7693]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 22 18:29:10 volumio-erg volumio[7693]: info: Reading ALSA contributions from plugins. Dec 22 18:29:10 volumio-erg volumio[7693]: info: Dec 22 18:29:10 volumio-erg volumio[7693]: ---------------------------- MPD announces state update: mixer Dec 22 18:29:10 volumio-erg volumio[7693]: info: ControllerMpd::getState Dec 22 18:29:10 volumio-erg volumio[7693]: verbose: ControllerMpd::sendMpdCommand status Dec 22 18:29:10 volumio-erg sudo[20809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:10 volumio-erg volumio[7693]: info: Dec 22 18:29:10 volumio-erg volumio[7693]: ---------------------------- MPD announces state update: mixer Dec 22 18:29:10 volumio-erg volumio[7693]: info: ControllerMpd::getState Dec 22 18:29:10 volumio-erg volumio[7693]: verbose: ControllerMpd::sendMpdCommand status Dec 22 18:29:10 volumio-erg sudo[20809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg volumio[7693]: info: sendMpdCommand status took 17 milliseconds Dec 22 18:29:10 volumio-erg sudo[20802]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg volumio[7693]: verbose: ControllerMpd::parseState Dec 22 18:29:10 volumio-erg volumio[7693]: info: ControllerMpd::pushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:10 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Dec 22 18:29:10 volumio-erg sudo[20809]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg volumio[7693]: info: ------------------------------ 67ms Dec 22 18:29:10 volumio-erg sudo[20812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:10 volumio-erg sudo[20812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg volumio[7693]: info: sendMpdCommand status took 77 milliseconds Dec 22 18:29:10 volumio-erg volumio[7693]: verbose: ControllerMpd::parseState Dec 22 18:29:10 volumio-erg volumio[7693]: info: ControllerMpd::pushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:10 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:10 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Dec 22 18:29:10 volumio-erg volumio[7693]: info: ------------------------------ 91ms Dec 22 18:29:10 volumio-erg systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 18:29:10 volumio-erg qobuz-connect[20664]: 20251222 18:29:10.276 [20664.20664] INFO SampleApp: Stopping Local configuration server Dec 22 18:29:10 volumio-erg qobuz-connect[20664]: 20251222 18:29:10.286 [20664.20664] INFO SampleApp: shat down connection on UNIX socket Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:10 volumio-erg systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 18:29:10 volumio-erg systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 22 18:29:10 volumio-erg systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:10 volumio-erg volumio[7693]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 22 18:29:10 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg sudo[20812]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg volumio[7693]: info: Asound.conf file written Dec 22 18:29:10 volumio-erg sudo[20824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Dec 22 18:29:10 volumio-erg sudo[20824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20824]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg volumio[7693]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Dec 22 18:29:10 volumio-erg volumio[7693]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: Output device has changed, restarting MPD Dec 22 18:29:10 volumio-erg volumio[7693]: info: Output device has changed, restarting Shairport Sync Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:10 volumio-erg sudo[20830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 18:29:10 volumio-erg sudo[20830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 18:29:10 volumio-erg sudo[20832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20830]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg volumio[7693]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 18:29:10 volumio-erg volumio[7693]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:10 volumio-erg systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 22 18:29:10 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg volumio[7693]: info: Output device has changed, restarting MPD Dec 22 18:29:10 volumio-erg sudo[20842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:10 volumio-erg sudo[20842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg volumio[7693]: info: Output device has changed, restarting Shairport Sync Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:10 volumio-erg sudo[20844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 18:29:10 volumio-erg sudo[20844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20846]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 18:29:10 volumio-erg sudo[20846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20844]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg volumio[7693]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 18:29:10 volumio-erg volumio[7693]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:10 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:10 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:10 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:10 volumio-erg sudo[20842]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:10 volumio-erg sudo[20857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:10 volumio-erg sudo[20857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:10 volumio-erg sudo[20862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:10 volumio-erg sudo[20859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:10 volumio-erg sudo[20871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:10 volumio-erg sudo[20871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:11 volumio-erg volumio[7693]: info: Dec 22 18:29:11 volumio-erg volumio[7693]: ---------------------------- MPD announces state update: mixer Dec 22 18:29:11 volumio-erg sudo[20857]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg sudo[20871]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg sudo[20878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:11 volumio-erg sudo[20878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:11 volumio-erg volumio[7693]: info: ControllerMpd::getState Dec 22 18:29:11 volumio-erg volumio[7693]: verbose: ControllerMpd::sendMpdCommand status Dec 22 18:29:11 volumio-erg sudo[20859]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg volumio[7693]: error: MPD error: Error: write EPIPE Dec 22 18:29:11 volumio-erg volumio[7693]: error: write EPIPE {"code":"EPIPE","errno":-32,"syscall":"write"} Dec 22 18:29:11 volumio-erg volumio[7693]: error: MPD error: Error: write EPIPE Dec 22 18:29:11 volumio-erg volumio[7693]: error: write EPIPE {"code":"EPIPE","errno":-32,"syscall":"write"} Dec 22 18:29:11 volumio-erg sudo[20880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:11 volumio-erg sudo[20862]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg sudo[20880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:11 volumio-erg volumio[7693]: info: MPD Permissions set Dec 22 18:29:11 volumio-erg volumio[7693]: info: MPD Permissions set Dec 22 18:29:11 volumio-erg volumio[7693]: info: Executing endpoint qc_getconfig Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 22 18:29:11 volumio-erg sudo[20878]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 18:29:11 volumio-erg systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 18:29:11 volumio-erg systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg sudo[20891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:11 volumio-erg sudo[20891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:11 volumio-erg systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg sudo[20880]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 18:29:11 volumio-erg systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 18:29:11 volumio-erg systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:11 volumio-erg systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:11 volumio-erg sudo[20891]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:11 volumio-erg volumio[7693]: info: Starting Shairport Sync Dec 22 18:29:11 volumio-erg volumio[7693]: info: Starting Shairport Sync Dec 22 18:29:11 volumio-erg sudo[20909]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 22 18:29:11 volumio-erg sudo[20909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:11 volumio-erg sudo[20907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 22 18:29:11 volumio-erg sudo[20907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:11 volumio-erg volumio[7693]: info: Executing endpoint qc_getconfig Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 22 18:29:11 volumio-erg systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 22 18:29:11 volumio-erg systemd[1]: shairport-sync.service: Deactivated successfully. Dec 22 18:29:11 volumio-erg systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:29:11 volumio-erg systemd[1]: shairport-sync.service: Consumed 1.934s CPU time. Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.449 [20902.20902] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 22 18:29:11 volumio-erg volumio[7693]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 22 18:29:11 volumio-erg volumio[7693]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 22 18:29:11 volumio-erg systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:29:11 volumio-erg sudo[20907]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg sudo[20909]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:11 volumio-erg volumio[7693]: info: Shairport-Sync Started Dec 22 18:29:11 volumio-erg volumio[7693]: info: Shairport-Sync Started Dec 22 18:29:11 volumio-erg volumio[7693]: (node:7693) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Dec 22 18:29:11 volumio-erg volumio[7693]: (Use `node --trace-warnings ...` to show where the warning was created) Dec 22 18:29:11 volumio-erg volumio[7693]: (node:7693) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Dec 22 18:29:11 volumio-erg volumio[7693]: (node:7693) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Dec 22 18:29:11 volumio-erg volumio[7693]: (node:7693) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Dec 22 18:29:11 volumio-erg volumio[7693]: (node:7693) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.819 [20902.20902] INFO VolumeManager: [0x457258]: Setting new playback volume: 75 Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.819 [20902.20902] INFO VolumeManager: [0x457258]: Setting new mute state: 0 Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.819 [20902.20902] INFO QobuzConnect: [0x457c28]: Client initialized! Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.819 [20902.20902] INFO SampleApp: Starting Avahi advertising, name: Volumio erg, service name: _qobuz-connect._tcp Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.836 [20902.20902] INFO LocalConfigManager: [0x456b38]: Starting Local Configuration server Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.836 [20902.20902] INFO SampleApp: Starting Local configuration server Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.838 [20902.20902] INFO SampleApp: Playback volume changed: 75 Dec 22 18:29:11 volumio-erg qobuz-connect[20902]: 20251222 18:29:11.839 [20902.20902] INFO SampleApp: Connected to UNIX socket client 0x441818 Dec 22 18:29:11 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:11 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:12 volumio-erg volumio[7693]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 22 18:29:12 volumio-erg volumio[7693]: info: Preparing to save Alsa Options, stopping services first Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:12 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPause Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreStateMachine::pause Dec 22 18:29:12 volumio-erg volumio[7693]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"FiiO USB Audio Class 2.0 DAC"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:12 volumio-erg volumio[7693]: info: Device 5 does not have any Mixer Control Available Dec 22 18:29:12 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:12 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 22 18:29:12 volumio-erg volumio[7693]: info: Updating Volume Controller Parameters: Device: 5 Name: FiiO USB Audio Class 2.0 DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 22 18:29:12 volumio-erg volumio[7693]: info: Disabling external Volume Control Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:12 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:12 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:12 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:12 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:12 volumio-erg volumio[7693]: info: Preparing to generate the ALSA configuration file Dec 22 18:29:12 volumio-erg volumio[7693]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 22 18:29:12 volumio-erg volumio[7693]: info: Reading ALSA contributions from plugins. Dec 22 18:29:12 volumio-erg go-librespot[7971]: time="2025-12-22T18:29:12+02:00" level=trace msg="sent dealer ping" Dec 22 18:29:12 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:12 volumio-erg systemd[1]: mpd.service: Deactivated successfully. Dec 22 18:29:12 volumio-erg systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 18:29:12 volumio-erg systemd[1]: mpd.service: Consumed 4.373s CPU time. Dec 22 18:29:12 volumio-erg systemd[1]: mpd.socket: Deactivated successfully. Dec 22 18:29:12 volumio-erg systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 18:29:12 volumio-erg systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 18:29:12 volumio-erg go-librespot[7971]: time="2025-12-22T18:29:12+02:00" level=trace msg="received dealer pong" Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:12 volumio-erg systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 18:29:12 volumio-erg systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 18:29:12 volumio-erg sudo[20953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:12 volumio-erg sudo[20942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:12 volumio-erg sudo[20953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:12 volumio-erg sudo[20942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:12 volumio-erg sudo[20947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:12 volumio-erg sudo[20947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 22 18:29:12 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 22 18:29:13 volumio-erg sudo[20953]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg volumio[7693]: info: Asound.conf file unchanged, so no further update is needed Dec 22 18:29:13 volumio-erg volumio[7693]: info: Output device has changed, restarting MPD Dec 22 18:29:13 volumio-erg sudo[20942]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg sudo[20947]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg sudo[20965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:13 volumio-erg sudo[20965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg sudo[20969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 18:29:13 volumio-erg sudo[20969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg volumio[7693]: info: Output device has changed, restarting Shairport Sync Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:13 volumio-erg sudo[20969]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 18:29:13 volumio-erg qobuz-connect[20902]: 20251222 18:29:13.176 [20902.20902] INFO SampleApp: Stopping Local configuration server Dec 22 18:29:13 volumio-erg sudo[20974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 18:29:13 volumio-erg sudo[20974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg volumio[7693]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 18:29:13 volumio-erg volumio[7693]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg sudo[20960]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 22 18:29:13 volumio-erg sudo[20960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 22 18:29:13 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:13 volumio-erg sudo[20960]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:13 volumio-erg systemd[1]: mpd.service: Deactivated successfully. Dec 22 18:29:13 volumio-erg systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 18:29:13 volumio-erg systemd[1]: mpd.socket: Deactivated successfully. Dec 22 18:29:13 volumio-erg systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 18:29:13 volumio-erg systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 18:29:13 volumio-erg sudo[20984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:13 volumio-erg sudo[20984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg sudo[20986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:13 volumio-erg sudo[20986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 18:29:13 volumio-erg volumio[7693]: info: MPD Permissions set Dec 22 18:29:13 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:13 volumio-erg systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg sudo[20994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:13 volumio-erg sudo[20994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:13 volumio-erg volumio[7693]: info: Starting Shairport Sync Dec 22 18:29:13 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:13 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:13 volumio-erg sudo[21011]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 22 18:29:13 volumio-erg sudo[21011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg sudo[20994]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg sudo[20984]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg sudo[21013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:29:13 volumio-erg sudo[21013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg sudo[21015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:13 volumio-erg sudo[21015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:13 volumio-erg sudo[20986]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreStateMachine::getcurrentVolume Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:13 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:13 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:13 volumio-erg sudo[20995]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 22 18:29:13 volumio-erg sudo[20995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 22 18:29:13 volumio-erg sudo[20995]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 22 18:29:13 volumio-erg systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 22 18:29:13 volumio-erg sudo[21013]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg systemd[1]: shairport-sync.service: Deactivated successfully. Dec 22 18:29:13 volumio-erg systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:29:13 volumio-erg systemd[1]: shairport-sync.service: Consumed 1.620s CPU time. Dec 22 18:29:13 volumio-erg systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:29:13 volumio-erg sudo[21011]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg volumio[7693]: info: Shairport-Sync Started Dec 22 18:29:13 volumio-erg qobuz-connect[20902]: 20251222 18:29:13.843 [20902.20902] INFO SampleApp: shat down connection on UNIX socket Dec 22 18:29:13 volumio-erg volumio[7693]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Dec 22 18:29:13 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:13 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:13 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:13 volumio-erg systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 18:29:13 volumio-erg systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:13 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:13 volumio-erg systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:13 volumio-erg sudo[20965]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:13 volumio-erg sudo[21015]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:14 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:14 volumio-erg volumio[7693]: info: Executing endpoint qc_getconfig Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.126 [21026.21026] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Dec 22 18:29:14 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.134 [21026.21026] INFO VolumeManager: [0x1d09258]: Setting new playback volume: 75 Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.135 [21026.21026] INFO VolumeManager: [0x1d09258]: Setting new mute state: 0 Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.135 [21026.21026] INFO QobuzConnect: [0x1d09c28]: Client initialized! Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.135 [21026.21026] INFO SampleApp: Starting Avahi advertising, name: Volumio erg, service name: _qobuz-connect._tcp Dec 22 18:29:14 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:14 volumio-erg volumio[7693]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Dec 22 18:29:14 volumio-erg volumio[7693]: info: QobuzConnect: QOBUZ Connect daemon connected Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.171 [21026.21026] INFO LocalConfigManager: [0x1d08b38]: Starting Local Configuration server Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.171 [21026.21026] INFO SampleApp: Starting Local configuration server Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.172 [21026.21026] INFO SampleApp: Connected to UNIX socket client 0x1cf3818 Dec 22 18:29:14 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:14 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:14 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:14 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:14 volumio-erg sudo[21064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:29:14 volumio-erg sudo[21064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:14 volumio-erg sudo[21066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:29:14 volumio-erg sudo[21066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:14 volumio-erg qobuz-connect[21026]: 20251222 18:29:14.282 [21026.21026] INFO SampleApp: Playback volume changed: 75 Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg sudo[21064]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:14 volumio-erg sudo[21066]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:14 volumio-erg volumio[7693]: info: Executing endpoint tc_getconfig Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Dec 22 18:29:14 volumio-erg vtcs[21023]: STARTING TidalConnect services, version: 1.5.2.56 Dec 22 18:29:14 volumio-erg vtcs[21023]: [2025-12-22 18:29:14.648] [tisoc] [critical] [DeviceInfo.cpp:52] ioctl error. ret=-1, errno="No such device" Dec 22 18:29:14 volumio-erg vtcs[21023]: [2025-12-22 18:29:14.648] [tisoc] [critical] [DeviceInfo.cpp:53] [ASSERT] generateDeviceId(0) Dec 22 18:29:14 volumio-erg vtcs[21023]: STARTED TidalConnect services. Dec 22 18:29:14 volumio-erg volumio[7693]: info: Executing endpoint tc_connect Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Dec 22 18:29:14 volumio-erg volumio[7693]: info: Connecting to TidalConnect Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:14 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:14 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg volumio[7693]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::servicePushState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:14 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:14 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:14 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:14 volumio-erg volumio[7693]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Dec 22 18:29:16 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:16 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:16 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:16 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:16 volumio-erg sudo[21108]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:29:16 volumio-erg sudo[21108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg sudo[21108]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:16 volumio-erg volumio[7693]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Dec 22 18:29:16 volumio-erg volumio[7693]: info: Preparing to save Alsa Options, stopping services first Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPause Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreStateMachine::pause Dec 22 18:29:16 volumio-erg volumio[7693]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"FiiO USB Audio Class 2.0 DAC"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:16 volumio-erg volumio[7693]: info: Device 5 does not have any Mixer Control Available Dec 22 18:29:16 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg vtcs[21023]: [2025-12-22 18:29:16.363] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Dec 22 18:29:16 volumio-erg vtcs[21023]: [2025-12-22 18:29:16.363] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Dec 22 18:29:16 volumio-erg sudo[21122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:16 volumio-erg sudo[21122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 22 18:29:16 volumio-erg volumio[7693]: info: Updating Volume Controller Parameters: Device: 5 Name: FiiO USB Audio Class 2.0 DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 22 18:29:16 volumio-erg volumio[7693]: info: Disabling external Volume Control Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:16 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:16 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg volumio[7693]: info: Preparing to generate the ALSA configuration file Dec 22 18:29:16 volumio-erg systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Dec 22 18:29:16 volumio-erg systemd[1]: vtcs.service: Killing process 21073 (vtcs) with signal SIGKILL. Dec 22 18:29:16 volumio-erg systemd[1]: vtcs.service: Deactivated successfully. Dec 22 18:29:16 volumio-erg systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Dec 22 18:29:16 volumio-erg sudo[21122]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:16 volumio-erg sudo[21129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:16 volumio-erg sudo[21129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg volumio[7693]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Dec 22 18:29:16 volumio-erg volumio[7693]: info: Reading ALSA contributions from plugins. Dec 22 18:29:16 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:16 volumio-erg volumio[7693]: info: TidalConnect service stoped! Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Dec 22 18:29:16 volumio-erg sudo[21137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 22 18:29:16 volumio-erg sudo[21137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg sudo[21129]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreStateMachine::getcurrentVolume Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreStateMachine::pushState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioPushState Dec 22 18:29:16 volumio-erg sudo[21137]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:16 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output update for this device Dec 22 18:29:16 volumio-erg volumio[7693]: info: MRS: Pushing multiroomSync output Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg sudo[21152]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:16 volumio-erg sudo[21152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg volumio[7693]: info: TidalConnect service started! Dec 22 18:29:16 volumio-erg qobuz-connect[21026]: 20251222 18:29:16.849 [21026.21026] INFO SampleApp: Stopping Local configuration server Dec 22 18:29:16 volumio-erg systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Dec 22 18:29:16 volumio-erg volumio[7693]: info: Asound.conf file unchanged, so no further update is needed Dec 22 18:29:16 volumio-erg volumio[7693]: info: Output device has changed, restarting MPD Dec 22 18:29:16 volumio-erg volumio[7693]: info: Output device has changed, restarting Shairport Sync Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:16 volumio-erg sudo[21159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 18:29:16 volumio-erg sudo[21159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg sudo[21159]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:16 volumio-erg sudo[21161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 18:29:16 volumio-erg sudo[21161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:16 volumio-erg volumio[7693]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 18:29:16 volumio-erg volumio[7693]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:16 volumio-erg volumio[7693]: info: QobuzConnect: setDeactiveState invoked Dec 22 18:29:16 volumio-erg volumio[7693]: info: CoreCommandRouter::volumioGetState Dec 22 18:29:16 volumio-erg volumio[7693]: info: CorePlayQueue::getTrack 2 Dec 22 18:29:16 volumio-erg sudo[21171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:16 volumio-erg sudo[21171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:17 volumio-erg sudo[21174]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Dec 22 18:29:17 volumio-erg sudo[21174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:17 volumio-erg systemd[1]: mpd.service: Deactivated successfully. Dec 22 18:29:17 volumio-erg systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 22 18:29:17 volumio-erg systemd[1]: mpd.service: Consumed 2.972s CPU time. Dec 22 18:29:17 volumio-erg systemd[1]: mpd.socket: Deactivated successfully. Dec 22 18:29:17 volumio-erg systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 22 18:29:17 volumio-erg systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 22 18:29:17 volumio-erg volumio[7693]: info: MPD Permissions set Dec 22 18:29:17 volumio-erg volumio[7693]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:17 volumio-erg volumio[7693]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg sudo[21182]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Dec 22 18:29:17 volumio-erg sudo[21182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 18:29:17 volumio-erg volumio[7693]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 18:29:17 volumio-erg systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 22 18:29:17 volumio-erg volumio[7693]: info: Starting Shairport Sync Dec 22 18:29:17 volumio-erg systemd[1]: Starting mpd.service - Music Player Daemon... Dec 22 18:29:17 volumio-erg sudo[21193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 22 18:29:17 volumio-erg sudo[21193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:17 volumio-erg sudo[21184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Dec 22 18:29:17 volumio-erg sudo[21184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:17 volumio-erg sudo[21182]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:17 volumio-erg sudo[21174]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:17 volumio-erg sudo[21171]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:17 volumio-erg systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 22 18:29:17 volumio-erg sudo[21196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Dec 22 18:29:17 volumio-erg sudo[21196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 22 18:29:17 volumio-erg volumio[7693]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 18:29:17 volumio-erg systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Dec 22 18:29:17 volumio-erg sudo[21192]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 22 18:29:17 volumio-erg sudo[21192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 22 18:29:17 volumio-erg systemd[1]: shairport-sync.service: Deactivated successfully. Dec 22 18:29:17 volumio-erg systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:29:17 volumio-erg systemd[1]: shairport-sync.service: Consumed 1.566s CPU time. Dec 22 18:29:17 volumio-erg sudo[21192]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:17 volumio-erg sudo[21184]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:17 volumio-erg volumio[7693]: Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Dec 22 18:29:17 volumio-erg volumio[7693]: Job for vtcs.service canceled. Dec 22 18:29:17 volumio-erg volumio[7693]: at ChildProcess.exithandler (node:child_process:421:12) Dec 22 18:29:17 volumio-erg volumio[7693]: at ChildProcess.emit (node:events:514:28) Dec 22 18:29:17 volumio-erg volumio[7693]: at maybeClose (node:internal/child_process:1105:16) Dec 22 18:29:17 volumio-erg volumio[7693]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) { Dec 22 18:29:17 volumio-erg volumio[7693]: code: 1, Dec 22 18:29:17 volumio-erg volumio[7693]: killed: false, Dec 22 18:29:17 volumio-erg volumio[7693]: signal: null, Dec 22 18:29:17 volumio-erg volumio[7693]: cmd: '/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3', Dec 22 18:29:17 volumio-erg volumio[7693]: stdout: '', Dec 22 18:29:17 volumio-erg volumio[7693]: stderr: 'Job for vtcs.service canceled.\n' Dec 22 18:29:17 volumio-erg volumio[7693]: } Dec 22 18:29:17 volumio-erg volumio[7693]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 18:29:17 volumio-erg systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 22 18:29:17 volumio-erg sudo[21193]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:18 volumio-erg qobuz-connect[21026]: 20251222 18:29:18.181 [21026.21026] INFO SampleApp: shat down connection on UNIX socket Dec 22 18:29:18 volumio-erg systemd[1]: qobuz-connect.service: Deactivated successfully. Dec 22 18:29:18 volumio-erg systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:18 volumio-erg systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Dec 22 18:29:18 volumio-erg sudo[21196]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:18 volumio-erg sudo[21152]: pam_unix(sudo:session): session closed for user root Dec 22 18:29:20 volumio-erg sudo[21235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-22 18:28' Dec 22 18:29:20 volumio-erg sudo[21235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"