Apr 14 18:27:08 volumio volumio[1269]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 14 18:27:08 volumio volumio[1269]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 14 18:27:08 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:08 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:08 volumio volumio[1269]: info: Starting MyVolumio Remote Streaming Endpoints Apr 14 18:27:08 volumio volumio[1269]: info: MyVolumio login type: Token Apr 14 18:27:08 volumio volumio[1269]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 14 18:27:08 volumio volumio[1269]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 14 18:27:11 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:11.808+07:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.247:53256 Apr 14 18:27:11 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:11.827+07:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.247:53256 @ 0x2134e10" latency=12.017668ms timeout=10s Apr 14 18:27:11 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:11.829+07:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.247:53256 @ 0x2134e10" latency=13.828599ms platform=PLATFORM_IOS version=5.260331.0 Apr 14 18:27:11 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:11.830+07:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" Apr 14 18:27:17 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:17.723+07:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.247:53256 @ 0x2134e10" latency=12.184374ms platform=PLATFORM_IOS version=5.260331.0 Apr 14 18:27:17 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:17.723+07:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.247:53256 @ 0x2134e10" latency=10.619093ms timeout=10s Apr 14 18:27:17 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:17.725+07:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" Apr 14 18:27:19 volumio upmpdcli[1894]: writing RSA key Apr 14 18:27:20 volumio volumio[1269]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 14 18:27:20 volumio volumio[1269]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 14 18:27:20 volumio volumio[1269]: info: Streaming services startup Apr 14 18:27:20 volumio volumio[1269]: info: Starting Streaming Daemon Apr 14 18:27:20 volumio volumio[1269]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 14 18:27:20 volumio sudo[1901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 18:27:20 volumio sudo[1901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:21 volumio sudo[1901]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 18:27:21 volumio volumio[1269]: info: AutoStart - Check #5/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 18:27:21 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:21 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:21 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 18:27:21 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:21 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:21 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:21 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:21.685+07:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" name=Volumio Apr 14 18:27:21 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:21.685+07:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" name=Volumio Apr 14 18:27:21 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:21.693+07:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" language=en Apr 14 18:27:21 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:21.693+07:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" language=en Apr 14 18:27:21 volumio volumio[1269]: error: Cannot start Volumio Streaming Daemon Apr 14 18:27:21 volumio volumio[1269]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 18:27:21 volumio volumio[1269]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 18:27:21 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:21.828+07:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.247:53256 @ 0x2134e10" latency=12.017668ms timeout=10s error="failed to get current timezone: could not get current timezone: context deadline exceeded" Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 14 18:27:21 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:21.991+07:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" timezone=Asia/Bangkok Apr 14 18:27:21 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 14 18:27:22 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:22.008+07:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" available=true connected=false macAddress= ip4Address= ip6Address= Apr 14 18:27:22 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:22.026+07:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" available=true connected=true macAddress=dc:a6:32:fe:04:fe ip4Address=192.168.1.242/24 ip6Address= ssid="PPGGGGKK 2.4" Apr 14 18:27:22 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:22.027+07:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" setupComplete=true Apr 14 18:27:22 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 14 18:27:22 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 14 18:27:22 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:22 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 14 18:27:22 volumio volumio[1269]: amixer -c 0 info | grep "bcm2835 ALSA" Apr 14 18:27:22 volumio volumio[1269]: amixer -c 1 info | grep "bcm2835 Headphones" Apr 14 18:27:22 volumio volumio[1269]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Apr 14 18:27:22 volumio volumio[1269]: amixer -c 2 info | grep "vc4-hdmi-0" Apr 14 18:27:22 volumio volumio[1269]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Apr 14 18:27:22 volumio volumio[1269]: amixer -c 3 info | grep "vc4-hdmi-1" Apr 14 18:27:22 volumio volumio[1269]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Apr 14 18:27:23 volumio volumio[1269]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Apr 14 18:27:23 volumio volumio[1269]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 14 18:27:23 volumio volumio[1269]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 14 18:27:23 volumio volumio[1269]: amixer -c 4 info | grep "I-Sabre Q2M DAC" Apr 14 18:27:23 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:23 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:23 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000022] -121 Apr 14 18:27:23 volumio volumio[1269]: Card sysdefault:4 'DAC'/'I-Sabre Q2M DAC' Apr 14 18:27:23 volumio volumio[1269]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 4 Apr 14 18:27:23 volumio volumio[1269]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 14 18:27:23 volumio volumio[1269]: {"cmd":"/usr/local/bin/alsacap -C 4","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 4\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 14 18:27:23 volumio volumio[1269]: amixer -c 4 info | grep "Audiophonics I-Sabre ES9028Q2M" Apr 14 18:27:23 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:23 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:23 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000022] -121 Apr 14 18:27:23 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:23.944+07:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" selectedOutputId=4 Apr 14 18:27:23 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 18:27:24 volumio volumio[1269]: error: MyVolumio Custom Token format not valid, refreshing it Apr 14 18:27:24 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:24 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:24 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:24 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:24.616+07:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" currentVersion=4.096 latestVersion=4.119 Apr 14 18:27:24 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:24.617+07:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.247:53256 @ 0x2134e10" status=UPDATE_STATUS_NONE progress=0 Apr 14 18:27:24 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:24.618+07:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" userId= Apr 14 18:27:24 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:24.619+07:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" providers=3 Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:24 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:24 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:24 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 18:27:25 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:25.051+07:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" plugins=0 Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:25 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:25 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:25.089+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=0 volume=87 Apr 14 18:27:25 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:25.090+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:27:25 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:25.117+07:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.247:53256 @ 0x2134e10" latency=9.268814ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:25 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:25 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:25 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:25 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:25 volumio volumio[1269]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:25 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:25 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 87 Apr 14 18:27:25 volumio volumio[1269]: SPOTIFY: SPOTIFY VOLUME undefined Apr 14 18:27:25 volumio volumio[1269]: SPOTIFY: VOLUMIO VOLUME 87 Apr 14 18:27:25 volumio volumio[1269]: info: Aligning Spotify Volume to Volumio Volume Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:25 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:25 volumio volumio[1269]: info: Setting Spotify Volume from Volumio: 87 Apr 14 18:27:25 volumio volumio[1269]: verbose: New Socket.io Connection to 192.168.1.242:3000 from 192.168.1.247 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:25 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:25 volumio volumio-remote-updater[773]: Test mode disabled Apr 14 18:27:25 volumio volumio-remote-updater[773]: Alpha mode disabled Apr 14 18:27:25 volumio volumio-remote-updater[773]: Alpha legacy test mode disabled Apr 14 18:27:25 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 14 18:27:25 volumio volumio[1269]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

  • Fix for missing PWM backlight module
  • Fix for crash loop on Onboarding plugin

NEW ADDITIONS

  • Bump RPi/CM4 kernel to 6.12.74

","title":"Update v4.119","updateavailable":true} Apr 14 18:27:26 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 14 18:27:26 volumio volumio[1269]: info: MyVolumio login type: Token Apr 14 18:27:26 volumio volumio[1269]: info: AutoStart - Check #6/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 14 18:27:26 volumio volumio[1269]: SPOTIFY: SETTING SPOTIFY VOLUME 87 Apr 14 18:27:26 volumio volumio[1269]: info: Sending Spotify command with payload to local API: /player/volume Apr 14 18:27:27 volumio volumio[1269]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::volumioGetBrowseSources Apr 14 18:27:28 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 18:27:28 volumio sudo[1957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 18:27:28 volumio sudo[1957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:28 volumio sudo[1957]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:28 volumio sudo[1959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 18:27:28 volumio sudo[1959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:29 volumio sudo[1959]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:29 volumio volumio[1269]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 14 18:27:29 volumio volumio[1269]: verbose: New Socket.io Connection to 192.168.1.242 from 192.168.1.247 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Apr 14 18:27:30 volumio sudo[1963]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 18:27:30 volumio sudo[1963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:30 volumio sudo[1963]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:30 volumio sudo[1965]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 18:27:30 volumio sudo[1965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:30 volumio sudo[1965]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:30 volumio volumio[1269]: verbose: New Socket.io Connection to 192.168.1.242 from 192.168.1.247 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Apr 14 18:27:31 volumio volumio[1269]: info: MyVolumio token set successfully Apr 14 18:27:31 volumio volumio[1269]: info: MYVOLUMIO: Adding device Apr 14 18:27:31 volumio volumio[1269]: info: MYVOLUMIO: Evaluating Server Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::volumioGetVisibleSources Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:31 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 14 18:27:31 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:31 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:31 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:31 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:31 volumio volumio[1269]: info: Listing playlists Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 14 18:27:31 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 18:27:33 volumio volumio[1269]: info: MyVolumio status changed Apr 14 18:27:33 volumio volumio[1269]: info: Streaming services startup Apr 14 18:27:33 volumio volumio[1269]: info: Starting Streaming Daemon Apr 14 18:27:33 volumio volumio[1269]: info: Removing browser output: myVolumio user plan is not superstar Apr 14 18:27:33 volumio volumio[1269]: info: Removing audio output: Apr 14 18:27:33 volumio volumio[1269]: info: Stoppping Tunnel 1 Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 14 18:27:33 volumio volumio[1269]: info: AutoStart - Check #7/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 14 18:27:33 volumio sudo[1989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 14 18:27:33 volumio sudo[1989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:33 volumio sudo[1991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 14 18:27:33 volumio sudo[1991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:27:33 volumio sudo[1989]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:33 volumio volumio[1269]: info: Setting Geolocation for MyVolumio to as1 Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:33 volumio volumio[1269]: error: Cannot start Volumio Streaming Daemon Apr 14 18:27:33 volumio volumio[1269]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 14 18:27:33 volumio volumio[1269]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 14 18:27:33 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 18:27:33 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 18:27:33 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 18:27:33 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 18:27:33 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 18:27:33 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 14 18:27:33 volumio sudo[1991]: pam_unix(sudo:session): session closed for user root Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 18:27:33 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:33 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:33 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 14 18:27:33 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:33 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:33 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:33 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:33 volumio volumio[1269]: info: Remote SSH Stopped Apr 14 18:27:34 volumio volumio[1269]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 18:27:34 volumio volumio[1269]: info: Updating MyVolumio device info Apr 14 18:27:34 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:34 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:34 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:35 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 14 18:27:35 volumio volumio[1269]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 18:27:38 volumio volumio[1269]: info: MYVOLUMIO: Adding device Apr 14 18:27:38 volumio volumio[1269]: info: MYVOLUMIO: Evaluating Server Apr 14 18:27:38 volumio volumio[1269]: info: AutoStart - Check #8/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 14 18:27:39 volumio volumio[1269]: info: CoreCommandRouter::volumioGetQueue Apr 14 18:27:39 volumio volumio[1269]: info: CoreStateMachine::getQueue Apr 14 18:27:39 volumio volumio[1269]: info: CorePlayQueue::getQueue Apr 14 18:27:40 volumio volumio[1269]: info: Setting Geolocation for MyVolumio to as1 Apr 14 18:27:40 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:40 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:40 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:40 volumio volumio[1269]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 14 18:27:40 volumio volumio[1269]: info: Completed starting MyVolumio Plugin Apr 14 18:27:40 volumio volumio[1269]: [Metrics] CommandRouter: 96s 328.05ms Apr 14 18:27:40 volumio volumio[1269]: info: CoreCommandRouter::volumiosetStartupVolume Apr 14 18:27:40 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 18:27:40 volumio volumio[1269]: info: VolumeController:: Setting startup Volume 20 Apr 14 18:27:40 volumio volumio[1269]: info: VolumeController::SetAlsaVolume20 Apr 14 18:27:41 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:41 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:41 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000022] -121 Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::Close All Modals sent Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::Close All Modals sent Apr 14 18:27:41 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:27:41 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:27:41 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:41 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:41.258+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=0 volume=20 Apr 14 18:27:41 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:41.259+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:27:41 volumio volumio[1269]: info: Updating MyVolumio device info Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 14 18:27:41 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:27:41 volumio volumio[1269]: info: CURURI: music-library Apr 14 18:27:41 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 14 18:27:41 volumio volumio[1269]: SPOTIFY: SPOTIFY VOLUME 87 Apr 14 18:27:41 volumio volumio[1269]: SPOTIFY: VOLUMIO VOLUME 20 Apr 14 18:27:41 volumio volumio[1269]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 14 18:27:41 volumio volumio[1269]: info: Setting Spotify Volume from Volumio: 20 Apr 14 18:27:41 volumio volumio[1269]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 14 18:27:41 volumio volumio[1269]: error: Failed LSINFO: null Apr 14 18:27:41 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:27:42 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 14 18:27:42 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 14 18:27:42 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 14 18:27:42 volumio volumio[1269]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 14 18:27:43 volumio volumio[1269]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Apr 14 18:27:43 volumio volumio[1269]: info: Sending Spotify command with payload to local API: /player/volume Apr 14 18:27:43 volumio volumio[1269]: info: AutoStart - Check #9/60 - VOLUMIO_SYSTEM_STATUS = starting Apr 14 18:27:45 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:45.241+07:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.1.247:53256 @ 0x2134e10" latency=11.863894ms timeout=3s volume=25 Apr 14 18:27:45 volumio volumio[1269]: info: VolumeController::SetAlsaVolume25 Apr 14 18:27:45 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:27:45 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:45 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 18:27:45 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:27:45 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:45.424+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=0 volume=25 Apr 14 18:27:45 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:45.424+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: SPOTIFY VOLUME 20 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: VOLUMIO VOLUME 25 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 14 18:27:45 volumio volumio[1269]: info: Setting Spotify Volume from Volumio: 25 Apr 14 18:27:45 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:45 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:45 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000022] -121 Apr 14 18:27:45 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:45.556+07:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.1.247:53256 @ 0x2134e10" latency=11.155497ms timeout=3s volume=34 Apr 14 18:27:45 volumio volumio[1269]: info: VolumeController::SetAlsaVolume34 Apr 14 18:27:45 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:27:45 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:45 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 18:27:45 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:27:45 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:45.652+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=0 volume=34 Apr 14 18:27:45 volumio volumio5-onboarding[1683]: time=2026-04-14T18:27:45.652+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:27:45 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:45 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:45 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000022] -121 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: SPOTIFY VOLUME 25 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: VOLUMIO VOLUME 34 Apr 14 18:27:45 volumio volumio[1269]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 14 18:27:45 volumio volumio[1269]: info: Setting Spotify Volume from Volumio: 34 Apr 14 18:27:46 volumio kernel: i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121 Apr 14 18:27:47 volumio volumio[1269]: SPOTIFY: SETTING SPOTIFY VOLUME 34 Apr 14 18:27:47 volumio volumio[1269]: info: Sending Spotify command with payload to local API: /player/volume Apr 14 18:27:48 volumio volumio[1269]: info: BOOT COMPLETED Apr 14 18:27:48 volumio volumio[1269]: info: AutoStart - Check #10/60 - VOLUMIO_SYSTEM_STATUS = ready Apr 14 18:27:48 volumio volumio[1269]: info: AutoStart - System ready state CONFIRMED after 10 checks Apr 14 18:27:48 volumio volumio[1269]: info: AutoStart - Applying additional delay of 5000ms before playback Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 14 18:27:49 volumio volumio[1269]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 14 18:27:49 volumio volumio[1269]: info: Received Get System Version Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 18:27:49 volumio volumio[1269]: info: Received Get System Info Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 14 18:27:49 volumio volumio[1269]: info: Discovery: Getting this device information Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::volumioGetState Apr 14 18:27:49 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:49 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 14 18:27:50 volumio volumio[1269]: info: CoreCommandRouter::volumioPlay Apr 14 18:27:50 volumio volumio[1269]: info: CoreStateMachine::play index undefined Apr 14 18:27:50 volumio volumio[1269]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 18:27:50 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:50 volumio volumio[1269]: info: CoreStateMachine::startPlaybackTimer Apr 14 18:27:50 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:50 volumio volumio[1269]: verbose: ControllerMpd::clearAddPlayTracks USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac Apr 14 18:27:50 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 18:27:51 volumio volumio[1269]: info: sendMpdCommand stop took 40 milliseconds Apr 14 18:27:51 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand clear Apr 14 18:27:51 volumio volumio[1269]: info: sendMpdCommand clear took 2 milliseconds Apr 14 18:27:51 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand add "USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" Apr 14 18:27:51 volumio volumio[1269]: info: Apr 14 18:27:51 volumio volumio[1269]: ---------------------------- MPD announces system playlist update Apr 14 18:27:51 volumio volumio[1269]: info: Ignoring MPD Status Update Apr 14 18:27:51 volumio volumio[1269]: info: Apr 14 18:27:51 volumio volumio[1269]: ---------------------------- MPD announces system playlist update Apr 14 18:27:51 volumio volumio[1269]: info: Ignoring MPD Status Update Apr 14 18:27:51 volumio volumio[1269]: info: Apr 14 18:27:51 volumio volumio[1269]: ---------------------------- MPD announces system playlist update Apr 14 18:27:51 volumio volumio[1269]: info: Ignoring MPD Status Update Apr 14 18:27:51 volumio volumio[1269]: error: updateQueue error: null Apr 14 18:27:51 volumio volumio[1269]: error: updateQueue error: null Apr 14 18:27:51 volumio volumio[1269]: info: ------------------------------ 28ms Apr 14 18:27:51 volumio volumio[1269]: info: ------------------------------ 22ms Apr 14 18:27:51 volumio volumio[1269]: error: updateQueue error: null Apr 14 18:27:51 volumio volumio[1269]: info: ------------------------------ 22ms Apr 14 18:27:53 volumio volumio[1269]: info: AutoStart - startPlayback called Apr 14 18:27:53 volumio volumio[1269]: info: CoreCommandRouter::volumioGetQueue Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::getQueue Apr 14 18:27:53 volumio volumio[1269]: info: CorePlayQueue::getQueue Apr 14 18:27:53 volumio volumio[1269]: info: AutoStart - Queue has 180 items Apr 14 18:27:53 volumio volumio[1269]: info: AutoStart - Playing from position 0 Apr 14 18:27:53 volumio volumio[1269]: info: CoreCommandRouter::volumioPlay Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::play index 0 Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::stop Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::play index undefined Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 18:27:53 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:53 volumio volumio[1269]: info: CoreStateMachine::startPlaybackTimer Apr 14 18:27:53 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:27:53 volumio volumio[1269]: verbose: ControllerMpd::clearAddPlayTracks USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac Apr 14 18:27:53 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 18:27:53 volumio volumio[1269]: info: sendMpdCommand stop took 4 milliseconds Apr 14 18:27:53 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand clear Apr 14 18:27:53 volumio volumio[1269]: info: Apr 14 18:27:53 volumio volumio[1269]: ---------------------------- MPD announces system playlist update Apr 14 18:27:53 volumio volumio[1269]: info: Ignoring MPD Status Update Apr 14 18:27:53 volumio volumio[1269]: info: sendMpdCommand clear took 12 milliseconds Apr 14 18:27:53 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand add "USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" Apr 14 18:27:53 volumio volumio[1269]: info: Apr 14 18:27:53 volumio volumio[1269]: ---------------------------- MPD announces system playlist update Apr 14 18:27:53 volumio volumio[1269]: info: Ignoring MPD Status Update Apr 14 18:27:53 volumio volumio[1269]: info: Apr 14 18:27:53 volumio volumio[1269]: ---------------------------- MPD announces system playlist update Apr 14 18:27:53 volumio volumio[1269]: info: Ignoring MPD Status Update Apr 14 18:27:53 volumio volumio[1269]: error: updateQueue error: null Apr 14 18:27:53 volumio volumio[1269]: error: updateQueue error: null Apr 14 18:27:53 volumio volumio[1269]: error: updateQueue error: null Apr 14 18:27:53 volumio volumio[1269]: info: ------------------------------ 35ms Apr 14 18:27:53 volumio volumio[1269]: info: ------------------------------ 19ms Apr 14 18:27:53 volumio volumio[1269]: info: ------------------------------ 10ms Apr 14 18:27:56 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:27:56 volumio volumio[1269]: info: CURURI: albums:// Apr 14 18:27:56 volumio volumio[1269]: info: listAlbums - loading Albums from cache Apr 14 18:27:56 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:00 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:28:00 volumio volumio[1269]: info: CURURI: playlists Apr 14 18:28:00 volumio volumio[1269]: info: Listing playlists Apr 14 18:28:00 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:11 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:28:11 volumio volumio[1269]: info: CURURI: music-library Apr 14 18:28:11 volumio volumio[1269]: error: Failed LSINFO: null Apr 14 18:28:11 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:15 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:28:15 volumio volumio[1269]: info: CURURI: artists:// Apr 14 18:28:15 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:19 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:28:19 volumio volumio[1269]: info: CURURI: playlists Apr 14 18:28:19 volumio volumio[1269]: info: Listing playlists Apr 14 18:28:19 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:27 volumio kernel: usb 1-1.2: USB disconnect, device number 3 Apr 14 18:28:27 volumio volumio[1269]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-id/usb-SanDisk_Cruzer_Blade_4C530499910509101400-0:0-part1 /dev/disk/by-uuid/5ED9-00E1 /dev/disk/by-label/MY_MUSIC /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.2:1.0-scsi-0:0:0:0-part1 /dev/disk/by-partuuid/8455d9bb-01","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"26","ID_BUS":"usb","ID_FS_LABEL":"MY_MUSIC","ID_FS_LABEL_ENC":"MY_MUSIC","ID_FS_TYPE":"vfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"5ED9-00E1","ID_FS_UUID_ENC":"5ED9-00E1","ID_FS_VERSION":"FAT32","ID_INSTANCE":"0:0","ID_MODEL":"Cruzer_Blade","ID_MODEL_ENC":"Cruzer\\x20Blade\\x20\\x20\\x20\\x20","ID_MODEL_ID":"5567","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_FLAGS":"0x80","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"2048","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"30527488","ID_PART_ENTRY_TYPE":"0xc","ID_PART_ENTRY_UUID":"8455d9bb-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"8455d9bb","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1.2:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_2_1_0-scsi-0_0_0_0","ID_REVISION":"1.27","ID_SERIAL":"SanDisk_Cruzer_Blade_4C530499910509101400-0:0","ID_SERIAL_SHORT":"4C530499910509101400","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INSTANCE":"0:0","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"Cruzer_Blade","ID_USB_MODEL_ENC":"Cruzer\\x20Blade\\x20\\x20\\x20\\x20","ID_USB_MODEL_ID":"5567","ID_USB_REVISION":"1.27","ID_USB_SERIAL":"SanDisk_Cruzer_Blade_4C530499910509101400-0:0","ID_USB_SERIAL_SHORT":"4C530499910509101400","ID_USB_TYPE":"disk","ID_USB_VENDOR":"SanDisk","ID_USB_VENDOR_ENC":"SanDisk\\x20","ID_USB_VENDOR_ID":"0781","ID_VENDOR":"SanDisk","ID_VENDOR_ENC":"SanDisk\\x20","ID_VENDOR_ID":"0781","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"2752","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"4017868"} Apr 14 18:28:28 volumio sudo[2125]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda1 Apr 14 18:28:28 volumio sudo[2125]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:28:28 volumio systemd[1]: media-MY_MUSIC.mount: Deactivated successfully. Apr 14 18:28:28 volumio sudo[2125]: pam_unix(sudo:session): session closed for user root Apr 14 18:28:29 volumio kernel: usb 1-1.1: new high-speed USB device number 4 using xhci_hcd Apr 14 18:28:29 volumio kernel: usb 1-1.1: New USB device found, idVendor=0781, idProduct=5567, bcdDevice= 1.27 Apr 14 18:28:29 volumio kernel: usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 14 18:28:29 volumio kernel: usb 1-1.1: Product: Cruzer Blade Apr 14 18:28:29 volumio kernel: usb 1-1.1: Manufacturer: SanDisk Apr 14 18:28:29 volumio kernel: usb 1-1.1: SerialNumber: 4C530499910509101400 Apr 14 18:28:29 volumio kernel: usb-storage 1-1.1:1.0: USB Mass Storage device detected Apr 14 18:28:29 volumio kernel: scsi host0: usb-storage 1-1.1:1.0 Apr 14 18:28:30 volumio kernel: scsi 0:0:0:0: Direct-Access SanDisk Cruzer Blade 1.27 PQ: 0 ANSI: 6 Apr 14 18:28:30 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Apr 14 18:28:30 volumio kernel: sd 0:0:0:0: [sda] 30529536 512-byte logical blocks: (15.6 GB/14.6 GiB) Apr 14 18:28:30 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off Apr 14 18:28:30 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 Apr 14 18:28:30 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA Apr 14 18:28:30 volumio kernel: sda: sda1 Apr 14 18:28:30 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Apr 14 18:28:30 volumio volumio[1269]: info: Mounting Device MY_MUSIC Apr 14 18:28:31 volumio sudo[2137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/MY_MUSIC -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 14 18:28:31 volumio sudo[2137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 18:28:31 volumio kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Apr 14 18:28:31 volumio kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Apr 14 18:28:31 volumio sudo[2137]: pam_unix(sudo:session): session closed for user root Apr 14 18:28:32 volumio volumio[1269]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/MY_MUSIC Apr 14 18:28:33 volumio volumio[1269]: info: Scanning removed location : "USB/MY_MUSIC" Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand status Apr 14 18:28:33 volumio volumio[1269]: info: Apr 14 18:28:33 volumio volumio[1269]: ---------------------------- MPD announces state update: update Apr 14 18:28:33 volumio volumio[1269]: info: ControllerMpd::getState Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand status Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand status Apr 14 18:28:33 volumio volumio[1269]: info: Apr 14 18:28:33 volumio volumio[1269]: ---------------------------- MPD announces state update: update Apr 14 18:28:33 volumio volumio[1269]: info: ControllerMpd::getState Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand status Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand status Apr 14 18:28:33 volumio volumio[1269]: info: Apr 14 18:28:33 volumio volumio[1269]: ---------------------------- MPD announces state update: update Apr 14 18:28:33 volumio volumio[1269]: info: ControllerMpd::getState Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::sendMpdCommand status Apr 14 18:28:33 volumio volumio[1269]: info: sendMpdCommand status took 65 milliseconds Apr 14 18:28:33 volumio volumio[1269]: info: sendMpdCommand status took 63 milliseconds Apr 14 18:28:33 volumio volumio[1269]: info: sendMpdCommand status took 63 milliseconds Apr 14 18:28:33 volumio volumio[1269]: info: sendMpdCommand status took 61 milliseconds Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::parseState Apr 14 18:28:33 volumio volumio[1269]: info: Command Router : Notfying DB Updatetrue Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::parseState Apr 14 18:28:33 volumio volumio[1269]: verbose: ControllerMpd::parseState Apr 14 18:28:34 volumio volumio[1269]: info: Command Router : Notfying DB Updatetrue Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::Close All Modals sent Apr 14 18:28:34 volumio volumio[1269]: verbose: ControllerMpd::parseState Apr 14 18:28:34 volumio volumio[1269]: info: ControllerMpd::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::servicePushState Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 14 18:28:34 volumio volumio[1269]: verbose: CURRENT POSITION 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::syncState stateService stop Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::syncState currentStatus stop Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:34 volumio volumio[1269]: info: No code Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:34 volumio volumio[1269]: info: ControllerMpd::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::servicePushState Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 14 18:28:34 volumio volumio[1269]: verbose: CURRENT POSITION 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::syncState stateService stop Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::syncState currentStatus stop Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:34 volumio volumio[1269]: info: No code Apr 14 18:28:34 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:34 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:34 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.618+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=39833 volume=34 Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.618+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.643+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=39833 volume=34 Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.644+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.649+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=39833 volume=34 Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.650+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.651+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=39833 volume=34 Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.652+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.698+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=39833 volume=34 Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.698+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.728+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=39833 volume=34 Apr 14 18:28:34 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:34.729+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:35 volumio volumio[1269]: info: ------------------------------ 1645ms Apr 14 18:28:35 volumio volumio[1269]: info: ------------------------------ 1643ms Apr 14 18:28:35 volumio volumio[1269]: info: sendMpdCommand status took 1718 milliseconds Apr 14 18:28:35 volumio volumio[1269]: info: sendMpdCommand status took 1674 milliseconds Apr 14 18:28:35 volumio volumio[1269]: verbose: ControllerMpd::parseState Apr 14 18:28:35 volumio volumio[1269]: info: Command Router : Notfying DB Updatetrue Apr 14 18:28:35 volumio volumio[1269]: info: CoreCommandRouter::Close All Modals sent Apr 14 18:28:35 volumio volumio[1269]: verbose: ControllerMpd::parseState Apr 14 18:28:35 volumio volumio[1269]: info: ControllerMpd::pushState Apr 14 18:28:35 volumio volumio[1269]: info: CoreCommandRouter::servicePushState Apr 14 18:28:35 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:35 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:35 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 18:28:35 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:35 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:35 volumio volumio[1269]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 14 18:28:35 volumio volumio[1269]: verbose: CURRENT POSITION 0 Apr 14 18:28:35 volumio volumio[1269]: info: CoreStateMachine::syncState stateService stop Apr 14 18:28:35 volumio volumio[1269]: info: CoreStateMachine::syncState currentStatus stop Apr 14 18:28:35 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:35 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:35 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:35 volumio volumio[1269]: info: No code Apr 14 18:28:35 volumio volumio[1269]: info: CoreStateMachine::pushState Apr 14 18:28:35 volumio volumio[1269]: info: CorePlayQueue::getTrack 0 Apr 14 18:28:35 volumio volumio[1269]: info: CoreCommandRouter::volumioPushState Apr 14 18:28:35 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:35.508+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=41762 volume=34 Apr 14 18:28:35 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:35.508+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:35 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:35.509+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=41762 volume=34 Apr 14 18:28:35 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:35.509+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:35 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:35.530+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" state=STATUS_STOPPED positionMs=41762 volume=34 Apr 14 18:28:35 volumio volumio5-onboarding[1683]: time=2026-04-14T18:28:35.531+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.247:53256 @ 0x2134e10" id="mnt/USB/ESD-USB/Phil Collins - Face Value (Audio Fidelity AFZ 084 24kt Gold, US), 2010/01 (Phil Collins) In The Air Tonight.flac" title="1 - In The Air Tonight" Apr 14 18:28:35 volumio volumio[1269]: info: ------------------------------ 2148ms Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:35 volumio volumio[1269]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Apr 14 18:28:43 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:28:43 volumio volumio[1269]: info: CURURI: music-library Apr 14 18:28:43 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:46 volumio volumio[1269]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 14 18:28:46 volumio volumio[1269]: info: CURURI: music-library/USB Apr 14 18:28:46 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:47 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:47 volumio volumio[1269]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 14 18:28:47 volumio volumio[1269]: info: CoreStateMachine::ClearQueue Apr 14 18:28:47 volumio volumio[1269]: info: CoreStateMachine::stop Apr 14 18:28:47 volumio volumio[1269]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 18:28:47 volumio volumio[1269]: info: CorePlayQueue::clearPlayQueue Apr 14 18:28:47 volumio volumio[1269]: info: CorePlayQueue::saveQueue Apr 14 18:28:47 volumio volumio[1269]: info: CoreCommandRouter::volumioPushQueue Apr 14 18:28:47 volumio volumio[1269]: info: CoreStateMachine::addQueueItems Apr 14 18:28:47 volumio volumio[1269]: info: CorePlayQueue::addQueueItems Apr 14 18:28:47 volumio volumio[1269]: info: Preload queue cleared Apr 14 18:28:47 volumio volumio[1269]: info: Adding Item to queue: music-library/USB/MY_MUSIC Apr 14 18:28:47 volumio volumio[1269]: info: Exploding uri music-library/USB/MY_MUSIC in service mpd Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F01%20-%20I%20Will%20Always%20Love%20You.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/01 - I Will Always Love You.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F02%20-%20Saving%20All%20My%20Love%20for%20You.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/02 - Saving All My Love for You.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F03%20-%20Greatest%20Love%20of%20All.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/03 - Greatest Love of All.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston%20with%20the%20London%20Symphony%20Orchestra/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F04%20-%20One%20Moment%20in%20Time.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/04 - One Moment in Time.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F05%20-%20I%20Wanna%20Dance%20With%20Somebody.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/05 - I Wanna Dance With Somebody.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F06%20-%20How%20Will%20I%20Know.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/06 - How Will I Know.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F07%20-%20So%20Emotional.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/07 - So Emotional.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Mariah%20Carey%20%26%20Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F08%20-%20When%20You%20Believe.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/08 - When You Believe.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F09%20-%20Where%20Do%20Broken%20Hearts%20Go.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/09 - Where Do Broken Hearts Go.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F10%20-%20I%E2%80%99m%20Your%20Baby%20Tonight.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/10 - I’m Your Baby Tonight.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F11%20-%20Didn%E2%80%99t%20We%20Almost%20Have%20It%20All.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/11 - Didn’t We Almost Have It All.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F12%20-%20Run%20to%20You.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/12 - Run to You.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F13%20-%20Exhale.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/13 - Exhale.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston%20%26%20George%20Michael/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F14%20-%20If%20I%20Told%20You%20That.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/14 - If I Told You That.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F15%20-%20I%20Have%20Nothing.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/15 - I Have Nothing.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F16%20-%20I%E2%80%99m%20Every%20Woman.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/16 - I’m Every Woman.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F17%20-%20It%E2%80%99s%20Not%20Right%20but%20It%E2%80%99s%20Okay.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/17 - It’s Not Right but It’s Okay.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Whitney%20Houston/All%20Time%20Best/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FAll%20Time%20Best%20-%20Reclam%20Musik%20Edition%2010%2F18%20-%20My%20Love%20Is%20Your%20Love.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/All Time Best - Reclam Musik Edition 10/18 - My Love Is Your Love.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F01%20Bruno%20Mars%20-%2024K%20Magic.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/01 Bruno Mars - 24K Magic.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F02%20Bruno%20Mars%20-%20Chunky.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/02 Bruno Mars - Chunky.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F03%20Bruno%20Mars%20-%20Perm.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/03 Bruno Mars - Perm.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F04%20Bruno%20Mars%20-%20That's%20What%20I%20Like.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/04 Bruno Mars - That's What I Like.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F05%20Bruno%20Mars%20-%20Versace%20On%20The%20Floor.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/05 Bruno Mars - Versace On The Floor.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F06%20Bruno%20Mars%20-%20Straight%20Up%20%26%20Down.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/06 Bruno Mars - Straight Up & Down.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F07%20Bruno%20Mars%20-%20Calling%20All%20My%20Lovelies.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/07 Bruno Mars - Calling All My Lovelies.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F08%20Bruno%20Mars%20-%20Finesse.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/08 Bruno Mars - Finesse.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Bruno%20Mars/XXIVk%20Magic/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FBruno%20Mars%2F09%20Bruno%20Mars%20-%20Too%20Good%20To%20Say%20Goodbye.wav&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Bruno Mars/09 Bruno Mars - Too Good To Say Goodbye.wav Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F01.%20Sultans%20Of%20Swing.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/01. Sultans Of Swing.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F02.%20Tunnel%20Of%20Love.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/02. Tunnel Of Love.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F03.%20My%20Parties.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/03. My Parties.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F04.%20Brothers%20In%20Arms.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/04. Brothers In Arms.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F05.%20Heavy%20Fuel.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/05. Heavy Fuel.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F06.%20Romeo%20And%20Juliet.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/06. Romeo And Juliet.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F07.%20Walk%20Of%20Life.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/07. Walk Of Life.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F08.%20Where%20Do%20You%20Think%20You're%20Going.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/08. Where Do You Think You're Going.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F09.%20Money%20For%20Nothing.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/09. Money For Nothing.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F10.%20So%20Far%20Away.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/10. So Far Away.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F11.%20When%20It%20Comes%20To%20You.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/11. When It Comes To You.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F12.%20Your%20Latest%20Trick.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/12. Your Latest Trick.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F13.%20One%20World.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/13. One World.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of%20Dire%20Straits/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2F14.%20Calling%20Elvis.flac&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/14. Calling Elvis.flac Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2FDire%20Straits%20-%20The%20Very%20Best%20Of.cue&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/Dire Straits - The Very Best Of.cue Apr 14 18:28:48 volumio volumio[1269]: info: ALBUMART /albumart?cacheid=803&web=Dire%20Straits/The%20Very%20Best%20Of/extralarge&path=%2Fmnt%2FUSB%2FMY_MUSIC%2FDire%20Straits%20-%20The%20Very%20Best%20Of%20Dire%20Straits%20-%20(1995)-%5BFLAC%5D%20-%20UP%20BY%20MAGIC%20JUAN%20DJ%2FDire%20Straits%20-%20The%20Very%20Best%20Of.cue&metadata=false Apr 14 18:28:48 volumio volumio[1269]: info: URI /mnt/USB/MY_MUSIC/Dire Straits - The Very Best Of Dire Straits - (1995)-[FLAC] - UP BY MAGIC JUAN DJ/Dire Straits - The Very Best Of.cue Apr 14 18:28:48 volumio volumio[1269]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 18:28:48 volumio volumio[1269]: Error: Unable to resolve or reject the same promise twice Apr 14 18:28:48 volumio volumio[1269]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 14 18:28:48 volumio volumio[1269]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Apr 14 18:28:48 volumio volumio[1269]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Apr 14 18:28:48 volumio volumio[1269]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Apr 14 18:28:48 volumio volumio[1269]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 14 18:28:48 volumio volumio[1269]: at Socket.emit (node:events:514:28) Apr 14 18:28:48 volumio volumio[1269]: at addChunk (node:internal/streams/readable:343:12) Apr 14 18:28:48 volumio volumio[1269]: at readableAddChunk (node:internal/streams/readable:312:11) Apr 14 18:28:48 volumio volumio[1269]: at Readable.push (node:internal/streams/readable:253:10) Apr 14 18:28:48 volumio volumio[1269]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Apr 14 18:28:48 volumio volumio[1269]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 18:28:56 volumio sudo[2201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 18:27' Apr 14 18:28:56 volumio sudo[2201]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"