-- Logs begin at Thu 2019-02-14 03:11:58 MST, end at Mon 2026-10-12 10:14:47 MDT. -- Oct 12 10:13:17 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 4 Oct 12 10:13:17 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Prefetching next song Oct 12 10:13:17 raspberrypi4 volumio[864]: info: DOING PREFETCH IN MPD Oct 12 10:13:17 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand add "NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac" Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Oct 12 10:13:17 raspberrypi4 volumio[864]: ---------------------------- MPD announces system playlist update Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Ignoring MPD Status Update Oct 12 10:13:17 raspberrypi4 volumio[864]: info: sendMpdCommand add "NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac" took 7 milliseconds Oct 12 10:13:17 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Oct 12 10:13:17 raspberrypi4 volumio[864]: ---------------------------- MPD announces system playlist update Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Ignoring MPD Status Update Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Oct 12 10:13:17 raspberrypi4 volumio[864]: ---------------------------- MPD announces system playlist update Oct 12 10:13:17 raspberrypi4 volumio[864]: info: Ignoring MPD Status Update Oct 12 10:13:17 raspberrypi4 volumio[864]: info: ------------------------------ 8ms Oct 12 10:13:17 raspberrypi4 volumio[864]: info: sendMpdCommand consume 1 took 5 milliseconds Oct 12 10:13:17 raspberrypi4 volumio[864]: info: ------------------------------ 4ms Oct 12 10:13:17 raspberrypi4 volumio[864]: info: ------------------------------ 3ms Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::startPlaybackTimer Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Oct 12 10:13:22 raspberrypi4 volumio[864]: ---------------------------- MPD announces system playlist update Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Ignoring MPD Status Update Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Oct 12 10:13:22 raspberrypi4 volumio[864]: ---------------------------- MPD announces state update: player Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ControllerMpd::getState Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand status Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Oct 12 10:13:22 raspberrypi4 volumio[864]: ---------------------------- MPD announces system playlist update Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Ignoring MPD Status Update Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Oct 12 10:13:22 raspberrypi4 volumio[864]: ---------------------------- MPD announces state update: player Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ControllerMpd::getState Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand status Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Oct 12 10:13:22 raspberrypi4 volumio[864]: ---------------------------- MPD announces system playlist update Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Ignoring MPD Status Update Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Oct 12 10:13:22 raspberrypi4 volumio[864]: ---------------------------- MPD announces state update: player Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ControllerMpd::getState Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand status Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ------------------------------ 15ms Oct 12 10:13:22 raspberrypi4 volumio[864]: info: sendMpdCommand status took 14 milliseconds Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ------------------------------ 13ms Oct 12 10:13:22 raspberrypi4 volumio[864]: info: sendMpdCommand status took 13 milliseconds Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ------------------------------ 12ms Oct 12 10:13:22 raspberrypi4 volumio[864]: info: sendMpdCommand status took 12 milliseconds Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::parseState Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::parseState Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::parseState Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 10:13:22 raspberrypi4 volumio[864]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 12 10:13:22 raspberrypi4 volumio[864]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::parseTrackInfo Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::parseTrackInfo Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: ControllerMpd::parseTrackInfo Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ControllerMpd::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::servicePushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":167,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"777 Kbps","isStreaming":false,"title":"Yellow River","artist":"Christie","album":"70s Songs [CD1]","uri":"NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac","trackType":"flac"} Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: CURRENT POSITION 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::syncState stateService play Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::syncState currentStatus play Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Received an update from plugin. extracting info from payload Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ControllerMpd::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::servicePushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":167,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"777 Kbps","isStreaming":false,"title":"Yellow River","artist":"Christie","album":"70s Songs [CD1]","uri":"NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac","trackType":"flac"} Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: CURRENT POSITION 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::syncState stateService play Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::syncState currentStatus play Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Received an update from plugin. extracting info from payload Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ControllerMpd::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::servicePushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":167,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"777 Kbps","isStreaming":false,"title":"Yellow River","artist":"Christie","album":"70s Songs [CD1]","uri":"NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac","trackType":"flac"} Oct 12 10:13:22 raspberrypi4 volumio[864]: verbose: CURRENT POSITION 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::syncState stateService play Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::syncState currentStatus play Oct 12 10:13:22 raspberrypi4 volumio[864]: info: Received an update from plugin. extracting info from payload Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreStateMachine::pushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:22 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioPushState Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ------------------------------ 65ms Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ------------------------------ 64ms Oct 12 10:13:22 raspberrypi4 volumio[864]: info: ------------------------------ 62ms Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.007-06:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.146:43590 Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.062-06:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.180952225s timeout=20s Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.062-06:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.062-06:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.183469537s platform=PLATFORM_ANDROID version=6.260930.0 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:13:56 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.072-06:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" name=Raspberrypi4 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.075-06:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" language=en Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.077-06:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" timezone=America/Edmonton Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.078-06:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" available=true connected=true macAddress=d8:3a:dd:61:59:3f ip4Address=192.168.1.226/24 ip6Address= Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.080-06:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.081-06:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" setupComplete=true Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 10:13:56 raspberrypi4 volumio[864]: amixer -c 2 info | grep "HiFiBerry Digi+ Pro HiFi wm8804-spdif-0" Oct 12 10:13:56 raspberrypi4 volumio[864]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 12 10:13:56 raspberrypi4 volumio[864]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 12 10:13:56 raspberrypi4 volumio[864]: Card hw:1 'Headphones'/'bcm2835 Headphones' Oct 12 10:13:56 raspberrypi4 volumio[864]: amixer -c 2 info | grep "snd_rpi_hifiberry_digi" Oct 12 10:13:56 raspberrypi4 volumio[864]: Card hw:2 'sndrpihifiberry'/'snd_rpi_hifiberry_digi' Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.375-06:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" selectedOutputId=2 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:13:56 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:13:56 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:13:56 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.410-06:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" currentVersion=3.912 latestVersion=3.912 Oct 12 10:13:56 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:56.410-06:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" status=UPDATE_STATUS_NONE progress=0 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 10:13:56 raspberrypi4 volumio[864]: verbose: New Socket.io Connection to 192.168.1.226:3000 from 192.168.1.146 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 10:13:56 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.579-06:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.181874752s timeout=20s Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.580-06:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.580-06:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.183295213s platform=PLATFORM_ANDROID version=6.260930.0 Oct 12 10:13:57 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:13:57 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.583-06:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" name=Raspberrypi4 Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.584-06:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" language=en Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.586-06:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" timezone=America/Edmonton Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.587-06:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" available=true connected=true macAddress=d8:3a:dd:61:59:3f ip4Address=192.168.1.226/24 ip6Address= Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.588-06:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.589-06:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" setupComplete=true Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 10:13:57 raspberrypi4 volumio[864]: amixer -c 2 info | grep "HiFiBerry Digi+ Pro HiFi wm8804-spdif-0" Oct 12 10:13:57 raspberrypi4 volumio[864]: amixer -c 0 info | grep "bcm2835 ALSA" Oct 12 10:13:57 raspberrypi4 volumio[864]: amixer -c 1 info | grep "bcm2835 Headphones" Oct 12 10:13:57 raspberrypi4 volumio[864]: Card hw:1 'Headphones'/'bcm2835 Headphones' Oct 12 10:13:57 raspberrypi4 volumio[864]: amixer -c 2 info | grep "snd_rpi_hifiberry_digi" Oct 12 10:13:57 raspberrypi4 volumio[864]: Card hw:2 'sndrpihifiberry'/'snd_rpi_hifiberry_digi' Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.853-06:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" selectedOutputId=2 Oct 12 10:13:57 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:13:57 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.874-06:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" currentVersion=3.912 latestVersion=3.912 Oct 12 10:13:57 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:57.875-06:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" status=UPDATE_STATUS_NONE progress=0 Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:13:57 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 10:13:58 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:58.780-06:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=U3Gadkc9W5cdyDcOn26nGxniFeO2 tokenExpiry=2026-10-12T11:13:58.780-06:00 Oct 12 10:13:58 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:13:58.792-06:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=U3Gadkc9W5cdyDcOn26nGxniFeO2 tokenExpiry=2026-10-12T11:13:58.792-06:00 Oct 12 10:14:00 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:00.348-06:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" userId=U3Gadkc9W5cdyDcOn26nGxniFeO2 Oct 12 10:14:00 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:14:00 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:14:00 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 10:14:00 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:00.873-06:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" userId=U3Gadkc9W5cdyDcOn26nGxniFeO2 Oct 12 10:14:01 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:01.875-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Oct 12 10:14:01 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:01.875-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Oct 12 10:14:01 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:01.875-06:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Oct 12 10:14:01 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:01.875-06:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory" Oct 12 10:14:01 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:01.875-06:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" providers=9 Oct 12 10:14:01 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:14:01 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:14:01 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.371-06:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" plugins=54 Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.371-06:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" plugins=54 Oct 12 10:14:02 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:14:02 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.375-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" state=STATUS_PLAYING positionMs=39560 volume=100 Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.375-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" state=STATUS_PLAYING positionMs=39560 volume=100 Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.376-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" id="mnt/NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac" title="6 - Yellow River" Oct 12 10:14:02 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:14:02 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.376-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" id="mnt/NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac" title="6 - Yellow River" Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.378-06:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" state=STATUS_PLAYING positionMs=39560 volume=100 Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.379-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.146:43590 @ 0x19a8a50" id="mnt/NAS/AS3102T-1F48/Music Files/Music Directory/70s Songs - 60 Hit Tracks On 3 CDs (2017)/70s Songs 3 Disc Set/70s Songs [CD1]/06 Christie - Yellow River.flac" title="6 - Yellow River" Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.480-06:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.184863604s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.538-06:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.610-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=69.755764ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.634-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://functions.volumio.cloud duration=95.865847ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.647-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=108.387068ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.674-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://functions.volumio.cloud duration=135.655014ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.694-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://securetoken.googleapis.com duration=153.971664ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.744-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://www.googleapis.com duration=205.376094ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.817-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://google.com duration=278.587912ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.921-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=http://pushupdates.volumio.org duration=381.150736ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.941-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=http://plugins.volumio.org duration=400.291454ms Oct 12 10:14:02 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:02.963-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://database.volumio.cloud duration=422.827355ms Oct 12 10:14:03 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:03.004-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=465.185044ms Oct 12 10:14:03 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:03.051-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=512.867627ms Oct 12 10:14:03 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:03.360-06:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.146:43590 @ 0x19a8a50" latency=1.218752485s timeout=10s endpoint=http://cddb.volumio.org duration=819.833034ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 10:14:03 raspberrypi4 sudo[6399]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 10:14:03 raspberrypi4 sudo[6399]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 10:14:03 raspberrypi4 sudo[6399]: pam_unix(sudo:session): session closed for user root Oct 12 10:14:03 raspberrypi4 sudo[6402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 10:14:03 raspberrypi4 sudo[6402]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 10:14:03 raspberrypi4 sudo[6402]: pam_unix(sudo:session): session closed for user root Oct 12 10:14:03 raspberrypi4 volumio[864]: verbose: New Socket.io Connection to 192.168.1.226 from 192.168.1.146 UA: Mozilla/5.0 (Linux; Android 15; motorola edge (2022) Build/V1STS35H.71-19-14; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.57 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 12 10:14:03 raspberrypi4 volumio5-onboarding[1011]: time=2026-10-12T10:14:03.917-06:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Oct 12 10:14:04 raspberrypi4 dbus-daemon[599]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.11" (uid=0 pid=1011 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=765 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Oct 12 10:14:04 raspberrypi4 sudo[6405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 10:14:04 raspberrypi4 sudo[6405]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 10:14:04 raspberrypi4 sudo[6405]: pam_unix(sudo:session): session closed for user root Oct 12 10:14:04 raspberrypi4 sudo[6408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 10:14:04 raspberrypi4 sudo[6408]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 10:14:04 raspberrypi4 sudo[6408]: pam_unix(sudo:session): session closed for user root Oct 12 10:14:04 raspberrypi4 volumio[864]: verbose: New Socket.io Connection to 192.168.1.226 from 192.168.1.146 UA: Mozilla/5.0 (Linux; Android 15; motorola edge (2022) Build/V1STS35H.71-19-14; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.57 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 12 10:14:04 raspberrypi4 volumio[864]: info: Listing playlists Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 10:14:04 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 10:14:06 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:14:06 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:14:06 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:14:06 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:14:06 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:14:06 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:14:06 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:14:06 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:14:07 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 10:14:07 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:14:07 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:14:07 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:14:07 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:14:07 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:14:07 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:14:07 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:14:08 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetQueue Oct 12 10:14:08 raspberrypi4 volumio[864]: info: CoreStateMachine::getQueue Oct 12 10:14:08 raspberrypi4 volumio[864]: info: CorePlayQueue::getQueue Oct 12 10:14:12 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 10:14:12 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 10:14:13 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 10:14:13 raspberrypi4 volumio[864]: info: CURURI: music-library Oct 12 10:14:13 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:14 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 10:14:14 raspberrypi4 volumio[864]: info: CURURI: music-library/NAS Oct 12 10:14:14 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:15 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 10:14:15 raspberrypi4 volumio[864]: info: CURURI: music-library/NAS/AS3102T-1F48 Oct 12 10:14:15 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:16 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 10:14:16 raspberrypi4 volumio[864]: info: CURURI: music-library/NAS/AS3102T-1F48/Music Files Oct 12 10:14:16 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:17 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 10:14:17 raspberrypi4 volumio[864]: info: CURURI: music-library/NAS/AS3102T-1F48/Music Files/Music Directory Oct 12 10:14:17 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:21 raspberrypi4 volumio[864]: Searching plugin music_service/mpd Oct 12 10:14:21 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 12 10:14:23 raspberrypi4 volumio[864]: info: Received Get System Version Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 10:14:23 raspberrypi4 volumio[864]: info: Received Get System Info Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 10:14:23 raspberrypi4 volumio[864]: info: Discovery: Getting this device information Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::volumioGetState Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CorePlayQueue::getTrack 5 Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 10:14:23 raspberrypi4 volumio[864]: Searching plugin music_service/mpd Oct 12 10:14:23 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 12 10:14:24 raspberrypi4 volumio[864]: info: All search sources collected, pushing search results Oct 12 10:14:24 raspberrypi4 volumio[864]: Searching plugin music_service/mpd Oct 12 10:14:24 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 12 10:14:24 raspberrypi4 volumio[864]: info: All search sources collected, pushing search results Oct 12 10:14:24 raspberrypi4 volumio[864]: info: All search sources collected, pushing search results Oct 12 10:14:39 raspberrypi4 volumio[864]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 10:14:39 raspberrypi4 volumio[864]: info: CURURI: artists://Remix Oct 12 10:14:39 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:39 raspberrypi4 volumio[864]: info: Preload queue cleared Oct 12 10:14:39 raspberrypi4 volumio[864]: info: Preloading song: music-library/NAS/AS3102T-1F48/Music Files/Music Directory/Disco_Bollywood for Dance Party/its time to disco mix.mp3 Oct 12 10:14:39 raspberrypi4 volumio[864]: info: Exploding uri music-library/NAS/AS3102T-1F48/Music Files/Music Directory/Disco_Bollywood for Dance Party/its time to disco mix.mp3 in service mpd Oct 12 10:14:39 raspberrypi4 volumio[864]: info: ALBUMART /albumart?cacheid=137&web=Remix/bootleg/small&path=%2Fmnt%2FNAS%2FAS3102T-1F48%2FMusic%20Files%2FMusic%20Directory%2FDisco_Bollywood%20for%20Dance%20Party%2Fits%20time%20to%20disco%20mix.mp3&metadata=false Oct 12 10:14:39 raspberrypi4 volumio[864]: info: URI /mnt/NAS/AS3102T-1F48/Music Files/Music Directory/Disco_Bollywood for Dance Party/its time to disco mix.mp3 Oct 12 10:14:47 raspberrypi4 volumio[864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 10:14:47 raspberrypi4 volumio[864]: TypeError: Cannot read property 'slice' of null Oct 12 10:14:47 raspberrypi4 volumio[864]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Oct 12 10:14:47 raspberrypi4 volumio[864]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Oct 12 10:14:47 raspberrypi4 volumio[864]: at Object.onceWrapper (events.js:422:26) Oct 12 10:14:47 raspberrypi4 volumio[864]: at ClientRequest.emit (events.js:315:20) Oct 12 10:14:47 raspberrypi4 volumio[864]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Oct 12 10:14:47 raspberrypi4 volumio[864]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Oct 12 10:14:47 raspberrypi4 volumio[864]: at HTTPParser.execute () Oct 12 10:14:47 raspberrypi4 volumio[864]: at TLSSocket.socketOnData (_http_client.js:509:22) Oct 12 10:14:47 raspberrypi4 volumio[864]: at TLSSocket.emit (events.js:315:20) Oct 12 10:14:47 raspberrypi4 volumio[864]: at addChunk (internal/streams/readable.js:309:12) Oct 12 10:14:47 raspberrypi4 volumio[864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 10:14:47 raspberrypi4 sudo[6564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-10-12 10:13 Oct 12 10:14:47 raspberrypi4 sudo[6564]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"