Mar 26 10:41:02 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 8 Mar 26 10:41:02 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 8 Mar 26 10:41:02 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 9 Mar 26 10:41:02 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:02 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:02 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 26 10:41:02 volumio volumio[1318]: info: CoreCommandRouter::volumioGetQueue Mar 26 10:41:02 volumio volumio[1318]: info: CoreStateMachine::getQueue Mar 26 10:41:02 volumio volumio[1318]: info: CorePlayQueue::getQueue Mar 26 10:41:02 volumio volumio[1318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 9 Mar 26 10:41:02 volumio squeezeboxserver[2169]: [10:41:02.849] mDNSsearchCallback:688 [0x195a88]: changed ip:port 192.168.219.105:5000 Mar 26 10:41:09 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:09.879+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.219.119:41418 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.073+09:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.219.119:41418 @ 0x162c030" latency=-756.865903ms platform=PLATFORM_ANDROID version=5.260209.0 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.073+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.219.119:41418 @ 0x162c030" latency=-757.25636ms timeout=10s Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.073+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" Mar 26 10:41:11 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:11 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.075+09:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" name=Volumio Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.075+09:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" language=ko Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.077+09:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" timezone=Asia/Seoul Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.077+09:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" available=true connected=true macAddress=2c:cf:67:11:02:18 ip4Address=192.168.219.105/24 ip6Address= Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.078+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.078+09:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" setupComplete=true Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 26 10:41:11 volumio volumio[1318]: amixer -c 0 info | grep "vc4-hdmi-0" Mar 26 10:41:11 volumio volumio[1318]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Mar 26 10:41:11 volumio volumio[1318]: amixer -c 1 info | grep "vc4-hdmi-1" Mar 26 10:41:11 volumio volumio[1318]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Mar 26 10:41:11 volumio volumio[1318]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Mar 26 10:41:11 volumio volumio[1318]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 26 10:41:11 volumio volumio[1318]: {"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)"} Mar 26 10:41:11 volumio volumio[1318]: amixer -c 5 info | grep "X70DAC-MQA" Mar 26 10:41:11 volumio volumio[1318]: Card sysdefault:5 'X70DACMQA'/'Jineung Elecom X70DAC-MQA at usb-xhci-hcd.0-1, high speed' Mar 26 10:41:11 volumio volumio[1318]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Mar 26 10:41:11 volumio volumio[1318]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 26 10:41:11 volumio volumio[1318]: {"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)"} Mar 26 10:41:11 volumio volumio[1318]: amixer -c 5 info | grep "X70DAC-MQA" Mar 26 10:41:11 volumio volumio[1318]: Card sysdefault:5 'X70DACMQA'/'Jineung Elecom X70DAC-MQA at usb-xhci-hcd.0-1, high speed' Mar 26 10:41:11 volumio volumio[1318]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 7 Mar 26 10:41:11 volumio volumio[1318]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 26 10:41:11 volumio volumio[1318]: {"cmd":"/usr/local/bin/alsacap -C 7","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 7\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)"} Mar 26 10:41:11 volumio volumio[1318]: amixer -c 7 info | grep "Dummy" Mar 26 10:41:11 volumio sshd[5141]: pam_unix(sshd:session): session closed for user volumio Mar 26 10:41:11 volumio volumio[1318]: Card sysdefault:7 'Dummy'/'Dummy 1' Mar 26 10:41:11 volumio volumio[1318]: Mixer name : 'Dummy Mixer' Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.150+09:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" selectedOutputId=5 Mar 26 10:41:11 volumio systemd[1]: session-1.scope: Deactivated successfully. Mar 26 10:41:11 volumio systemd-logind[1023]: Session 1 logged out. Waiting for processes to exit. Mar 26 10:41:11 volumio systemd-logind[1023]: Removed session 1. Mar 26 10:41:11 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:11 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.192+09:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" currentVersion=4.103 latestVersion=4.103 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.192+09:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.219.119:41418 @ 0x162c030" status=UPDATE_STATUS_NONE progress=0 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.192+09:00 level=INFO msg="emitting user changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" userId= Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.192+09:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" providers=3 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.192+09:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" plugins=62 Mar 26 10:41:11 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.195+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PLAYING positionMs=272308 volume=100 Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.195+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:11.237+09:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.219.119:41418 @ 0x162c030" latency=-756.890625ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 26 10:41:11 volumio sudo[5343]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 26 10:41:11 volumio sudo[5343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 10:41:11 volumio sudo[5343]: pam_unix(sudo:session): session closed for user root Mar 26 10:41:11 volumio sudo[5345]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 26 10:41:11 volumio sudo[5345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 10:41:11 volumio sudo[5345]: pam_unix(sudo:session): session closed for user root Mar 26 10:41:11 volumio volumio[1318]: verbose: New Socket.io Connection to 192.168.219.105 from 192.168.219.119 UA: Mozilla/5.0 (Linux; Android 15; TB375FC Build/AP3A.240905.015; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/141.0.7390.122 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Mar 26 10:41:11 volumio sudo[5349]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 26 10:41:11 volumio sudo[5349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 10:41:11 volumio sudo[5349]: pam_unix(sudo:session): session closed for user root Mar 26 10:41:11 volumio sudo[5351]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 26 10:41:11 volumio sudo[5351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 10:41:11 volumio sudo[5351]: pam_unix(sudo:session): session closed for user root Mar 26 10:41:11 volumio volumio[1318]: verbose: New Socket.io Connection to 192.168.219.105 from 192.168.219.119 UA: Mozilla/5.0 (Linux; Android 15; TB375FC Build/AP3A.240905.015; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/141.0.7390.122 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::volumioGetVisibleSources Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 26 10:41:12 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:12 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:12 volumio volumio[1318]: info: Listing playlists Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 26 10:41:12 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 10:41:13 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:13 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:13 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:13 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 10:41:14 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 10:41:14 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 10:41:16 volumio volumio[1318]: info: Enabling plugin dark_ascendants Mar 26 10:41:16 volumio volumio[1318]: info: Loading plugin "dark_ascendants"... Mar 26 10:41:16 volumio volumio[1318]: info: PLUGIN START: dark_ascendants Mar 26 10:41:16 volumio volumio[1318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 26 10:41:16 volumio volumio[1318]: info: [1774489276551] CoreMusicLibrary::Adding element Dark Ascendants Mar 26 10:41:16 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 10:41:16 volumio volumio[1318]: Cannot find translation for source 스트리밍 라디오 Mar 26 10:41:16 volumio volumio[1318]: Cannot find translation for source Dark Ascendants Mar 26 10:41:16 volumio volumio[1318]: info: Done. Mar 26 10:41:16 volumio volumio[1318]: info: [DarkAscendants] Token restored (refreshed) Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 10:41:17 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:17 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:17 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 10:41:17 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:17 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:17 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:17 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:18 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 10:41:18 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:18 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:18 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:18 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:18 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:18 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:18 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:19 volumio volumio[1318]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 26 10:41:21 volumio systemd[1]: Stopping user@1000.service - User Manager for UID 1000... Mar 26 10:41:21 volumio systemd[5144]: Activating special unit exit.target... Mar 26 10:41:21 volumio systemd[5144]: Stopped target default.target - Main User Target. Mar 26 10:41:21 volumio systemd[5144]: Stopping mpris-proxy.service - Bluetooth mpris proxy... Mar 26 10:41:21 volumio mpris-proxy[5161]: org.bluez appeared Mar 26 10:41:21 volumio mpris-proxy[5161]: Bluetooth Adapter /org/bluez/hci0 found Mar 26 10:41:21 volumio mpris-proxy[5161]: Bluetooth Adapter /org/bluez/hci0 removed Mar 26 10:41:21 volumio mpris-proxy[5161]: org.bluez disappeared Mar 26 10:41:21 volumio systemd[5144]: Stopped mpris-proxy.service - Bluetooth mpris proxy. Mar 26 10:41:21 volumio systemd[5144]: Stopping dbus.service - D-Bus User Message Bus... Mar 26 10:41:21 volumio systemd[5144]: Stopped dbus.service - D-Bus User Message Bus. Mar 26 10:41:21 volumio systemd[5144]: Removed slice session.slice - User Core Session Slice. Mar 26 10:41:21 volumio systemd[5144]: Stopped target basic.target - Basic System. Mar 26 10:41:21 volumio systemd[5144]: Stopped target paths.target - Paths. Mar 26 10:41:21 volumio systemd[5144]: Stopped target sockets.target - Sockets. Mar 26 10:41:21 volumio systemd[5144]: Stopped target timers.target - Timers. Mar 26 10:41:21 volumio systemd[5144]: Closed dbus.socket - D-Bus User Message Bus Socket. Mar 26 10:41:21 volumio systemd[5144]: Closed dirmngr.socket - GnuPG network certificate management daemon. Mar 26 10:41:21 volumio systemd[5144]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Mar 26 10:41:21 volumio systemd[5144]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Mar 26 10:41:21 volumio systemd[5144]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Mar 26 10:41:21 volumio systemd[5144]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Mar 26 10:41:21 volumio systemd[5144]: Removed slice app.slice - User Application Slice. Mar 26 10:41:21 volumio systemd[5144]: Reached target shutdown.target - Shutdown. Mar 26 10:41:21 volumio systemd[5144]: Finished systemd-exit.service - Exit the Session. Mar 26 10:41:21 volumio systemd[5144]: Reached target exit.target - Exit the Session. Mar 26 10:41:21 volumio systemd[1]: user@1000.service: Deactivated successfully. Mar 26 10:41:21 volumio systemd[1]: Stopped user@1000.service - User Manager for UID 1000. Mar 26 10:41:21 volumio systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Mar 26 10:41:21 volumio systemd[1]: run-user-1000.mount: Deactivated successfully. Mar 26 10:41:21 volumio systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. Mar 26 10:41:21 volumio systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Mar 26 10:41:21 volumio systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. Mar 26 10:41:21 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 26 10:41:23 volumio volumio[1318]: info: CALLMETHOD: music_service dark_ascendants saveMonochromeSettings [object Object] Mar 26 10:41:23 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , saveMonochromeSettings Mar 26 10:41:24 volumio volumio[1318]: info: [DarkAscendants] Monochrome Connected: https://eu-central.monochrome.tf Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::servicePause Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePause Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pause Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand pause Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand pause took 5 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: Mar 26 10:41:27 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:41:27 volumio volumio[1318]: info: Mar 26 10:41:27 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:41:27 volumio volumio[1318]: info: Mar 26 10:41:27 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:41:27 volumio volumio[1318]: info: Mar 26 10:41:27 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:41:27 volumio volumio[1318]: info: Mar 26 10:41:27 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:41:27 volumio volumio[1318]: info: Mar 26 10:41:27 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand status took 2 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:41:27 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":289017,"duration":335,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:41:27 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState stateService pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":289017,"duration":335,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:41:27 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState stateService pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":289017,"duration":335,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:41:27 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState stateService pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":289017,"duration":335,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:41:27 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState stateService pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":289017,"duration":335,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:41:27 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState stateService pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":289017,"duration":335,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"575 Kbps","isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:41:27 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState stateService pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus pause Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:41:27 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:27 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:41:27 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.938+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PAUSED positionMs=289074 volume=100 Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.938+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.938+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PAUSED positionMs=289074 volume=100 Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.939+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PAUSED positionMs=289074 volume=100 Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.939+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.939+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.939+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PAUSED positionMs=289074 volume=100 Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.940+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.940+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PAUSED positionMs=289074 volume=100 Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.940+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.941+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PAUSED positionMs=289074 volume=100 Mar 26 10:41:27 volumio volumio5-onboarding[3177]: time=2026-03-26T10:41:27.941+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:41:27 volumio volumio[1318]: info: ------------------------------ 40ms Mar 26 10:41:27 volumio volumio[1318]: info: ------------------------------ 39ms Mar 26 10:41:27 volumio volumio[1318]: info: ------------------------------ 39ms Mar 26 10:41:27 volumio volumio[1318]: info: ------------------------------ 39ms Mar 26 10:41:27 volumio volumio[1318]: info: ------------------------------ 39ms Mar 26 10:41:27 volumio volumio[1318]: info: ------------------------------ 38ms Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: Starting persist timer - 30s Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: Starting persist timer - 30s Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: Starting persist timer - 30s Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: Starting persist timer - 30s Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: Starting persist timer - 30s Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Mar 26 10:41:27 volumio volumio[1318]: info: peppy_screensaver: Starting persist timer - 30s Mar 26 10:41:27 volumio volumio[1318]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 26 10:41:28 volumio volumio[1318]: info: CoreCommandRouter::volumioGetQueue Mar 26 10:41:28 volumio volumio[1318]: info: CoreStateMachine::getQueue Mar 26 10:41:28 volumio volumio[1318]: info: CorePlayQueue::getQueue Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 26 10:41:31 volumio volumio[1318]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 26 10:41:31 volumio volumio[1318]: info: Received Get System Version Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 10:41:31 volumio volumio[1318]: info: Received Get System Info Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 10:41:31 volumio volumio[1318]: info: Discovery: Getting this device information Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState Mar 26 10:41:31 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 10:41:31 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri Mar 26 10:41:31 volumio volumio[1318]: info: [DarkAscendants] handleBrowseUri: darkascendants Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/117059394 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/211935293 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/74974163 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/13495889 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/338126394 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/154206934 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/104148239 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/358672898 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/70095873 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/340542859 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/8255766 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/338126382 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/52027341 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/195928415 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/117059389 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/70095891 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/280980527 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/106901363 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/83754016 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/338126381 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/106901357 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/196384590 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/108385387 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/83334128 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/130587210 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/407105204 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/81718512 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/68714352 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/53319608 Mar 26 10:41:32 volumio volumio[1318]: info: Preloading song: darkascendants/track/198444763 Mar 26 10:41:32 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:41:36 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri Mar 26 10:41:36 volumio volumio[1318]: info: [DarkAscendants] handleBrowseUri: darkascendants/playlists Mar 26 10:41:47 volumio squeezeboxserver[2169]: [10:41:47.857] mDNSsearchCallback:688 [0x195a88]: changed ip:port 172.17.0.1:5000 Mar 26 10:41:57 volumio volumio[1318]: info: peppy_screensaver: Persist timer expired - stopping PeppyMeter Mar 26 10:41:58 volumio volumio[1318]: info: peppy_screensaver: Start PeppyMeter Mar 26 10:42:05 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:42:05 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:42:08 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri Mar 26 10:42:08 volumio volumio[1318]: info: [DarkAscendants] handleBrowseUri: darkascendants/playlist/c0b6aa4f-17c0-4ec5-80b2-9002da8137a1 Mar 26 10:42:09 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/1656141 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/77623374 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/315163624 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/1713342 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/77623370 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/252778005 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/77637380 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/2113600 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/4508198 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/315163629 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/470140352 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/77623769 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/77623372 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/502876048 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/111068098 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/84779515 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/241359377 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/465647774 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/502834131 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/52280271 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/100508619 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/132184648 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/71035926 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/44620214 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/179642559 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/489904979 Mar 26 10:42:09 volumio volumio[1318]: info: Preloading song: darkascendants/track/310922199 Mar 26 10:42:09 volumio volumio[1318]: info: Exploding uri darkascendants/track/1656141 in service dark_ascendants Mar 26 10:42:09 volumio volumio[1318]: info: Exploding uri darkascendants/track/77623374 in service dark_ascendants Mar 26 10:42:09 volumio volumio[1318]: info: Exploding uri darkascendants/track/315163624 in service dark_ascendants Mar 26 10:42:09 volumio volumio[1318]: info: Exploding uri darkascendants/track/1713342 in service dark_ascendants Mar 26 10:42:09 volumio volumio[1318]: info: Exploding uri darkascendants/track/77623370 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/252778005 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/77637380 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/2113600 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/4508198 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/315163629 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/470140352 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/77623769 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/77623372 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/502876048 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/111068098 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/84779515 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/241359377 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/465647774 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/502834131 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/52280271 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/100508619 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/132184648 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/71035926 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/44620214 in service dark_ascendants Mar 26 10:42:10 volumio volumio[1318]: info: Exploding uri darkascendants/track/179642559 in service dark_ascendants Mar 26 10:42:11 volumio volumio[1318]: info: Exploding uri darkascendants/track/489904979 in service dark_ascendants Mar 26 10:42:11 volumio volumio[1318]: info: Exploding uri darkascendants/track/310922199 in service dark_ascendants Mar 26 10:42:11 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::ClearQueue Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::updateTrackBlock Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrackBlock Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::stPlaybackTimer Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::serviceStop Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::serviceStop Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::stop Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand stop Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::clearPlayQueue Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::saveQueue Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushQueue Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::addQueueItems Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::addQueueItems Mar 26 10:42:11 volumio volumio[1318]: info: Preload queue cleared Mar 26 10:42:11 volumio volumio[1318]: info: Adding Item to queue: darkascendants/playlist/c0b6aa4f-17c0-4ec5-80b2-9002da8137a1 Mar 26 10:42:11 volumio volumio[1318]: info: Exploding uri darkascendants/playlist/c0b6aa4f-17c0-4ec5-80b2-9002da8137a1 in service dark_ascendants Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.674+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.675+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id="music-library/USB/MQA/Chris Botti/2007 Italia/01. Italia.flac" title=Italia Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Mar 26 10:42:11 volumio volumio[1318]: info: Mar 26 10:42:11 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand stop took 10 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:11 volumio volumio[1318]: info: Mar 26 10:42:11 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:11 volumio volumio[1318]: info: Mar 26 10:42:11 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:11 volumio volumio[1318]: info: Mar 26 10:42:11 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:11 volumio volumio[1318]: info: Mar 26 10:42:11 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:11 volumio volumio[1318]: info: Mar 26 10:42:11 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand status took 2 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand status took 2 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand status took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand status took 0 milliseconds Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseState Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:42:11 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:42:11 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState stateService stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: No code Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:42:11 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState stateService stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: No code Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:42:11 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState stateService stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: No code Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:42:11 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState stateService stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: No code Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:42:11 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState stateService stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: No code Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: ControllerMpd::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Italia","artist":"Andrea Bocelli","album":"Italia","uri":"USB/MQA/Chris Botti/2007 Italia/01. Italia.flac","trackType":"flac"} Mar 26 10:42:11 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState stateService stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio[1318]: info: No code Mar 26 10:42:11 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:11 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:11 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.728+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.728+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.729+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.729+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.729+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.729+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.729+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.729+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.730+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.730+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.731+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.731+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.731+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.732+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.733+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.733+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.733+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.733+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.733+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.734+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.734+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.734+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.734+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.734+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.735+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.735+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.735+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.735+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_STOPPED positionMs=0 volume=100 Mar 26 10:42:11 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:11.735+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id= title= Mar 26 10:42:11 volumio volumio[1318]: info: ------------------------------ 90ms Mar 26 10:42:11 volumio volumio[1318]: info: ------------------------------ 90ms Mar 26 10:42:11 volumio volumio[1318]: info: ------------------------------ 90ms Mar 26 10:42:11 volumio volumio[1318]: info: ------------------------------ 90ms Mar 26 10:42:11 volumio volumio[1318]: info: ------------------------------ 90ms Mar 26 10:42:11 volumio volumio[1318]: info: ------------------------------ 91ms Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:11 volumio volumio[1318]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined Mar 26 10:42:12 volumio volumio[1318]: info: CoreCommandRouter::volumioPushQueue Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::saveQueue Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::updateTrackBlock Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrackBlock Mar 26 10:42:12 volumio volumio[1318]: info: CoreCommandRouter::volumioPlay Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::play index 0 Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::stop Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::play index undefined Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::startPlaybackTimer Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:12 volumio volumio[1318]: info: [DarkAscendants] clearAddPlayTrack quality=HI_RES_LOSSLESS useHiResProxy=true raw=true Mar 26 10:42:12 volumio volumio[1318]: info: [DarkAscendants] clearAddPlayTrack: darkascendants/track/1656141 Mar 26 10:42:12 volumio volumio[1318]: info: [TidalApi] getStreamUrl[HI_RES_LOSSLESS] trackId=1656141 audioQuality=LOSSLESS mimeType=application/vnd.tidal.bts encType=NONE api.bitDepth=16 api.sampleRate=44100 Mar 26 10:42:12 volumio volumio[1318]: info: [TidalApi] getStreamUrl OK(BTS): quality=LOSSLESS bitDepth=16 sampleRate=44100 bts.bitDepth=undefined bts.sampleRate=undefined Mar 26 10:42:12 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:12 volumio volumio[1318]: verbose: STATE SERVICE {"status":"play","service":"dark_ascendants","uri":"darkascendants/track/1656141","name":"Misty","title":"Misty","artist":"Bob Brookmeyer","album":"Bob Brookmeyer & Friends","albumart":"https://resources.tidal.com/images/ff65741f/a4e0/4442/8634/f4d960f569ef/750x750.jpg","duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2,"seek":0} Mar 26 10:42:12 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::syncState stateService play Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus stop Mar 26 10:42:12 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand stop Mar 26 10:42:12 volumio volumio[1318]: info: sendMpdCommand stop took 0 milliseconds Mar 26 10:42:12 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand clear Mar 26 10:42:12 volumio volumio[1318]: info: sendMpdCommand clear took 0 milliseconds Mar 26 10:42:12 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand add "https://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic5YzkzN2U2YTNkMzNiOTUzNzNkYzRlYWNjZjIzZDUwN182MS5tcDQ/0.flac?token=1774492932~YjQ0MzhlZjg1NzJhMjdkY2E5YmMzNTQxODAyMDZjMTU2M2UyNmZhNg==" Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: sendMpdCommand add "https://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic5YzkzN2U2YTNkMzNiOTUzNzNkYzRlYWNjZjIzZDUwN182MS5tcDQ/0.flac?token=1774492932~YjQ0MzhlZjg1NzJhMjdkY2E5YmMzNTQxODAyMDZjMTU2M2UyNmZhNg==" took 2 milliseconds Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 3ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 3ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 3ms Mar 26 10:42:12 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand play Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: Mar 26 10:42:12 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:12 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 3ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 3ms Mar 26 10:42:12 volumio volumio[1318]: info: sendMpdCommand play took 1 milliseconds Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 1ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 1ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 1ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 0ms Mar 26 10:42:12 volumio volumio[1318]: info: ------------------------------ 1ms Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:12 volumio volumio[1318]: info: CoreCommandRouter::servicePushState Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:12 volumio volumio[1318]: verbose: STATE SERVICE {"status":"play","service":"dark_ascendants","uri":"darkascendants/track/1656141","name":"Misty","title":"Misty","artist":"Bob Brookmeyer","album":"Bob Brookmeyer & Friends","albumart":"https://resources.tidal.com/images/ff65741f/a4e0/4442/8634/f4d960f569ef/750x750.jpg","duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2,"seek":0} Mar 26 10:42:12 volumio volumio[1318]: verbose: CURRENT POSITION 0 Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::syncState stateService play Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus play Mar 26 10:42:12 volumio volumio[1318]: info: Received an update from plugin. extracting info from payload Mar 26 10:42:12 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:12 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:12 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 10:42:12 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:13 volumio volumio[1318]: info: CoreStateMachine::pushState Mar 26 10:42:13 volumio volumio[1318]: info: CorePlayQueue::getTrack 0 Mar 26 10:42:13 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState Mar 26 10:42:13 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:13.003+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PLAYING positionMs=0 volume=100 Mar 26 10:42:13 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:13.003+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id=darkascendants/track/1656141 title=Misty Mar 26 10:42:13 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:13.004+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" state=STATUS_PLAYING positionMs=0 volume=100 Mar 26 10:42:13 volumio volumio5-onboarding[3177]: time=2026-03-26T10:42:13.004+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:41418 @ 0x162c030" id=darkascendants/track/1656141 title=Misty Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:13 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces system playlist update Mar 26 10:42:13 volumio volumio[1318]: info: Ignoring MPD Status Update Mar 26 10:42:13 volumio volumio[1318]: info: ------------------------------ 1ms Mar 26 10:42:13 volumio volumio[1318]: info: ------------------------------ 0ms Mar 26 10:42:13 volumio volumio[1318]: info: peppy_screensaver: pushState - status=play service=dark_ascendants volatile=false Mar 26 10:42:13 volumio volumio[1318]: info: peppy_screensaver: pushState - status=play service=dark_ascendants volatile=false Mar 26 10:42:13 volumio volumio[1318]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:13 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:13 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:13 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:13 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:13 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:13 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:13 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:13 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:13 volumio volumio[1318]: info: Mar 26 10:42:13 volumio volumio[1318]: ---------------------------- MPD announces state update: player Mar 26 10:42:13 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:13 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:13 volumio volumio[1318]: info: ControllerMpd::getState Mar 26 10:42:13 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status Mar 26 10:42:13 volumio volumio[1318]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 10:42:13 volumio volumio[1318]: TypeError: self.mpdPlugin.getState(...).then(...).catch is not a function Mar 26 10:42:13 volumio volumio[1318]: at self._onMpdPlayer (/data/plugins/music_service/dark_ascendants/index.js:232:13) Mar 26 10:42:13 volumio volumio[1318]: at MpdClient.emit (node:events:514:28) Mar 26 10:42:13 volumio volumio[1318]: at /volumio/app/plugins/music_service/mpd/lib/mpd.js:128:12 Mar 26 10:42:13 volumio volumio[1318]: at Array.forEach () Mar 26 10:42:13 volumio volumio[1318]: at MpdClient.handleIdleResults (/volumio/app/plugins/music_service/mpd/lib/mpd.js:125:19) Mar 26 10:42:13 volumio volumio[1318]: at MpdClient.handleIdleResultsLoop (/volumio/app/plugins/music_service/mpd/lib/mpd.js:115:8) Mar 26 10:42:13 volumio volumio[1318]: at /volumio/app/plugins/music_service/mpd/lib/mpd.js:97:12 Mar 26 10:42:13 volumio volumio[1318]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Mar 26 10:42:13 volumio volumio[1318]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Mar 26 10:42:13 volumio volumio[1318]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Mar 26 10:42:13 volumio volumio[1318]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 10:42:13 volumio sudo[5548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 10:41' Mar 26 10:42:13 volumio sudo[5548]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"