Feb 12 13:05:03 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:03-05:00" level=debug msg="fetched chunk 5/13, size: 524288" uri="spotify:track:16QN8cBubEq706vNtPpOME" Feb 12 13:05:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 12 13:05:04 volumio-new-2026 volumio[7965]: info: CURURI: playlists Feb 12 13:05:04 volumio-new-2026 volumio[7965]: info: Listing playlists Feb 12 13:05:05 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:05 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:05-05:00" level=trace msg="sent dealer ping" Feb 12 13:05:05 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:05-05:00" level=trace msg="received dealer pong" Feb 12 13:05:15 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:15-05:00" level=debug msg="fetched chunk 6/13, size: 524288" uri="spotify:track:16QN8cBubEq706vNtPpOME" Feb 12 13:05:20 volumio-new-2026 sudo[9490]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:05:20 volumio-new-2026 sudo[9490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:05:20 volumio-new-2026 sudo[9490]: pam_unix(sudo:session): session closed for user root Feb 12 13:05:20 volumio-new-2026 sudo[9492]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:05:20 volumio-new-2026 sudo[9492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:05:20 volumio-new-2026 sudo[9492]: pam_unix(sudo:session): session closed for user root Feb 12 13:05:20 volumio-new-2026 volumio[7965]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.250 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Feb 12 13:05:20 volumio-new-2026 sudo[9496]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 13:05:20 volumio-new-2026 sudo[9496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:05:20 volumio-new-2026 sudo[9496]: pam_unix(sudo:session): session closed for user root Feb 12 13:05:20 volumio-new-2026 sudo[9498]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 13:05:20 volumio-new-2026 sudo[9498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 13:05:20 volumio-new-2026 sudo[9498]: pam_unix(sudo:session): session closed for user root Feb 12 13:05:20 volumio-new-2026 volumio[7965]: verbose: New Socket.io Connection to 192.168.1.197 from 192.168.1.250 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetVisibleSources Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetState Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetQueue Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreStateMachine::getQueue Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getQueue Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: Listing playlists Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: Received Get System Info Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: Discovery: Getting this device information Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetState Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetState Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 12 13:05:20 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 12 13:05:21 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: Received Get System Info Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: Discovery: Getting this device information Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetState Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: Received Get System Info Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: Discovery: Getting this device information Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetState Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:22 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 13:05:28 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:28-05:00" level=debug msg="fetched chunk 7/13, size: 524288" uri="spotify:track:16QN8cBubEq706vNtPpOME" Feb 12 13:05:30 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 12 13:05:33 volumio-new-2026 volumio[7965]: error: error Feb 12 13:05:33 volumio-new-2026 volumio[7965]: error: error Feb 12 13:05:35 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:35-05:00" level=trace msg="received accesspoint ping" Feb 12 13:05:35 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:35-05:00" level=trace msg="received accesspoint pong ack" Feb 12 13:05:35 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:35-05:00" level=trace msg="sent dealer ping" Feb 12 13:05:35 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:35-05:00" level=trace msg="received dealer pong" Feb 12 13:05:37 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: motherearthradio , handleBrowseUri Feb 12 13:05:37 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: Received Get System Version Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: Received Get System Info Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: Discovery: Getting this device information Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioGetState Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:39 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 12 13:05:40 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:40-05:00" level=debug msg="fetched chunk 8/13, size: 524288" uri="spotify:track:16QN8cBubEq706vNtPpOME" Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::ClearQueue Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::stop Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::stPlaybackTimer Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::updateTrackBlock Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrackBlock Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::serviceStop Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 1 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::serviceStop Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Spotify Stop Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: SPOTIFY STOP Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: {"status":"play","position":1,"title":"Love So Soft","artist":"Kelly Clarkson","album":"Meaning of Life","albumart":"https://i.scdn.co/image/ab67616d0000b2731b808f1c7fff4f3e81f79523","uri":"spotify:track:16QN8cBubEq706vNtPpOME","trackType":"spotify","codec":"ogg","seek":250,"duration":172,"samplerate":"320 kbps","bitdepth":"16 bit","repeat":true,"repeatSingle":false,"consume":false,"volume":80,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Sending Spotify command to local API: /player/pause Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::clearPlayQueue Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::saveQueue Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushQueue Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::addQueueItems Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::addQueueItems Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Adding Item to queue: webmer/0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Exploding uri webmer/0 in service motherearthradio Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushQueue Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::saveQueue Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::updateTrackBlock Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrackBlock Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPlay Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::play index 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::stop Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::play index undefined Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::startPlaybackTimer Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand stop Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand stop took 23 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand clear Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand clear took 6 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand consume 1 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: error: updateQueue error: null Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: options Feb 12 13:05:43 volumio-new-2026 volumio[7965]: error: updateQueue error: null Feb 12 13:05:43 volumio-new-2026 volumio[7965]: error: updateQueue error: null Feb 12 13:05:43 volumio-new-2026 volumio[7965]: error: updateQueue error: null Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 16ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand consume 1 took 13 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 13ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 11ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 9ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: [1770919543509] [MotherEarth] set to consume mode, adding url: https://motherearth.streamserver24.com/listen/motherearth/motherearth Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand add "https://motherearth.streamserver24.com/listen/motherearth/motherearth" Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: options Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: options Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: options Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:43 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:43-05:00" level=debug msg="pause track at 64608ms" Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 28 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand add "https://motherearth.streamserver24.com/listen/motherearth/motherearth" took 27 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 21 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 20 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 17 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand play Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 68ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 69ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 68ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 69ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:43-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:43 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 69ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: sendMpdCommand play took 58 milliseconds Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 14ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 7ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: ------------------------------ 5ms Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:05:43 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:43-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 12 13:05:43 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:05:43-05:00" level=trace msg="emitting websocket event: paused" Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:4Tn2llBm1g0UlWctmgPL8Z","uri":"spotify:track:16QN8cBubEq706vNtPpOME","play_origin":"go-librespot"}} Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: PUSH STATE SPOTIFY Feb 12 13:05:43 volumio-new-2026 volumio[7965]: SPOTIFY: {"status":"pause","service":"spop","title":"Love So Soft","artist":"Kelly Clarkson","album":"Meaning of Life","albumart":"https://i.scdn.co/image/ab67616d00001e021b808f1c7fff4f3e81f79523","uri":"spotify:track:16QN8cBubEq706vNtPpOME","trackType":"spotify","seek":65000,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:43 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received spop Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"play","service":"motherearthradio","type":"webradio","trackType":"flac","radioType":"mer","albumart":"https://motherearth.streamserver24.com/api/station/motherearth/art/5aa07011a9a63d06079fed22-1769465217.jpg","uri":"https://motherearth.streamserver24.com/listen/motherearth/motherearth","name":"Jack Johnson - In Between Dreams - Banana Pancakes","title":"Banana Pancakes","artist":"Jack Johnson","album":"In Between Dreams","streaming":true,"disableUiControls":true,"duration":121,"seek":0,"bitdepth":"24 bit","channels":2} Feb 12 13:05:44 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService play Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: [1770919544450] [MotherEarth] setting new timer with duration of 121000 seconds. Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: Prefetching next song Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:44 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:44 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:44 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:44 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:44 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:44 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:44 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:44 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: FusionDsp - ---- read samplerate from file: 192000 Feb 12 13:05:44 volumio-new-2026 volumio[7965]: info: camilladsp stopping service pid 9535... Feb 12 13:05:45 volumio-new-2026 volumio[7965]: grep: /proc/9535/cmdline: binary file matches Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: camilladsp service terminated, instance 1 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: camilladsp service started and running in background, instance 1 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: FusionDsp - ---- read samplerate from file: 192000 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 170 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 168 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 166 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 164 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 17 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 15 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 11 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 9 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 7 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 206ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 203ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 201ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 198ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: error: FusionDsp - Reload WebSocket error: [object Object] Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 31 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 27 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 27 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 27 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 66ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 56ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 54ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 52ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces system playlist update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Ignoring MPD Status Update Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Feb 12 13:05:45 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 27ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 17 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 16ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 15 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 14ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 7 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 15ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 11 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 39ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 35ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 30ms Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 12 13:05:45 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd Feb 12 13:05:45 volumio-new-2026 volumio[7965]: info: ------------------------------ 27ms Feb 12 13:05:55 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 12 13:05:55 volumio-new-2026 volumio[7965]: info: In handleBrowseUri, curUri=spotify Feb 12 13:05:55 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:55 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:55 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:05:55 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::ClearQueue Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::stPlaybackTimer Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::updateTrackBlock Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrackBlock Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::serviceStop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::serviceStop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::clearPlayQueue Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::saveQueue Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushQueue Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::addQueueItems Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::addQueueItems Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Preload queue cleared Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DXcBWIGoYBM5M Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Exploding uri spotify:playlist:37i9dQZF1DXcBWIGoYBM5M in service spop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DXcBWIGoYBM5M Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:02 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Feb 12 13:06:02 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand stop took 35 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"stop","service":"motherearthradio","type":"webradio","trackType":"flac","radioType":"mer","albumart":"https://motherearth.streamserver24.com/api/station/motherearth/art/5aa07011a9a63d06079fed22-1769465217.jpg","uri":"https://motherearth.streamserver24.com/listen/motherearth/motherearth","name":"Jack Johnson - In Between Dreams - Banana Pancakes","title":"Banana Pancakes","artist":"Jack Johnson","album":"In Between Dreams","streaming":true,"disableUiControls":true,"duration":121,"seek":0,"bitdepth":"24 bit","channels":2} Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: No code Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Feb 12 13:06:02 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Feb 12 13:06:02 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: Feb 12 13:06:02 volumio-new-2026 volumio[7965]: ---------------------------- MPD announces state update: player Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::getState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand status Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:02 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 71 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 45 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 44 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand status took 41 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: ControllerMpd::parseTrackInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"motherearth","artist":"Mother Earth Radio","album":null,"uri":"https://motherearth.streamserver24.com/listen/motherearth/motherearth","trackType":""} Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: No code Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"motherearth","artist":"Mother Earth Radio","album":null,"uri":"https://motherearth.streamserver24.com/listen/motherearth/motherearth","trackType":""} Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: No code Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"motherearth","artist":"Mother Earth Radio","album":null,"uri":"https://motherearth.streamserver24.com/listen/motherearth/motherearth","trackType":""} Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: No code Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: ControllerMpd::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"motherearth","artist":"Mother Earth Radio","album":null,"uri":"https://motherearth.streamserver24.com/listen/motherearth/motherearth","trackType":""} Feb 12 13:06:02 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: No code Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:02 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: ------------------------------ 163ms Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: ------------------------------ 138ms Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: ------------------------------ 136ms Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: ------------------------------ 135ms Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is not playing Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipped samples monitor stopped Feb 12 13:06:03 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:03-05:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DXcBWIGoYBM5M" Feb 12 13:06:03 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:03-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 12 13:06:03 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:03-05:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DXcBWIGoYBM5M" Feb 12 13:06:03 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:03-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 12 13:06:03 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushQueue Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::saveQueue Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::updateTrackBlock Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrackBlock Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPlay Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::play index 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::stop Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::play index undefined Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::startPlaybackTimer Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: [1770919564006] ControllerSpotify::clearAddPlayTrack Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: Sending Spotify command with payload to local API: /player/play Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="resolved context of track" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=trace msg="emitting websocket event: will_play" Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","play_origin":"go-librespot"}} Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="selected format OGG_VORBIS_320 (fc1bde0a4e1eb3a242a3c5d1f621b94b2f6411a3)" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="requested aes key for file fc1bde0a4e1eb3a242a3c5d1f621b94b2f6411a3, gid: 3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="fetched first chunk of 23, total size is 11879291 bytes" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=info msg="loaded track \"DtMF\" (paused: false, position: 0ms, duration: 237117ms, prefetched: false)" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: camilladsp stopping service pid 9586... Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=trace msg="scheduling prefetch in 207s" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=trace msg="emitting websocket event: metadata" Feb 12 13:06:04 volumio-new-2026 volumio[7965]: grep: /proc/9586/cmdline: binary file matches Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: camilladsp service terminated, instance 1 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: camilladsp service started and running in background, instance 1 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","name":"DtMF","artist_names":["Bad Bunny"],"album_name":"DeBÍ TiRAR MáS FOToS","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bbd45c8d36e0e045ef640411","position":0,"duration":237117,"release_date":"year:2025 month:1 day:5","track_number":16,"disc_number":1}} Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=trace msg="emitting websocket event: playing" Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","resume":false,"play_origin":"go-librespot"}} Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: PUSH STATE SPOTIFY Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: {"status":"play","service":"spop","title":"DtMF","artist":"Bad Bunny","album":"DeBÍ TiRAR MáS FOToS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbd45c8d36e0e045ef640411","uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","trackType":"spotify","seek":0,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DtMF","artist":"Bad Bunny","album":"DeBÍ TiRAR MáS FOToS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbd45c8d36e0e045ef640411","uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","trackType":"spotify","seek":0,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 12 13:06:04 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService play Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus stop Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:04-05:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: PUSH STATE SPOTIFY Feb 12 13:06:04 volumio-new-2026 volumio[7965]: SPOTIFY: {"status":"play","service":"spop","title":"DtMF","artist":"Bad Bunny","album":"DeBÍ TiRAR MáS FOToS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbd45c8d36e0e045ef640411","uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","trackType":"spotify","seek":0,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::servicePushState Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DtMF","artist":"Bad Bunny","album":"DeBÍ TiRAR MáS FOToS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbd45c8d36e0e045ef640411","uri":"spotify:track:3sK8wGT43QFpWrvNQsrQya","trackType":"spotify","seek":0,"duration":237,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 12 13:06:04 volumio-new-2026 volumio[7965]: verbose: CURRENT POSITION 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState stateService play Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::syncState currentStatus play Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: Received an update from plugin. extracting info from payload Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreStateMachine::pushState Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CorePlayQueue::getTrack 0 Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::volumioPushState Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is playing Feb 12 13:06:04 volumio-new-2026 volumio[7965]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Feb 12 13:06:04 volumio-new-2026 volumio[7965]: info: FusionDsp - Volumio is playing Feb 12 13:06:05 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:05 volumio-new-2026 volumio[7965]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Feb 12 13:06:05 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipping Monitor started Feb 12 13:06:05 volumio-new-2026 volumio[7965]: info: FusionDsp - Clipping Monitor started Feb 12 13:06:05 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:05-05:00" level=trace msg="sent dealer ping" Feb 12 13:06:05 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:05-05:00" level=trace msg="received dealer pong" Feb 12 13:06:17 volumio-new-2026 volumio[7965]: Searching plugin music_service/spop Feb 12 13:06:17 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 13:06:18 volumio-new-2026 volumio[7965]: info: All search sources collected, pushing search results Feb 12 13:06:18 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:18-05:00" level=debug msg="fetched chunk 4/22, size: 524288" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:19 volumio-new-2026 volumio[7965]: Searching plugin music_service/spop Feb 12 13:06:19 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 13:06:20 volumio-new-2026 volumio[7965]: info: All search sources collected, pushing search results Feb 12 13:06:23 volumio-new-2026 volumio[7965]: Searching plugin music_service/spop Feb 12 13:06:23 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 13:06:24 volumio-new-2026 volumio[7965]: info: All search sources collected, pushing search results Feb 12 13:06:24 volumio-new-2026 volumio[7965]: Searching plugin music_service/spop Feb 12 13:06:24 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 12 13:06:25 volumio-new-2026 volumio[7965]: info: All search sources collected, pushing search results Feb 12 13:06:28 volumio-new-2026 volumio[7965]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 12 13:06:28 volumio-new-2026 volumio[7965]: info: In handleBrowseUri, curUri=spotify:artist:6aOJnh4q3g9dHvzH71Aahu Feb 12 13:06:28 volumio-new-2026 go-librespot[8193]: time="2026-02-12T13:06:28-05:00" level=debug msg="fetched chunk 5/22, size: 524288" uri="spotify:track:3sK8wGT43QFpWrvNQsrQya" Feb 12 13:06:29 volumio-new-2026 volumio[7965]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:06:29 volumio-new-2026 volumio[7965]: TypeError: Cannot read properties of undefined (reading 'url') Feb 12 13:06:29 volumio-new-2026 volumio[7965]: at /data/plugins/music_service/spop/index.js:2446:60 Feb 12 13:06:29 volumio-new-2026 volumio[7965]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 12 13:06:29 volumio-new-2026 volumio[7965]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 13:06:29 volumio-new-2026 sudo[9668]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 13:05' Feb 12 13:06:29 volumio-new-2026 sudo[9668]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"