May 27 11:29:00 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:07 volumio go-librespot[1972]: time="2026-05-27T11:29:07+02:00" level=trace msg="sent dealer ping" May 27 11:29:07 volumio go-librespot[1972]: time="2026-05-27T11:29:07+02:00" level=trace msg="received dealer pong" May 27 11:29:09 volumio bluealsa[940]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_57_C2_38_C3_CD_A3, ...) May 27 11:29:10 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:10 volumio volumio[1355]: info: Listing playlists May 27 11:29:10 volumio volumio[1355]: info: Listing playlists May 27 11:29:18 volumio volumio[1355]: info: May 27 11:29:18 volumio volumio[1355]: ---------------------------- MPD announces system playlist update May 27 11:29:18 volumio volumio[1355]: info: Ignoring MPD Status Update May 27 11:29:18 volumio volumio[1355]: info: May 27 11:29:18 volumio volumio[1355]: ---------------------------- MPD announces state update: player May 27 11:29:18 volumio volumio[1355]: info: ControllerMpd::getState May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::sendMpdCommand status May 27 11:29:18 volumio volumio[1355]: info: May 27 11:29:18 volumio volumio[1355]: ---------------------------- MPD announces system playlist update May 27 11:29:18 volumio volumio[1355]: info: Ignoring MPD Status Update May 27 11:29:18 volumio volumio[1355]: info: May 27 11:29:18 volumio volumio[1355]: ---------------------------- MPD announces state update: player May 27 11:29:18 volumio volumio[1355]: info: ControllerMpd::getState May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::sendMpdCommand status May 27 11:29:18 volumio volumio[1355]: info: May 27 11:29:18 volumio volumio[1355]: ---------------------------- MPD announces system playlist update May 27 11:29:18 volumio volumio[1355]: info: Ignoring MPD Status Update May 27 11:29:18 volumio volumio[1355]: info: May 27 11:29:18 volumio volumio[1355]: ---------------------------- MPD announces state update: player May 27 11:29:18 volumio volumio[1355]: info: ControllerMpd::getState May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::sendMpdCommand status May 27 11:29:18 volumio volumio[1355]: info: ------------------------------ 5ms May 27 11:29:18 volumio volumio[1355]: info: sendMpdCommand status took 3 milliseconds May 27 11:29:18 volumio volumio[1355]: info: ------------------------------ 3ms May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::parseState May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 11:29:18 volumio volumio[1355]: info: sendMpdCommand status took 4 milliseconds May 27 11:29:18 volumio volumio[1355]: info: ------------------------------ 3ms May 27 11:29:18 volumio volumio[1355]: info: sendMpdCommand status took 3 milliseconds May 27 11:29:18 volumio volumio[1355]: info: sendMpdCommand playlistinfo took 2 milliseconds May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::parseState May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::parseState May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::parseTrackInfo May 27 11:29:18 volumio volumio[1355]: info: ControllerMpd::pushState May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::servicePushState May 27 11:29:18 volumio volumio[1355]: info: CorePlayQueue::getTrack 0 May 27 11:29:18 volumio volumio[1355]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2141306,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"The Kid LAROI - Girls","artist":"BASE FM","album":null,"uri":"https://icast.connectmedia.hu/5401/live.mp3","trackType":"mp3"} May 27 11:29:18 volumio volumio[1355]: verbose: CURRENT POSITION 0 May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::syncState stateService play May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::syncState currentStatus play May 27 11:29:18 volumio volumio[1355]: info: Received an update from plugin. extracting info from payload May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::pushState May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::volumioPushState May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::pushState May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::volumioPushState May 27 11:29:18 volumio volumio[1355]: info: ------------------------------ 17ms May 27 11:29:18 volumio volumio[1355]: info: sendMpdCommand playlistinfo took 12 milliseconds May 27 11:29:18 volumio volumio[1355]: info: sendMpdCommand playlistinfo took 12 milliseconds May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::parseTrackInfo May 27 11:29:18 volumio volumio[1355]: verbose: ControllerMpd::parseTrackInfo May 27 11:29:18 volumio volumio[1355]: info: ControllerMpd::pushState May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::servicePushState May 27 11:29:18 volumio volumio[1355]: info: CorePlayQueue::getTrack 0 May 27 11:29:18 volumio volumio[1355]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2141306,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"The Kid LAROI - Girls","artist":"BASE FM","album":null,"uri":"https://icast.connectmedia.hu/5401/live.mp3","trackType":"mp3"} May 27 11:29:18 volumio volumio[1355]: verbose: CURRENT POSITION 0 May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::syncState stateService play May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::syncState currentStatus play May 27 11:29:18 volumio volumio[1355]: info: Received an update from plugin. extracting info from payload May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 27 11:29:18 volumio volumio[1355]: info: CoreStateMachine::pushState May 27 11:29:18 volumio volumio[1355]: info: CoreCommandRouter::volumioPushState May 27 11:29:19 volumio volumio[1355]: info: CoreStateMachine::pushState May 27 11:29:19 volumio volumio[1355]: info: CoreCommandRouter::volumioPushState May 27 11:29:19 volumio volumio[1355]: info: ControllerMpd::pushState May 27 11:29:19 volumio volumio[1355]: info: CoreCommandRouter::servicePushState May 27 11:29:19 volumio volumio[1355]: info: CorePlayQueue::getTrack 0 May 27 11:29:19 volumio volumio[1355]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2141306,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"The Kid LAROI - Girls","artist":"BASE FM","album":null,"uri":"https://icast.connectmedia.hu/5401/live.mp3","trackType":"mp3"} May 27 11:29:19 volumio volumio[1355]: verbose: CURRENT POSITION 0 May 27 11:29:19 volumio volumio[1355]: info: CoreStateMachine::syncState stateService play May 27 11:29:19 volumio volumio[1355]: info: CoreStateMachine::syncState currentStatus play May 27 11:29:19 volumio volumio[1355]: info: Received an update from plugin. extracting info from payload May 27 11:29:19 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 27 11:29:19 volumio volumio[1355]: info: CoreStateMachine::pushState May 27 11:29:19 volumio volumio[1355]: info: CoreCommandRouter::volumioPushState May 27 11:29:19 volumio volumio[1355]: info: CoreStateMachine::pushState May 27 11:29:19 volumio volumio[1355]: info: CoreCommandRouter::volumioPushState May 27 11:29:19 volumio volumio[1355]: info: ------------------------------ 32ms May 27 11:29:19 volumio volumio[1355]: info: ------------------------------ 32ms May 27 11:29:19 volumio volumio[1355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 May 27 11:29:19 volumio volumio[1355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 May 27 11:29:19 volumio volumio[1355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 May 27 11:29:19 volumio volumio[1355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 May 27 11:29:19 volumio volumio[1355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 May 27 11:29:19 volumio volumio[1355]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 May 27 11:29:20 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:30 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:30 volumio volumio[1355]: info: Listing playlists May 27 11:29:30 volumio volumio[1355]: info: Listing playlists May 27 11:29:31 volumio bluealsa[940]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_C2_C4_4A_F3_88_7F, ...) May 27 11:29:32 volumio bluealsa[940]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_0B_CC_37_BE_A8_77, ...) May 27 11:29:37 volumio go-librespot[1972]: time="2026-05-27T11:29:37+02:00" level=trace msg="sent dealer ping" May 27 11:29:37 volumio go-librespot[1972]: time="2026-05-27T11:29:37+02:00" level=trace msg="received dealer pong" May 27 11:29:40 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:49 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. May 27 11:29:49 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... May 27 11:29:49 volumio systemd[1]: welcome.service: Deactivated successfully. May 27 11:29:49 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 27 11:29:49 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 27 11:29:49 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 27 11:29:49 volumio welcome[1453]: Resolved ip:[2] 192.168.10.193 172.17.0.1 May 27 11:29:49 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 27 11:29:49 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. May 27 11:29:49 volumio volumio[1355]: info: Received Get System Info May 27 11:29:49 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 27 11:29:49 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 27 11:29:49 volumio volumio[1355]: info: Discovery: Getting this device information May 27 11:29:49 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:49 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 27 11:29:49 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 27 11:29:49 volumio volumio[1355]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 27 11:29:50 volumio volumio5-onboarding[1935]: time=2026-05-27T11:29:50.624+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 27 11:29:50 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:29:50 volumio volumio[1355]: info: Listing playlists May 27 11:29:50 volumio volumio[1355]: info: Listing playlists May 27 11:30:00 volumio volumio[1355]: info: CoreCommandRouter::volumioGetState May 27 11:30:01 volumio bluealsa[940]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_C2_C4_4A_F3_88_7F, ...) May 27 11:30:01 volumio volumio[1355]: info: [ytcr] Refresh session PO token May 27 11:30:01 volumio volumio[1355]: info: [ytcr] Obtained session PO token using visitorData (expires in 43103 seconds) May 27 11:30:01 volumio volumio[1355]: info: [ytcr] Going to refresh session PO token in 43003 seconds May 27 11:30:01 volumio volumio[1355]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 11:30:01 volumio volumio[1355]: TypeError: Chaining cycle detected for promise # May 27 11:30:01 volumio volumio[1355]: at InnertubeWrapper._InnertubeWrapper_doGetSessionPoToken (/data/plugins/music_service/ytcr/node_modules/volumio-yt-support/dist/lib/innertube/Wrapper.js:187:12) May 27 11:30:01 volumio volumio[1355]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) May 27 11:30:01 volumio volumio[1355]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 11:30:03 volumio bluealsa[940]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_0B_CC_37_BE_A8_77, ...) May 27 11:30:03 volumio sudo[1528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 11:29' May 27 11:30:03 volumio sudo[1528]: 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"