Aug 29 11:57:03 cebmusic systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 124373.
Aug 29 11:57:03 cebmusic systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:03 cebmusic systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:03 cebmusic upmpdcli[7430]: Could not open config: /tmp/upmpdcli.conf
Aug 29 11:57:03 cebmusic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 11:57:03 cebmusic systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 29 11:57:18 cebmusic systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 124374.
Aug 29 11:57:18 cebmusic systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:18 cebmusic systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:18 cebmusic upmpdcli[7446]: Could not open config: /tmp/upmpdcli.conf
Aug 29 11:57:18 cebmusic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 11:57:18 cebmusic systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 29 11:57:19 cebmusic volumio[1374]: info: Tunnel connection is inactive, restarting it
Aug 29 11:57:19 cebmusic volumio[1374]: info: Starting Tunnel 1
Aug 29 11:57:19 cebmusic volumio[1374]: info: Starting Tunnel Connection Checker
Aug 29 11:57:19 cebmusic sudo[7469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Aug 29 11:57:19 cebmusic sudo[7469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Aug 29 11:57:19 cebmusic autossh[7172]: received signal to exit (15)
Aug 29 11:57:19 cebmusic systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel...
Aug 29 11:57:19 cebmusic systemd[1]: sshtunnel.service: Deactivated successfully.
Aug 29 11:57:19 cebmusic systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel.
Aug 29 11:57:20 cebmusic systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Aug 29 11:57:20 cebmusic sudo[7469]: pam_unix(sudo:session): session closed for user root
Aug 29 11:57:20 cebmusic autossh[7472]: port set to 0, monitoring disabled
Aug 29 11:57:20 cebmusic autossh[7472]: starting ssh (count 1)
Aug 29 11:57:20 cebmusic autossh[7472]: ssh child pid is 7475
Aug 29 11:57:20 cebmusic volumio[1374]: info: Remote SSH Started
Aug 29 11:57:20 cebmusic volumio[1374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6
Aug 29 11:57:20 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetState
Aug 29 11:57:20 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:57:20 cebmusic volumiossh-tunnel[7475]: Warning: Permanently added '[eu6.myvolumio.org]:2222' (RSA) to the list of known hosts.
Aug 29 11:57:33 cebmusic systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 124375.
Aug 29 11:57:33 cebmusic systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:33 cebmusic systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:33 cebmusic upmpdcli[7491]: Could not open config: /tmp/upmpdcli.conf
Aug 29 11:57:33 cebmusic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 11:57:33 cebmusic systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 29 11:57:49 cebmusic systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 124376.
Aug 29 11:57:49 cebmusic systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:49 cebmusic systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:57:49 cebmusic upmpdcli[7521]: Could not open config: /tmp/upmpdcli.conf
Aug 29 11:57:49 cebmusic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 11:57:49 cebmusic systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 29 11:57:59 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:57:59.937+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.035+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=97.191911ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.035+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=http://pushupdates.volumio.org duration=96.37076ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.128+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://www.googleapis.com duration=190.929107ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.128+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=190.937348ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.159+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=221.452101ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.238+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://securetoken.googleapis.com duration=300.425116ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.244+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://functions.volumio.cloud duration=305.694634ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.244+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://functions.volumio.cloud duration=305.642171ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.287+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://database.volumio.cloud duration=349.205285ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.290+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://google.com duration=352.264925ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.309+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=370.955601ms
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.492+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=http://cddb.volumio.org duration=553.726827ms
Aug 29 11:58:00 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 11:58:00 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 11:58:00 cebmusic volumio[1374]: info: Discovery: Getting this device information
Aug 29 11:58:00 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetState
Aug 29 11:58:00 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:00 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 11:58:00 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:00.535+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" latency=310.87316ms timeout=10s endpoint=http://plugins.volumio.org duration=597.285627ms
Aug 29 11:58:00 cebmusic volumio[1374]: verbose: New Socket.io Connection to 192.168.1.29:3000 from 192.168.1.166 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6
Aug 29 11:58:00 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Aug 29 11:58:00 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Aug 29 11:58:01 cebmusic volumio[1374]: verbose: New Socket.io Connection to 192.168.1.29 from 192.168.1.166 UA: Mozilla/5.0 (Linux; Android 16; SM-X210 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/151.0.7922.199 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetState
Aug 29 11:58:01 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Aug 29 11:58:01 cebmusic volumio[1374]: info: Received Get System Info
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 11:58:01 cebmusic volumio[1374]: info: Discovery: Getting this device information
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetState
Aug 29 11:58:01 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetState
Aug 29 11:58:01 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:01 cebmusic volumio[1374]: info: Listing playlists
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetQueue
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreStateMachine::getQueue
Aug 29 11:58:01 cebmusic volumio[1374]: info: CorePlayQueue::getQueue
Aug 29 11:58:01 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Aug 29 11:58:03 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Aug 29 11:58:03 cebmusic volumio[1374]: info: Received Get System Info
Aug 29 11:58:03 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 29 11:58:03 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 29 11:58:03 cebmusic volumio[1374]: info: Discovery: Getting this device information
Aug 29 11:58:03 cebmusic volumio[1374]: info: CoreCommandRouter::volumioGetState
Aug 29 11:58:03 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:03 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 29 11:58:04 cebmusic systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 124377.
Aug 29 11:58:04 cebmusic systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:58:04 cebmusic systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Aug 29 11:58:04 cebmusic upmpdcli[7538]: Could not open config: /tmp/upmpdcli.conf
Aug 29 11:58:04 cebmusic systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Aug 29 11:58:04 cebmusic systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Aug 29 11:58:05 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Aug 29 11:58:05 cebmusic volumio[1374]: info: Preload queue cleared
Aug 29 11:58:07 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Aug 29 11:58:07 cebmusic volumio[1374]: info: Preload queue cleared
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreCommandRouter::volumioReplaceandPlayItems
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::ClearQueue
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::stop
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::clearPlayQueue
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::saveQueue
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushQueue
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::addQueueItems
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::addQueueItems
Aug 29 11:58:11 cebmusic volumio[1374]: info: Preload queue cleared
Aug 29 11:58:11 cebmusic volumio[1374]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99611259
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushQueue
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::saveQueue
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::updateTrackBlock
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::getTrackBlock
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPlay
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::play index 0
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::stop
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::play index undefined
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::startPlaybackTimer
Aug 29 11:58:11 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:11 cebmusic volumio[1374]: info: [1787997491117] ControllerWebradio::clearAddPlayTrack
Aug 29 11:58:11 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand stop
Aug 29 11:58:11 cebmusic volumio[1374]: info: sendMpdCommand stop took 1 milliseconds
Aug 29 11:58:11 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand clear
Aug 29 11:58:11 cebmusic volumio[1374]: info:
Aug 29 11:58:11 cebmusic volumio[1374]: ---------------------------- MPD announces system playlist update
Aug 29 11:58:11 cebmusic volumio[1374]: info: Ignoring MPD Status Update
Aug 29 11:58:11 cebmusic volumio[1374]: info: sendMpdCommand clear took 0 milliseconds
Aug 29 11:58:11 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99611259"
Aug 29 11:58:11 cebmusic volumio[1374]: error: updateQueue error: null
Aug 29 11:58:11 cebmusic volumio[1374]: info: ------------------------------ 1ms
Aug 29 11:58:11 cebmusic volumio[1374]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99611259" took 360 milliseconds
Aug 29 11:58:11 cebmusic volumio[1374]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 29 11:58:11 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand play
Aug 29 11:58:11 cebmusic volumio[1374]: info:
Aug 29 11:58:11 cebmusic volumio[1374]: ---------------------------- MPD announces system playlist update
Aug 29 11:58:11 cebmusic volumio[1374]: info: Ignoring MPD Status Update
Aug 29 11:58:11 cebmusic volumio[1374]: info: sendMpdCommand play took 1 milliseconds
Aug 29 11:58:11 cebmusic volumio[1374]: info: ------------------------------ 1ms
Aug 29 11:58:12 cebmusic volumio[1374]: info:
Aug 29 11:58:12 cebmusic volumio[1374]: ---------------------------- MPD announces state update: player
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::getState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 11:58:12 cebmusic volumio[1374]: info:
Aug 29 11:58:12 cebmusic volumio[1374]: ---------------------------- MPD announces state update: player
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand status took 3 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::getState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand status took 0 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand playlistinfo took 0 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseTrackInfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::servicePushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":"(#1 - 78/600) A MISSISSIPPI BLUES","album":null,"uri":"https://cast1.torontocast.com:4450/","trackType":"com:4450/"}
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: CURRENT POSITION 0
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState stateService play
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState currentStatus stop
Aug 29 11:58:12 cebmusic volumio[1374]: info: ------------------------------ 5ms
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand playlistinfo took 1 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseTrackInfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::servicePushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"","artist":"(#1 - 78/600) A MISSISSIPPI BLUES","album":null,"uri":"https://cast1.torontocast.com:4450/","trackType":"com:4450/"}
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: CURRENT POSITION 0
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState stateService play
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState currentStatus play
Aug 29 11:58:12 cebmusic volumio[1374]: info: Received an update from plugin. extracting info from payload
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushState
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.212+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" state=STATUS_PLAYING positionMs=0 volume=100
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.212+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" id=https://cast1.torontocast.com:4450/ title=
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.212+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" state=STATUS_PLAYING positionMs=0 volume=100
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.213+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" id=https://cast1.torontocast.com:4450/ title=
Aug 29 11:58:12 cebmusic volumio[1374]: info: ------------------------------ 5ms
Aug 29 11:58:12 cebmusic volumio[1374]: info:
Aug 29 11:58:12 cebmusic volumio[1374]: ---------------------------- MPD announces system playlist update
Aug 29 11:58:12 cebmusic volumio[1374]: info: Ignoring MPD Status Update
Aug 29 11:58:12 cebmusic volumio[1374]: info:
Aug 29 11:58:12 cebmusic volumio[1374]: ---------------------------- MPD announces state update: player
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::getState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 11:58:12 cebmusic volumio[1374]: info:
Aug 29 11:58:12 cebmusic volumio[1374]: ---------------------------- MPD announces system playlist update
Aug 29 11:58:12 cebmusic volumio[1374]: info: Ignoring MPD Status Update
Aug 29 11:58:12 cebmusic volumio[1374]: info:
Aug 29 11:58:12 cebmusic volumio[1374]: ---------------------------- MPD announces state update: player
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::getState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand status
Aug 29 11:58:12 cebmusic volumio[1374]: info: ------------------------------ 1ms
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand status took 1 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: ------------------------------ 1ms
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand status took 0 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseState
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand playlistinfo took 1 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: info: sendMpdCommand playlistinfo took 0 milliseconds
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseTrackInfo
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: ControllerMpd::parseTrackInfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::servicePushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Julian Sas - Blues for the Lost and Found","artist":"A MISSISSIPPI BLUES","album":null,"uri":"https://cast1.torontocast.com:4450/","trackType":"com:4450/"}
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: CURRENT POSITION 0
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState stateService play
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState currentStatus play
Aug 29 11:58:12 cebmusic volumio[1374]: info: Received an update from plugin. extracting info from payload
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: ControllerMpd::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::servicePushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CorePlayQueue::getTrack 0
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Julian Sas - Blues for the Lost and Found","artist":"A MISSISSIPPI BLUES","album":null,"uri":"https://cast1.torontocast.com:4450/","trackType":"com:4450/"}
Aug 29 11:58:12 cebmusic volumio[1374]: verbose: CURRENT POSITION 0
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState stateService play
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::syncState currentStatus play
Aug 29 11:58:12 cebmusic volumio[1374]: info: Received an update from plugin. extracting info from payload
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreStateMachine::pushState
Aug 29 11:58:12 cebmusic volumio[1374]: info: CoreCommandRouter::volumioPushState
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.437+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" state=STATUS_PLAYING positionMs=250 volume=100
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.437+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" id=https://cast1.torontocast.com:4450/ title="Julian Sas - Blues for the Lost and Found"
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.437+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" state=STATUS_PLAYING positionMs=250 volume=100
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.437+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" id=https://cast1.torontocast.com:4450/ title="Julian Sas - Blues for the Lost and Found"
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.437+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" state=STATUS_PLAYING positionMs=250 volume=100
Aug 29 11:58:12 cebmusic volumio[1374]: info: ------------------------------ 7ms
Aug 29 11:58:12 cebmusic volumio[1374]: info: ------------------------------ 6ms
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.438+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" id=https://cast1.torontocast.com:4450/ title="Julian Sas - Blues for the Lost and Found"
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.438+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" state=STATUS_PLAYING positionMs=250 volume=100
Aug 29 11:58:12 cebmusic volumio5-onboarding[1690]: time=2026-08-29T11:58:12.439+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.166:47578,00:00:00:00:00:00%06 @ 0x2916270" id=https://cast1.torontocast.com:4450/ title="Julian Sas - Blues for the Lost and Found"
Aug 29 11:58:14 cebmusic volumio[1374]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 29 11:58:14 cebmusic volumio[1374]: TypeError: Cannot read properties of null (reading 'slice')
Aug 29 11:58:14 cebmusic volumio[1374]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41)
Aug 29 11:58:14 cebmusic volumio[1374]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7)
Aug 29 11:58:14 cebmusic volumio[1374]: at Object.onceWrapper (node:events:629:26)
Aug 29 11:58:14 cebmusic volumio[1374]: at ClientRequest.emit (node:events:514:28)
Aug 29 11:58:14 cebmusic volumio[1374]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27)
Aug 29 11:58:14 cebmusic volumio[1374]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17)
Aug 29 11:58:14 cebmusic volumio[1374]: at TLSSocket.socketOnData (node:_http_client:535:22)
Aug 29 11:58:14 cebmusic volumio[1374]: at TLSSocket.emit (node:events:514:28)
Aug 29 11:58:14 cebmusic volumio[1374]: at addChunk (node:internal/streams/readable:343:12)
Aug 29 11:58:14 cebmusic volumio[1374]: at readableAddChunk (node:internal/streams/readable:316:9)
Aug 29 11:58:14 cebmusic volumio[1374]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 29 11:58:15 cebmusic sudo[7572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-29 11:57'
Aug 29 11:58:15 cebmusic sudo[7572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026"
VOLUMIO_VERSION="4.119"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"