Apr 11 13:05:06 volumio go-librespot[1756]: time="2026-04-11T13:05:06+03:00" level=debug msg="fetched chunk 6/28, size: 524288" uri="spotify:track:7i3H4FhCGq3kMwhRnwDe6J" Apr 11 13:05:20 volumio go-librespot[1756]: time="2026-04-11T13:05:20+03:00" level=debug msg="fetched chunk 7/28, size: 524288" uri="spotify:track:7i3H4FhCGq3kMwhRnwDe6J" Apr 11 13:05:23 volumio kernel: usb 1-1.3: USB disconnect, device number 5 Apr 11 13:05:23 volumio kernel: usb 1-1.3: Unable to submit urb #10: -19 at snd_usb_queue_pending_output_urbs Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=error msg="output device failed" error="ALSA error at snd_pcm_recover: No such device" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=trace msg="cleared closed output device" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=trace msg="emitting websocket event: stopped" Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}} Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: PUSH STATE SPOTIFY Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: {"status":"stop","service":"spop","title":"Don't Die Just Yet","artist":"David Holmes","album":"Let's Get Killed","albumart":"https://i.scdn.co/image/ab67616d00001e029d839aa3d234e48e0c6e3d59","uri":"spotify:track:7i3H4FhCGq3kMwhRnwDe6J","trackType":"spotify","seek":65000,"duration":393,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::servicePushState Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 13 Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 13 Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 13 Apr 11 13:05:23 volumio volumio[1254]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Don't Die Just Yet","artist":"David Holmes","album":"Let's Get Killed","albumart":"https://i.scdn.co/image/ab67616d00001e029d839aa3d234e48e0c6e3d59","uri":"spotify:track:7i3H4FhCGq3kMwhRnwDe6J","trackType":"spotify","seek":65000,"duration":393,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 11 13:05:23 volumio volumio[1254]: verbose: CURRENT POSITION 13 Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::syncState stateService stop Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::play index undefined Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:23 volumio volumio[1254]: info: [1775901923205] ControllerSpotify::clearAddPlayTrack Apr 11 13:05:23 volumio volumio[1254]: info: Sending Spotify command with payload to local API: /player/play Apr 11 13:05:23 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:23 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:05:23 volumio volumio[1254]: info: Apr 11 13:05:23 volumio volumio[1254]: ---------------------------- USB Audio Device Detached Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="resolved context of track" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Apr 11 13:05:23 volumio volumio[1254]: info: touch_display: Setting screensaver timeout to 60 seconds. Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=trace msg="emitting websocket event: will_play" Apr 11 13:05:23 volumio volumio[1254]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:3HFsuWqaZwKCTFAe9qEyEm","play_origin":"go-librespot"}} Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="selected format OGG_VORBIS_320 (428e0e9e59a258940bb1832ce3880047431b9803)" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="requested aes key for file 428e0e9e59a258940bb1832ce3880047431b9803, gid: 3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="fetched first chunk of 31, total size is 15862360 bytes" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="created new output device" Apr 11 13:05:23 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:3HFsuWqaZwKCTFAe9qEyEm: ALSA error at snd_pcm_open: No such device" Apr 11 13:05:23 volumio volumio[1254]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="fetched chunk 1/30, size: 524288" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="fetched chunk 2/30, size: 524288" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:23 volumio go-librespot[1756]: time="2026-04-11T13:05:23+03:00" level=debug msg="fetched chunk 3/30, size: 524288" uri="spotify:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:05:24 volumio go-librespot[1756]: time="2026-04-11T13:05:24+03:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Apr 11 13:05:24 volumio go-librespot[1756]: time="2026-04-11T13:05:24+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Apr 11 13:05:25 volumio volumio[1254]: info: Executing endpoint metavolumio Apr 11 13:05:25 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:05:25 volumio volumio[1254]: info: Executing endpoint metavolumio Apr 11 13:05:25 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:05:25 volumio volumio[1254]: info: Executing endpoint metavolumio Apr 11 13:05:25 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:05:25 volumio go-librespot[1756]: time="2026-04-11T13:05:25+03:00" level=trace msg="sent dealer ping" Apr 11 13:05:25 volumio go-librespot[1756]: time="2026-04-11T13:05:25+03:00" level=trace msg="received dealer pong" Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.839+03:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.102:39620 Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.894+03:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.0.102:39620 @ 0x1ccc7b0" latency=-865.576598ms platform=PLATFORM_ANDROID version=5.260331.0 Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.898+03:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.102:39620 @ 0x1ccc7b0" latency=-866.430106ms timeout=10s Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.898+03:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" Apr 11 13:05:52 volumio volumio[1254]: info: Received Get System Info Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:05:52 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.901+03:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" name=Volumio Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.901+03:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" language=en Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.903+03:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" timezone=Europe/Athens Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.905+03:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" available=true connected=false macAddress= ip4Address= ip6Address= Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.909+03:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" available=true connected=true macAddress=dc:a6:32:51:b0:5f ip4Address=192.168.0.113/24 ip6Address= ssid=Teras_Archer_5G Apr 11 13:05:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:52.909+03:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" setupComplete=true Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:05:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:05:52 volumio volumio[1254]: amixer -c 0 info | grep "bcm2835 ALSA" Apr 11 13:05:52 volumio volumio[1254]: amixer -c 1 info | grep "bcm2835 Headphones" Apr 11 13:05:52 volumio volumio[1254]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Apr 11 13:05:52 volumio volumio[1254]: amixer -c 2 info | grep "vc4-hdmi-0" Apr 11 13:05:52 volumio volumio[1254]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Apr 11 13:05:52 volumio volumio[1254]: amixer -c 3 info | grep "vc4-hdmi-1" Apr 11 13:05:53 volumio volumio[1254]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Apr 11 13:05:53 volumio volumio[1254]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Apr 11 13:05:53 volumio volumio[1254]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 11 13:05:53 volumio volumio[1254]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 11 13:05:53 volumio volumio[1254]: amixer -c 5 info | grep "Mojo" Apr 11 13:05:53 volumio volumio[1254]: Invalid card number '5'. Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.030+03:00 level=WARN msg="active output device not found in available devices" component=volumio/socket activeDeviceId=5 Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.030+03:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" selectedOutputId=5 Apr 11 13:05:53 volumio volumio[1254]: info: Received Get System Info Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:05:53 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.072+03:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" currentVersion=4.119 latestVersion=4.119 Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.072+03:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" status=UPDATE_STATUS_NONE progress=0 Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.073+03:00 level=INFO msg="emitting user changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" userId= Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.073+03:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" providers=3 Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.073+03:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" plugins=63 Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.076+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=29806 volume=92 Apr 11 13:05:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:53.076+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:05:53 volumio bluealsa[1068]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_63_DD_8F_EE_08_06, ...) Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:05:53 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:05:53 volumio volumio[1254]: verbose: New Socket.io Connection to 192.168.0.113:3000 from 192.168.0.102 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 13:05:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 13:05:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:05:54.171+03:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.0.102:39620 @ 0x1ccc7b0" latency=-864.307873ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 11 13:05:55 volumio sudo[32396]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 13:05:55 volumio sudo[32396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:05:55 volumio sudo[32396]: pam_unix(sudo:session): session closed for user root Apr 11 13:05:55 volumio sudo[32398]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 13:05:55 volumio sudo[32398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:05:55 volumio sudo[32398]: pam_unix(sudo:session): session closed for user root Apr 11 13:05:55 volumio volumio[1254]: verbose: New Socket.io Connection to 192.168.0.113 from 192.168.0.102 UA: Mozilla/5.0 (Linux; Android 15; SM-G996B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.178 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Apr 11 13:05:55 volumio sudo[32402]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 13:05:55 volumio sudo[32402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:05:55 volumio sudo[32402]: pam_unix(sudo:session): session closed for user root Apr 11 13:05:55 volumio sudo[32404]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 13:05:55 volumio sudo[32404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:05:55 volumio sudo[32404]: pam_unix(sudo:session): session closed for user root Apr 11 13:05:55 volumio volumio[1254]: verbose: New Socket.io Connection to 192.168.0.113 from 192.168.0.102 UA: Mozilla/5.0 (Linux; Android 15; SM-G996B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.178 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Apr 11 13:05:55 volumio go-librespot[1756]: time="2026-04-11T13:05:55+03:00" level=trace msg="sent dealer ping" Apr 11 13:05:55 volumio go-librespot[1756]: time="2026-04-11T13:05:55+03:00" level=trace msg="received dealer pong" Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:55 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 13:05:55 volumio volumio[1254]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 11 13:05:55 volumio volumio[1254]: info: Received Get System Info Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:05:55 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:55 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:55 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:55 volumio volumio[1254]: info: Listing playlists Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 13:05:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 11 13:05:56 volumio go-librespot[1756]: time="2026-04-11T13:05:56+03:00" level=trace msg="received accesspoint ping" Apr 11 13:05:56 volumio go-librespot[1756]: time="2026-04-11T13:05:56+03:00" level=trace msg="received accesspoint pong ack" Apr 11 13:05:56 volumio bluealsa[1068]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_46_BB_0C_CA_73_2E, ...) Apr 11 13:05:57 volumio kernel: Bluetooth: Unexpected continuation frame (len 0) Apr 11 13:05:57 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 13:05:57 volumio volumio[1254]: info: Received Get System Info Apr 11 13:05:57 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:05:57 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:05:57 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:05:57 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:57 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:57 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:05:57 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 11 13:05:58 volumio bluealsa[1068]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_61_15_C5_8D_10_D1, ...) Apr 11 13:05:59 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 13:05:59 volumio volumio[1254]: info: Received Get System Info Apr 11 13:05:59 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:05:59 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:05:59 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:05:59 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:05:59 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:05:59 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:06:00 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:00.151+03:00 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 Apr 11 13:06:00 volumio dbus-daemon[721]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.19" (uid=0 pid=1633 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=1018 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 11 13:06:02 volumio go-librespot[1756]: time="2026-04-11T13:06:02+03:00" level=debug msg="handling skip_next player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:02 volumio go-librespot[1756]: time="2026-04-11T13:06:02+03:00" level=debug msg="resolving autoplay station for 1 tracks" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="resolved autoplay station: spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="resolved context of track" uri="spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=trace msg="emitting websocket event: will_play" Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:1ugzchqZgU8wwBB6N4NmXj","play_origin":"go-librespot"}} Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="selected format OGG_VORBIS_320 (17b1381bb69be1422c65137d17c18ca56ae3f4a9)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="requested aes key for file 17b1381bb69be1422c65137d17c18ca56ae3f4a9, gid: 1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="fetched first chunk of 27, total size is 14031932 bytes" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=trace msg="seek to 1ms (diff: -178ms, samples: 44, bytes: 1962)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=warning msg="failed loading station for spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm" error="failed loading current track (load context): failed setting stream for spotify:track:1ugzchqZgU8wwBB6N4NmXj: ALSA error at snd_pcm_open: No such device" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=trace msg="emitting websocket event: stopped" Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"go-librespot"}} Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: PUSH STATE SPOTIFY Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: {"status":"stop","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::servicePushState Apr 11 13:06:03 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="sending successful reply for dealer request" Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio[1254]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 11 13:06:03 volumio volumio[1254]: verbose: CURRENT POSITION 14 Apr 11 13:06:03 volumio volumio[1254]: info: CoreStateMachine::syncState stateService stop Apr 11 13:06:03 volumio volumio[1254]: info: CoreStateMachine::syncState currentStatus stop Apr 11 13:06:03 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio[1254]: info: No code Apr 11 13:06:03 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:03 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:03 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:03 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:03.412+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=40066 volume=92 Apr 11 13:06:03 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:03.413+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=40066 volume=92 Apr 11 13:06:03 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:03.413+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=40066 volume=92 Apr 11 13:06:03 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:03.413+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:03 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:03.413+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:03 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:03.414+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:06:03 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="fetched chunk 1/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="fetched chunk 3/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="fetched chunk 2/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Apr 11 13:06:03 volumio go-librespot[1756]: time="2026-04-11T13:06:03+03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 167" Apr 11 13:06:06 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 11 13:06:07 volumio go-librespot[1756]: time="2026-04-11T13:06:07+03:00" level=debug msg="handling pause player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:07 volumio go-librespot[1756]: time="2026-04-11T13:06:07+03:00" level=debug msg="pause track at 179ms" Apr 11 13:06:07 volumio go-librespot[1756]: time="2026-04-11T13:06:07+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:07 volumio go-librespot[1756]: time="2026-04-11T13:06:07+03:00" level=debug msg="sending successful reply for dealer request" Apr 11 13:06:07 volumio go-librespot[1756]: time="2026-04-11T13:06:07+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:07 volumio go-librespot[1756]: time="2026-04-11T13:06:07+03:00" level=trace msg="emitting websocket event: paused" Apr 11 13:06:07 volumio volumio[1254]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:1ugzchqZgU8wwBB6N4NmXj","play_origin":"go-librespot"}} Apr 11 13:06:07 volumio volumio[1254]: SPOTIFY: PUSH STATE SPOTIFY Apr 11 13:06:07 volumio volumio[1254]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 11 13:06:07 volumio volumio[1254]: info: CoreCommandRouter::servicePushState Apr 11 13:06:07 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:07 volumio volumio[1254]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 11 13:06:07 volumio volumio[1254]: verbose: CURRENT POSITION 14 Apr 11 13:06:07 volumio volumio[1254]: info: CoreStateMachine::syncState stateService pause Apr 11 13:06:07 volumio volumio[1254]: info: CoreStateMachine::syncState currentStatus stop Apr 11 13:06:07 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:07 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:07 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:06:07 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:07 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:07 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:07 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Apr 11 13:06:07 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:07.473+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=44070 volume=92 Apr 11 13:06:07 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:07.473+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:08 volumio go-librespot[1756]: time="2026-04-11T13:06:08+03:00" level=debug msg="handling resume player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:08 volumio go-librespot[1756]: time="2026-04-11T13:06:08+03:00" level=trace msg="seek to 179ms (diff: -151ms, samples: 7893, bytes: 8370)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:08 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:06:08 volumio go-librespot[1756]: time="2026-04-11T13:06:08+03:00" level=warning msg="failed handling dealer request" error="failed starting playback: ALSA error at snd_pcm_open: No such device" Apr 11 13:06:08 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:08.682+03:00 level=INFO msg="new address was allocated" component=ble/conn old=4 new=5 Apr 11 13:06:10 volumio go-librespot[1756]: time="2026-04-11T13:06:10+03:00" level=debug msg="handling skip_next player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:10 volumio go-librespot[1756]: time="2026-04-11T13:06:10+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:10 volumio go-librespot[1756]: time="2026-04-11T13:06:10+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:10 volumio go-librespot[1756]: time="2026-04-11T13:06:10+03:00" level=trace msg="emitting websocket event: will_play" Apr 11 13:06:10 volumio volumio[1254]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:2c8k7Mg24AMUV5pPgJPQKg","play_origin":"go-librespot"}} Apr 11 13:06:10 volumio go-librespot[1756]: time="2026-04-11T13:06:10+03:00" level=debug msg="selected format OGG_VORBIS_320 (94fc19e59b156e34cfd1ef001f98497abb790bd8)" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:10 volumio go-librespot[1756]: time="2026-04-11T13:06:10+03:00" level=debug msg="requested aes key for file 94fc19e59b156e34cfd1ef001f98497abb790bd8, gid: 2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:11 volumio go-librespot[1756]: time="2026-04-11T13:06:11+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:11 volumio go-librespot[1756]: time="2026-04-11T13:06:11+03:00" level=debug msg="fetched first chunk of 28, total size is 14285576 bytes" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:11 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:06:11 volumio go-librespot[1756]: time="2026-04-11T13:06:11+03:00" level=warning msg="failed handling dealer request" error="failed skipping to next track: failed loading current track (advance to spotify:track:2c8k7Mg24AMUV5pPgJPQKg): failed setting stream for spotify:track:2c8k7Mg24AMUV5pPgJPQKg: ALSA error at snd_pcm_open: No such device" Apr 11 13:06:11 volumio go-librespot[1756]: time="2026-04-11T13:06:11+03:00" level=debug msg="fetched chunk 3/27, size: 524288" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:11 volumio go-librespot[1756]: time="2026-04-11T13:06:11+03:00" level=debug msg="fetched chunk 1/27, size: 524288" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:11 volumio go-librespot[1756]: time="2026-04-11T13:06:11+03:00" level=debug msg="fetched chunk 2/27, size: 524288" uri="spotify:track:2c8k7Mg24AMUV5pPgJPQKg" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="handling skip_prev player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="skip previous track" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=trace msg="emitting websocket event: will_play" Apr 11 13:06:12 volumio volumio[1254]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:1ugzchqZgU8wwBB6N4NmXj","play_origin":"go-librespot"}} Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="selected format OGG_VORBIS_320 (17b1381bb69be1422c65137d17c18ca56ae3f4a9)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="requested aes key for file 17b1381bb69be1422c65137d17c18ca56ae3f4a9, gid: 1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=debug msg="fetched first chunk of 27, total size is 14031932 bytes" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=trace msg="seek to 1ms (diff: -178ms, samples: 44, bytes: 1962)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:12 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:06:12 volumio go-librespot[1756]: time="2026-04-11T13:06:12+03:00" level=warning msg="failed handling dealer request" error="failed loading current track (skip prev): failed setting stream for spotify:track:1ugzchqZgU8wwBB6N4NmXj: ALSA error at snd_pcm_open: No such device" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched chunk 2/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched chunk 3/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched chunk 1/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="handling skip_prev player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="skip previous track" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=trace msg="emitting websocket event: will_play" Apr 11 13:06:13 volumio volumio[1254]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:1ugzchqZgU8wwBB6N4NmXj","play_origin":"go-librespot"}} Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="selected format OGG_VORBIS_320 (17b1381bb69be1422c65137d17c18ca56ae3f4a9)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="requested aes key for file 17b1381bb69be1422c65137d17c18ca56ae3f4a9, gid: 1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched first chunk of 27, total size is 14031932 bytes" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=warning msg="failed handling dealer request" error="failed loading current track (skip prev): failed setting stream for spotify:track:1ugzchqZgU8wwBB6N4NmXj: ALSA error at snd_pcm_open: No such device" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched chunk 1/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched chunk 2/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:13 volumio go-librespot[1756]: time="2026-04-11T13:06:13+03:00" level=debug msg="fetched chunk 3/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 13:06:15 volumio volumio[1254]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 11 13:06:15 volumio volumio[1254]: info: Received Get System Version Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 13:06:15 volumio volumio[1254]: info: Received Get System Info Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:06:15 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:15 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:15 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="handling skip_prev player command from 53c83f87f2bee608686656fc80d4d6c552a044b0" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="skip previous track" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=trace msg="emitting websocket event: will_play" Apr 11 13:06:15 volumio volumio[1254]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:track:3HFsuWqaZwKCTFAe9qEyEm","uri":"spotify:track:1ugzchqZgU8wwBB6N4NmXj","play_origin":"go-librespot"}} Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="selected format OGG_VORBIS_320 (17b1381bb69be1422c65137d17c18ca56ae3f4a9)" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="requested aes key for file 17b1381bb69be1422c65137d17c18ca56ae3f4a9, gid: 1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="fetched first chunk of 27, total size is 14031932 bytes" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Mojo Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=warning msg="failed handling dealer request" error="failed loading current track (skip prev): failed setting stream for spotify:track:1ugzchqZgU8wwBB6N4NmXj: ALSA error at snd_pcm_open: No such device" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="fetched chunk 1/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="fetched chunk 3/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:15 volumio go-librespot[1756]: time="2026-04-11T13:06:15+03:00" level=debug msg="fetched chunk 2/26, size: 524288" uri="spotify:track:1ugzchqZgU8wwBB6N4NmXj" Apr 11 13:06:24 volumio bluealsa[1068]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_63_DD_8F_EE_08_06, ...) Apr 11 13:06:25 volumio go-librespot[1756]: time="2026-04-11T13:06:25+03:00" level=trace msg="sent dealer ping" Apr 11 13:06:25 volumio go-librespot[1756]: time="2026-04-11T13:06:25+03:00" level=trace msg="received dealer pong" Apr 11 13:06:28 volumio bluealsa[1068]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_46_BB_0C_CA_73_2E, ...) Apr 11 13:06:29 volumio kernel: usb 1-1.3: new high-speed USB device number 6 using xhci_hcd Apr 11 13:06:29 volumio kernel: usb 1-1.3: New USB device found, idVendor=245f, idProduct=0815, bcdDevice= 1.97 Apr 11 13:06:29 volumio kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 11 13:06:29 volumio kernel: usb 1-1.3: Product: Mojo Apr 11 13:06:29 volumio kernel: usb 1-1.3: Manufacturer: Chord Electronics Ltd Apr 11 13:06:29 volumio kernel: usb 1-1.3: SerialNumber: 413-001 Apr 11 13:06:29 volumio volumio[1254]: info: Apr 11 13:06:29 volumio volumio[1254]: ---------------------------- USB Audio Device Attached Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::Close All Modals sent Apr 11 13:06:29 volumio volumio[1254]: info: Preparing to save Alsa Options, stopping services first Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:29 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::volumioPause Apr 11 13:06:29 volumio volumio[1254]: info: CoreStateMachine::pause Apr 11 13:06:29 volumio volumio[1254]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"Mojo","alsacard":"Mojo"},"i2s":false} Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:29 volumio volumio[1254]: info: Setting mixer PCM for card Mojo Apr 11 13:06:29 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:29 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:29 volumio vtcs[20404]: [2026-04-11 13:06:29.952] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Apr 11 13:06:29 volumio vtcs[20404]: [2026-04-11 13:06:29.954] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Apr 11 13:06:29 volumio sudo[32491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:29 volumio sudo[32491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 13:06:29 volumio volumio[1254]: info: Updating Volume Controller Parameters: Device: 5 Name: Mojo Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 11 13:06:29 volumio volumio[1254]: info: Disabling external Volume Control Apr 11 13:06:29 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:30 volumio volumio[1254]: info: Preparing to generate the ALSA configuration file Apr 11 13:06:30 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Apr 11 13:06:30 volumio systemd[1]: vtcs.service: Killing process 20435 (vtcs) with signal SIGKILL. Apr 11 13:06:30 volumio systemd[1]: vtcs.service: Deactivated successfully. Apr 11 13:06:30 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Apr 11 13:06:30 volumio systemd[1]: vtcs.service: Consumed 4.657s CPU time. Apr 11 13:06:30 volumio sudo[32491]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio sudo[32499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:30 volumio sudo[32499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio sudo[32506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:30 volumio sudo[32506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio sudo[32499]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio sudo[32506]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio sudo[32510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:30 volumio sudo[32510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:30 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:30 volumio qobuz-connect[20488]: 20260411 13:06:30.193 [20488.20488] INFO SampleApp: Stopping Local configuration server Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:30 volumio volumio[1254]: info: Asound.conf file unchanged, so no further update is needed Apr 11 13:06:30 volumio volumio[1254]: info: Output device has changed, restarting MPD Apr 11 13:06:30 volumio volumio[1254]: info: Output device has changed, restarting Shairport Sync Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:30 volumio sudo[32521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 13:06:30 volumio sudo[32521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio sudo[32521]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio sudo[32523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 13:06:30 volumio volumio[1254]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 13:06:30 volumio volumio[1254]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 13:06:30 volumio sudo[32523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:30 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 13:06:30 volumio sudo[32533]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:30 volumio sudo[32533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio sudo[32535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:30 volumio sudo[32535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 13:06:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 13:06:30 volumio systemd[1]: mpd.service: Consumed 1.420s CPU time. Apr 11 13:06:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 13:06:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 13:06:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 13:06:30 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:30 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:30 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:30 volumio sudo[32544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:30 volumio sudo[32544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:30 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:30 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:30.333+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%04 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=66894 volume=100 Apr 11 13:06:30 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:30.333+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%04 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:30 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:30 volumio volumio[1254]: SPOTIFY: SPOTIFY VOLUME 92 Apr 11 13:06:30 volumio volumio[1254]: SPOTIFY: VOLUMIO VOLUME 100 Apr 11 13:06:30 volumio volumio[1254]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 11 13:06:30 volumio volumio[1254]: info: Setting Spotify Volume from Volumio: 100 Apr 11 13:06:30 volumio volumio[1254]: info: MPD Permissions set Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 13:06:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:30 volumio volumio[1254]: info: Starting Shairport Sync Apr 11 13:06:30 volumio sudo[32544]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio sudo[32554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:30 volumio sudo[32554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio sudo[32533]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio sudo[32555]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 13:06:30 volumio sudo[32555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:30 volumio sudo[32535]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Apr 11 13:06:30 volumio sudo[32551]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 13:06:30 volumio sudo[32551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 13:06:30 volumio sudo[32551]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:30 volumio sudo[32555]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:30 volumio volumio[1254]: info: Shairport-Sync Started Apr 11 13:06:30 volumio volumio[1254]: (node:1254) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 11 13:06:30 volumio volumio[1254]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 11 13:06:30 volumio volumio[1254]: (node:1254) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 11 13:06:30 volumio volumio[1254]: (node:1254) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 11 13:06:30 volumio volumio[1254]: (node:1254) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 11 13:06:30 volumio volumio[1254]: (node:1254) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit Apr 11 13:06:31 volumio qobuz-connect[20488]: 20260411 13:06:31.038 [20488.20488] INFO SampleApp: shat down connection on UNIX socket Apr 11 13:06:31 volumio volumio[1254]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Apr 11 13:06:31 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:31 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:31 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:31 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 11 13:06:31 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:31 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:31 volumio sudo[32554]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:31 volumio sudo[32510]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:31 volumio volumio[1254]: info: Executing endpoint qc_getconfig Apr 11 13:06:31 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.202 [32577.32577] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 11 13:06:31 volumio volumio[1254]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 11 13:06:31 volumio volumio[1254]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.217 [32577.32577] INFO VolumeManager: [0x167af78]: Setting new playback volume: 75 Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.217 [32577.32577] INFO VolumeManager: [0x167af78]: Setting new mute state: 0 Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.217 [32577.32577] INFO AudioStreamManager: [0x167acd0]: Setting new audio download buffer size: 1048576 Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.217 [32577.32577] INFO QobuzConnect: [0x167b840]: Client initialized! Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.217 [32577.32577] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.230 [32577.32577] INFO LocalConfigManager: [0x167a9f8]: Starting Local Configuration server Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.230 [32577.32577] INFO SampleApp: Starting Local configuration server Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.231 [32577.32577] INFO SampleApp: Connected to UNIX socket client 0x1665818 Apr 11 13:06:31 volumio qobuz-connect[32577]: 20260411 13:06:31.352 [32577.32577] INFO SampleApp: Playback volume changed: 75 Apr 11 13:06:31 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:31 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:31 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:31.505+03:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Apr 11 13:06:31 volumio volumio[1254]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 11 13:06:31 volumio volumio[1254]: info: Sending Spotify command with payload to local API: /player/volume Apr 11 13:06:31 volumio go-librespot[1756]: time="2026-04-11T13:06:31+03:00" level=debug msg="update volume requested to 65535/65535" Apr 11 13:06:31 volumio mpd[32562]: 2026-04-11T13:06:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 13:06:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 13:06:31 volumio sudo[32523]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:31 volumio volumio[1254]: error: updateQueue error: null Apr 11 13:06:32 volumio go-librespot[1756]: time="2026-04-11T13:06:32+03:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 11 13:06:32 volumio go-librespot[1756]: time="2026-04-11T13:06:32+03:00" level=trace msg="emitting websocket event: volume" Apr 11 13:06:32 volumio volumio[1254]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 11 13:06:32 volumio volumio[1254]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 11 13:06:33 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:33 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:33 volumio volumio[1254]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:33 volumio volumio[1254]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:33 volumio sudo[32594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 11 13:06:33 volumio sudo[32594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:33 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 11 13:06:33 volumio sudo[32594]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:33 volumio volumio[1254]: info: Executing endpoint tc_getconfig Apr 11 13:06:33 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 11 13:06:33 volumio vtcs[32597]: STARTING TidalConnect services, version: 1.6.1 Apr 11 13:06:33 volumio vtcs[32597]: STARTED TidalConnect services. Apr 11 13:06:33 volumio volumio[1254]: info: Executing endpoint tc_connect Apr 11 13:06:33 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 11 13:06:33 volumio volumio[1254]: info: Connecting to TidalConnect Apr 11 13:06:33 volumio volumio[1254]: info: CoreCommandRouter::servicePushState Apr 11 13:06:33 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:33 volumio volumio[1254]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Apr 11 13:06:33 volumio volumio[1254]: info: CoreCommandRouter::servicePushState Apr 11 13:06:33 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:33 volumio volumio[1254]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Apr 11 13:06:33 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:33 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:33 volumio volumio[1254]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:33 volumio volumio[1254]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:33 volumio sudo[32622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 11 13:06:33 volumio sudo[32622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:33 volumio sudo[32622]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:33 volumio volumio[1254]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 11 13:06:33 volumio volumio[1254]: info: CoreStateMachine::getcurrentVolume Apr 11 13:06:33 volumio volumio[1254]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 13:06:34 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:34 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:34 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:34 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:06:34 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:34 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:34 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:34 volumio volumio[1254]: info: CoreStateMachine::updateTrackBlock Apr 11 13:06:34 volumio volumio[1254]: info: CorePlayQueue::getTrackBlock Apr 11 13:06:34 volumio volumio[1254]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 13:06:34 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:34 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:34.038+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=70656 volume=100 Apr 11 13:06:34 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:34.039+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:34 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:34 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:34 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:34 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:34 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:34 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:34 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:34.084+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=70656 volume=100 Apr 11 13:06:34 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:34.084+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:34 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:34 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:34.814+03:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Apr 11 13:06:36 volumio volumio[1254]: info: TidalConnect service started! Apr 11 13:06:36 volumio volumio[1254]: info: TidalConnect service started! Apr 11 13:06:39 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:39.151+03:00 level=INFO msg="new address was allocated" component=ble/conn old=5 new=6 Apr 11 13:06:41 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:41.537+03:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=4 chunks=1 index=0 tries=11 Apr 11 13:06:49 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:49 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:49 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:49 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:50 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 13:06:51 volumio volumio[1254]: info: Received Get System Info Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 13:06:51 volumio volumio[1254]: info: Discovery: Getting this device information Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:51 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 13:06:51 volumio volumio[1254]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 11 13:06:51 volumio volumio[1254]: info: Preparing to save Alsa Options, stopping services first Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:51 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::volumioPause Apr 11 13:06:51 volumio volumio[1254]: info: CoreStateMachine::pause Apr 11 13:06:51 volumio volumio[1254]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Mojo"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:51 volumio volumio[1254]: info: Setting mixer PCM for card Mojo Apr 11 13:06:51 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:51 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:51 volumio vtcs[32597]: [2026-04-11 13:06:51.743] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected Apr 11 13:06:51 volumio vtcs[32597]: [2026-04-11 13:06:51.744] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Apr 11 13:06:51 volumio sudo[32677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:51 volumio sudo[32677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 13:06:51 volumio volumio[1254]: info: Updating Volume Controller Parameters: Device: 5 Name: Mojo Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 11 13:06:51 volumio volumio[1254]: info: Disabling external Volume Control Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:51 volumio volumio[1254]: info: Preparing to generate the ALSA configuration file Apr 11 13:06:51 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Apr 11 13:06:51 volumio systemd[1]: vtcs.service: Killing process 32602 (vtcs) with signal SIGKILL. Apr 11 13:06:51 volumio systemd[1]: vtcs.service: Deactivated successfully. Apr 11 13:06:51 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Apr 11 13:06:51 volumio sudo[32677]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:51 volumio sudo[32686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:51 volumio sudo[32686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:51 volumio sudo[32693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:51 volumio sudo[32693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:51 volumio sudo[32686]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:51 volumio sudo[32693]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:51 volumio sudo[32700]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:51 volumio sudo[32700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:51 volumio volumio[1254]: info: Asound.conf file unchanged, so no further update is needed Apr 11 13:06:51 volumio volumio[1254]: info: Output device has changed, restarting MPD Apr 11 13:06:51 volumio qobuz-connect[32577]: 20260411 13:06:51.936 [32577.32577] INFO SampleApp: Stopping Local configuration server Apr 11 13:06:51 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:51 volumio volumio[1254]: info: Output device has changed, restarting Shairport Sync Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:51 volumio sudo[32706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 13:06:51 volumio sudo[32706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:51 volumio sudo[32706]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:51 volumio sudo[32708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 13:06:51 volumio sudo[32708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:51 volumio volumio[1254]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 13:06:51 volumio volumio[1254]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:51 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:51 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:51 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:52 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 13:06:52 volumio sudo[32718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:52 volumio sudo[32718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio sudo[32720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:52 volumio sudo[32720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 13:06:52 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 13:06:52 volumio systemd[1]: mpd.service: Consumed 1.448s CPU time. Apr 11 13:06:52 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 13:06:52 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 13:06:52 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 13:06:52 volumio sudo[32728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:52 volumio sudo[32728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio volumio[1254]: info: MPD Permissions set Apr 11 13:06:52 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:52 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:52.085+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=88851 volume=100 Apr 11 13:06:52 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:52.085+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:52 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:52 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 13:06:52 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 13:06:52 volumio volumio[1254]: info: Starting Shairport Sync Apr 11 13:06:52 volumio sudo[32738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 13:06:52 volumio sudo[32738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio sudo[32718]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio sudo[32728]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 13:06:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 13:06:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:52 volumio systemd[1]: shairport-sync.service: Consumed 1.607s CPU time. Apr 11 13:06:52 volumio sudo[32740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:52 volumio sudo[32740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio sudo[32720]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio sudo[32736]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 13:06:52 volumio sudo[32736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 13:06:52 volumio sudo[32736]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:52 volumio sudo[32738]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio volumio[1254]: info: Shairport-Sync Started Apr 11 13:06:52 volumio volumio[1254]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 11 13:06:52 volumio volumio[1254]: info: Preparing to save Alsa Options, stopping services first Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioPause Apr 11 13:06:52 volumio volumio[1254]: info: CoreStateMachine::pause Apr 11 13:06:52 volumio volumio[1254]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Mojo"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:52 volumio volumio[1254]: info: Setting mixer PCM for card Mojo Apr 11 13:06:52 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:52 volumio sudo[304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:52 volumio sudo[304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 13:06:52 volumio volumio[1254]: info: Updating Volume Controller Parameters: Device: 5 Name: Mojo Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 11 13:06:52 volumio volumio[1254]: info: Disabling external Volume Control Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:52 volumio volumio[1254]: info: Preparing to generate the ALSA configuration file Apr 11 13:06:52 volumio sudo[304]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio sudo[313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:52 volumio sudo[313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio volumio[1254]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 11 13:06:52 volumio volumio[1254]: info: Preparing to save Alsa Options, stopping services first Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioPause Apr 11 13:06:52 volumio volumio[1254]: info: CoreStateMachine::pause Apr 11 13:06:52 volumio volumio[1254]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Mojo"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:52 volumio sudo[319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:52 volumio sudo[319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio sudo[313]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:52 volumio sudo[319]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:52 volumio sudo[330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:52 volumio sudo[330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:52 volumio volumio[1254]: info: Setting mixer PCM for card Mojo Apr 11 13:06:52 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:52 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:52 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio sudo[334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:53 volumio sudo[334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 13:06:53 volumio volumio[1254]: info: Updating Volume Controller Parameters: Device: 5 Name: Mojo Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 11 13:06:53 volumio volumio[1254]: info: Disabling external Volume Control Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:53 volumio sudo[334]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:53 volumio sudo[343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio volumio[1254]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 11 13:06:53 volumio volumio[1254]: info: Preparing to save Alsa Options, stopping services first Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioPause Apr 11 13:06:53 volumio volumio[1254]: info: CoreStateMachine::pause Apr 11 13:06:53 volumio volumio[1254]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Mojo"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:53 volumio sudo[351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:53 volumio sudo[351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio qobuz-connect[32577]: 20260411 13:06:53.261 [32577.32577] INFO SampleApp: shat down connection on UNIX socket Apr 11 13:06:53 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 11 13:06:53 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:53 volumio volumio[1254]: info: Setting mixer PCM for card Mojo Apr 11 13:06:53 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio sudo[343]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 13:06:53 volumio volumio[1254]: info: Updating Volume Controller Parameters: Device: 5 Name: Mojo Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 11 13:06:53 volumio volumio[1254]: info: Disabling external Volume Control Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:53 volumio sudo[364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:53 volumio sudo[364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio volumio[1254]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 11 13:06:53 volumio volumio[1254]: info: Preparing to save Alsa Options, stopping services first Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioPause Apr 11 13:06:53 volumio volumio[1254]: info: CoreStateMachine::pause Apr 11 13:06:53 volumio volumio[1254]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Mojo"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:53 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:53 volumio sudo[330]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[32740]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[32700]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:53 volumio sudo[351]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio volumio[1254]: info: Setting mixer PCM for card Mojo Apr 11 13:06:53 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio sudo[364]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:53 volumio sudo[383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 11 13:06:53 volumio volumio[1254]: info: Updating Volume Controller Parameters: Device: 5 Name: Mojo Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 11 13:06:53 volumio volumio[1254]: info: Disabling external Volume Control Apr 11 13:06:53 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:53 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 11 13:06:53 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 13:06:53 volumio sudo[390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:53 volumio sudo[390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio sudo[395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:53 volumio sudo[395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:53 volumio sudo[383]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:53 volumio sudo[397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio sudo[390]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[395]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[406]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:53 volumio sudo[406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio sudo[406]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio sudo[397]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio volumio[1254]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Apr 11 13:06:53 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:53 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:53 volumio sudo[413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:53 volumio sudo[413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio sudo[420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:53 volumio sudo[420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:53 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:53.913+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=90616 volume=100 Apr 11 13:06:53 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:53.914+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:53 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:53 volumio sudo[413]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:53 volumio volumio[1254]: info: Executing endpoint qc_getconfig Apr 11 13:06:53 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 13:06:53 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:53 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 11 13:06:53 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:53 volumio sudo[424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:53 volumio sudo[424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:54 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:54 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio sudo[420]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:54.040+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=90616 volume=100 Apr 11 13:06:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:54.040+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:54 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:54 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:54 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:54 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 11 13:06:54 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:54.059+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=90616 volume=100 Apr 11 13:06:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:54.059+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:54 volumio volumio[1254]: info: VolumeController:: Volume=100 Mute =false Apr 11 13:06:54 volumio volumio[1254]: info: CoreStateMachine::pushState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioPushState Apr 11 13:06:54 volumio sudo[424]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:54.085+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" state=STATUS_STOPPED positionMs=90616 volume=100 Apr 11 13:06:54 volumio volumio5-onboarding[1633]: time=2026-04-11T13:06:54.085+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.102:39620,00:00:00:00:00:00%05 @ 0x1ccc7b0" id=spotify:track:3HFsuWqaZwKCTFAe9qEyEm title="Find My Way" Apr 11 13:06:54 volumio mpd[32746]: 2026-04-11T13:06:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 11 13:06:54 volumio sudo[32708]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:54 volumio volumio[1254]: info: Asound.conf file unchanged, so no further update is needed Apr 11 13:06:54 volumio volumio[1254]: info: Output device has changed, restarting MPD Apr 11 13:06:54 volumio volumio[1254]: info: Output device has changed, restarting Shairport Sync Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio sudo[442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 13:06:54 volumio sudo[442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio sudo[442]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio sudo[444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 13:06:54 volumio sudo[444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio volumio[1254]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 13:06:54 volumio volumio[1254]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 11 13:06:54 volumio volumio[1254]: info: Preparing to generate the ALSA configuration file Apr 11 13:06:54 volumio sudo[454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:54 volumio sudo[454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 13:06:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 13:06:54 volumio systemd[1]: mpd.service: Consumed 1.843s CPU time. Apr 11 13:06:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 13:06:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 13:06:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 13:06:54 volumio sudo[458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:54 volumio sudo[458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio sudo[465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:54 volumio sudo[465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:54 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:54 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:54 volumio volumio[1254]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 11 13:06:54 volumio volumio[1254]: info: Executing endpoint qc_getconfig Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 13:06:54 volumio sudo[465]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio sudo[478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:54 volumio sudo[478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio sudo[458]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:54 volumio sudo[454]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:54 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Apr 11 13:06:54 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:54 volumio sudo[474]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 13:06:54 volumio sudo[474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 13:06:54 volumio sudo[474]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 13:06:54 volumio volumio[1254]: info: MPD Permissions set Apr 11 13:06:54 volumio sudo[478]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 13:06:54 volumio volumio[1254]: info: Executing endpoint qc_getconfig Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 13:06:54 volumio volumio[1254]: info: Executing endpoint qc_getconfig Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.795 [490.490] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.800 [490.490] INFO VolumeManager: [0x1100f78]: Setting new playback volume: 75 Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.800 [490.490] INFO VolumeManager: [0x1100f78]: Setting new mute state: 0 Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.801 [490.490] INFO AudioStreamManager: [0x1100cd0]: Setting new audio download buffer size: 1048576 Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.801 [490.490] INFO QobuzConnect: [0x1101840]: Client initialized! Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.801 [490.490] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.817 [490.490] INFO LocalConfigManager: [0x11009f8]: Starting Local Configuration server Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.818 [490.490] INFO SampleApp: Starting Local configuration server Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.819 [490.490] INFO SampleApp: Connected to UNIX socket client 0x10eb818 Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: Asound.conf file unchanged, so no further update is needed Apr 11 13:06:54 volumio volumio[1254]: info: Output device has changed, restarting MPD Apr 11 13:06:54 volumio volumio[1254]: info: Output device has changed, restarting Shairport Sync Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:54 volumio sudo[513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 13:06:54 volumio sudo[513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio sudo[513]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:54 volumio sudo[515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 13:06:54 volumio volumio[1254]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 13:06:54 volumio volumio[1254]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:54 volumio sudo[515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:54 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:54 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:54 volumio qobuz-connect[490]: 20260411 13:06:54.945 [490.490] INFO SampleApp: Playback volume changed: 75 Apr 11 13:06:54 volumio volumio[1254]: info: Preparing to generate the ALSA configuration file Apr 11 13:06:54 volumio sudo[534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:54 volumio sudo[534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:54 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 13:06:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 13:06:55 volumio sudo[539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:55 volumio sudo[539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 13:06:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 13:06:55 volumio volumio[1254]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 11 13:06:55 volumio volumio[1254]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 11 13:06:55 volumio volumio[1254]: info: MPD Permissions set Apr 11 13:06:55 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:55 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:55 volumio volumio[1254]: error: MPD error: Error: read ECONNRESET Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:55 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:55 volumio volumio[1254]: info: Starting Shairport Sync Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio sudo[546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:55 volumio sudo[546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 13:06:55 volumio sudo[551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 13:06:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: Asound.conf file unchanged, so no further update is needed Apr 11 13:06:55 volumio volumio[1254]: info: Output device has changed, restarting MPD Apr 11 13:06:55 volumio volumio[1254]: info: Output device has changed, restarting Shairport Sync Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 13:06:55 volumio sudo[565]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 13:06:55 volumio sudo[565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[546]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:55 volumio systemd[1]: shairport-sync.service: Consumed 1.412s CPU time. Apr 11 13:06:55 volumio volumio[1254]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 13:06:55 volumio volumio[1254]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:55 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:55 volumio sudo[561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 13:06:55 volumio sudo[561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[534]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio sudo[561]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio volumio[1254]: info: Preparing to generate the ALSA configuration file Apr 11 13:06:55 volumio sudo[569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:55 volumio sudo[569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:55 volumio sudo[574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:55 volumio sudo[559]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 13:06:55 volumio sudo[578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 13:06:55 volumio sudo[559]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio volumio[1254]: info: MPD Permissions set Apr 11 13:06:55 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:55 volumio volumio[1254]: info: TidalConnect service stoped! Apr 11 13:06:55 volumio sudo[588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:55 volumio sudo[588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:55 volumio volumio[1254]: info: Starting Shairport Sync Apr 11 13:06:55 volumio sudo[551]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio sudo[600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 13:06:55 volumio sudo[600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[539]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio volumio[1254]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:55 volumio volumio[1254]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: Asound.conf file unchanged, so no further update is needed Apr 11 13:06:55 volumio volumio[1254]: info: Output device has changed, restarting MPD Apr 11 13:06:55 volumio volumio[1254]: info: Output device has changed, restarting Shairport Sync Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:55 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Apr 11 13:06:55 volumio qobuz-connect[490]: 20260411 13:06:55.432 [490.490] INFO SampleApp: Stopping Local configuration server Apr 11 13:06:55 volumio sudo[588]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 13:06:55 volumio sudo[628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 13:06:55 volumio sudo[631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 13:06:55 volumio sudo[628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio volumio[1254]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 13:06:55 volumio volumio[1254]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio sudo[628]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio sudo[578]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio sudo[633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:55 volumio sudo[633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio volumio[1254]: info: QobuzConnect: setDeactiveState invoked Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::volumioGetState Apr 11 13:06:55 volumio volumio[1254]: info: CorePlayQueue::getTrack 14 Apr 11 13:06:55 volumio sudo[574]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 13:06:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 13:06:55 volumio sudo[644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:55 volumio sudo[644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 13:06:55 volumio sudo[646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio volumio[1254]: info: Shairport-Sync Started Apr 11 13:06:55 volumio volumio[1254]: info: MPD Permissions set Apr 11 13:06:55 volumio volumio[1254]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:55 volumio volumio[1254]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 11 13:06:55 volumio sudo[655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 13:06:55 volumio sudo[655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio volumio[1254]: info: Starting Shairport Sync Apr 11 13:06:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 13:06:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 13:06:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 13:06:55 volumio sudo[660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 11 13:06:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio sudo[660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 13:06:55 volumio go-librespot[1756]: time="2026-04-11T13:06:55+03:00" level=trace msg="sent dealer ping" Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio sudo[663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 13:06:55 volumio volumio[1254]: info: Starting Shairport Sync Apr 11 13:06:55 volumio go-librespot[1756]: time="2026-04-11T13:06:55+03:00" level=trace msg="received dealer pong" Apr 11 13:06:55 volumio sudo[667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 11 13:06:55 volumio sudo[667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio sudo[646]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio volumio[1254]: error: Error starting TidalConnect Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Apr 11 13:06:55 volumio volumio[1254]: Job for vtcs.service canceled. Apr 11 13:06:55 volumio volumio[1254]: {"cmd":"/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3","code":1,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3\nJob for vtcs.service canceled.\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at ChildProcess._handle.onexit (node:internal/child_process:305:5)","stderr":"Job for vtcs.service canceled.\n","stdout":""} Apr 11 13:06:55 volumio sudo[678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 13:06:55 volumio sudo[678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 11 13:06:55 volumio volumio[1254]: info: CoreStateMachine::getcurrentVolume Apr 11 13:06:55 volumio volumio[1254]: info: CoreCommandRouter::volumioRetrievevolume Apr 11 13:06:55 volumio sudo[600]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 11 13:06:55 volumio volumio[1254]: info: Shairport-Sync Started Apr 11 13:06:55 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 11 13:06:55 volumio sudo[644]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio sudo[663]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio volumio[1254]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 13:06:55 volumio sudo[660]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio sudo[655]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio volumio[1254]: Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Apr 11 13:06:55 volumio volumio[1254]: Job for vtcs.service canceled. Apr 11 13:06:55 volumio volumio[1254]: at ChildProcess.exithandler (node:child_process:421:12) Apr 11 13:06:55 volumio volumio[1254]: at ChildProcess.emit (node:events:514:28) Apr 11 13:06:55 volumio volumio[1254]: at maybeClose (node:internal/child_process:1105:16) Apr 11 13:06:55 volumio volumio[1254]: at Socket. (node:internal/child_process:457:11) Apr 11 13:06:55 volumio volumio[1254]: at Socket.emit (node:events:514:28) Apr 11 13:06:55 volumio volumio[1254]: at Pipe. (node:net:337:12) { Apr 11 13:06:55 volumio volumio[1254]: code: 1, Apr 11 13:06:55 volumio volumio[1254]: killed: false, Apr 11 13:06:55 volumio volumio[1254]: signal: null, Apr 11 13:06:55 volumio volumio[1254]: cmd: '/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3', Apr 11 13:06:55 volumio volumio[1254]: stdout: '', Apr 11 13:06:55 volumio volumio[1254]: stderr: 'Job for vtcs.service canceled.\n' Apr 11 13:06:55 volumio volumio[1254]: } Apr 11 13:06:55 volumio volumio[1254]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 13:06:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 11 13:06:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 11 13:06:55 volumio sudo[715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 13:06:55 volumio sudo[715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 13:06:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 13:06:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 13:06:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 13:06:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 13:06:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:55 volumio sudo[667]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 13:06:55 volumio sudo[678]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:56 volumio sudo[729]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 13:06:56 volumio sudo[729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 13:06:56 volumio sudo[729]: pam_unix(sudo:session): session closed for user root Apr 11 13:06:56 volumio sudo[755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 13:05' Apr 11 13:06:56 volumio sudo[755]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"