Jan 11 15:21:04 volumio go-librespot[1765]: time="2026-01-11T15:21:04+01:00" level=trace msg="received accesspoint ping" Jan 11 15:21:04 volumio go-librespot[1765]: time="2026-01-11T15:21:04+01:00" level=trace msg="received accesspoint pong ack" Jan 11 15:21:05 volumio go-librespot[1765]: time="2026-01-11T15:21:05+01:00" level=trace msg="sent dealer ping" Jan 11 15:21:05 volumio go-librespot[1765]: time="2026-01-11T15:21:05+01:00" level=trace msg="received dealer pong" Jan 11 15:21:28 volumio volumio[1296]: verbose: New Socket.io Connection to 192.168.1.45:3000 from 192.168.1.58 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:28 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:28 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:28 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:28 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Jan 11 15:21:28 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 11 15:21:29 volumio sudo[2420]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 11 15:21:29 volumio sudo[2420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:29 volumio sudo[2432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 11 15:21:29 volumio sudo[2432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:29 volumio sudo[2420]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:29 volumio sudo[2425]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 11 15:21:29 volumio sudo[2425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:29 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:29 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:29 volumio sudo[2432]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:29 volumio volumio[1296]: verbose: New Socket.io Connection to 192.168.1.45:3000 from 192.168.1.58 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 11 15:21:29 volumio sudo[2425]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:29 volumio sudo[2441]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 15:21:29 volumio sudo[2441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:29 volumio sudo[2443]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 15:21:29 volumio sudo[2443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:29 volumio sudo[2436]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 11 15:21:29 volumio sudo[2436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:29 volumio sudo[2436]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:29 volumio sudo[2441]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:29 volumio sudo[2443]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:29 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:29 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:29 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:29 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:30 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:30 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:30 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:30 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:30 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:30 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:30 volumio volumio[1296]: verbose: New Socket.io Connection to 192.168.1.45:3000 from 192.168.1.58 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 11 15:21:30 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 11 15:21:30 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 11 15:21:31 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 11 15:21:31 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 11 15:21:32 volumio sudo[2459]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 15:21:32 volumio sudo[2459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:32 volumio sudo[2461]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 15:21:32 volumio sudo[2461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:32 volumio sudo[2461]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:32 volumio sudo[2459]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:32 volumio volumio[1296]: verbose: New Socket.io Connection to 192.168.1.45 from 192.168.1.58 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Jan 11 15:21:33 volumio sudo[2470]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 15:21:33 volumio sudo[2470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:33 volumio sudo[2468]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 15:21:33 volumio sudo[2468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:21:33 volumio sudo[2470]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:33 volumio sudo[2468]: pam_unix(sudo:session): session closed for user root Jan 11 15:21:33 volumio volumio[1296]: verbose: New Socket.io Connection to 192.168.1.45 from 192.168.1.58 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::volumioGetVisibleSources Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:34 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 11 15:21:34 volumio volumio[1296]: info: Received Get System Info Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:34 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:34 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:34 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:34 volumio volumio[1296]: info: Listing playlists Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 11 15:21:34 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 11 15:21:35 volumio go-librespot[1765]: time="2026-01-11T15:21:35+01:00" level=trace msg="sent dealer ping" Jan 11 15:21:35 volumio go-librespot[1765]: time="2026-01-11T15:21:35+01:00" level=trace msg="received dealer pong" Jan 11 15:21:35 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:21:35 volumio volumio[1296]: info: Received Get System Info Jan 11 15:21:35 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:35 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:35 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:35 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:35 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:35 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:35 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 11 15:21:36 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 11 15:21:38 volumio volumio[1296]: info: VolumeController::SetAlsaVolume45 Jan 11 15:21:38 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:21:38 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:21:38 volumio volumio[1296]: info: Received Get System Info Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:38 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:38 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:38 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:38 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Jan 11 15:21:38 volumio volumio[1296]: SPOTIFY: SPOTIFY VOLUME 100 Jan 11 15:21:38 volumio volumio[1296]: SPOTIFY: VOLUMIO VOLUME 45 Jan 11 15:21:38 volumio volumio[1296]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 11 15:21:38 volumio volumio[1296]: info: Setting Spotify Volume from Volumio: 45 Jan 11 15:21:39 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:39 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:39 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:39 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:39 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:39 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:39 volumio volumio[1296]: verbose: New Socket.io Connection to 192.168.1.45:3000 from 192.168.1.58 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Jan 11 15:21:39 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 11 15:21:39 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:21:40 volumio volumio[1296]: info: Received Get System Info Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:40 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:40 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:40 volumio volumio[1296]: SPOTIFY: SETTING SPOTIFY VOLUME 45 Jan 11 15:21:40 volumio volumio[1296]: info: Sending Spotify command with payload to local API: /player/volume Jan 11 15:21:40 volumio go-librespot[1765]: time="2026-01-11T15:21:40+01:00" level=debug msg="update volume requested to 29490/65535" Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:21:40 volumio volumio[1296]: info: Received Get System Info Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:40 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:40 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:40 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:21:40 volumio volumio[1296]: info: VolumeController::SetAlsaVolume23 Jan 11 15:21:41 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:21:41 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:41 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:21:41 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:21:41 volumio go-librespot[1765]: time="2026-01-11T15:21:41+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 11 15:21:41 volumio go-librespot[1765]: time="2026-01-11T15:21:41+01:00" level=trace msg="emitting websocket event: volume" Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: SPOTIFY VOLUME 45 Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: VOLUMIO VOLUME 23 Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 11 15:21:41 volumio volumio[1296]: info: Setting Spotify Volume from Volumio: 23 Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 Jan 11 15:21:41 volumio volumio[1296]: info: Setting Volumio Volume from Spotify: 45 Jan 11 15:21:41 volumio volumio[1296]: info: VolumeController::SetAlsaVolume45 Jan 11 15:21:41 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:21:41 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:41 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:21:41 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:21:41 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Jan 11 15:21:42 volumio volumio[1296]: SPOTIFY: SETTING SPOTIFY VOLUME 23 Jan 11 15:21:42 volumio volumio[1296]: info: Sending Spotify command with payload to local API: /player/volume Jan 11 15:21:42 volumio go-librespot[1765]: time="2026-01-11T15:21:42+01:00" level=debug msg="update volume requested to 15073/65535" Jan 11 15:21:42 volumio go-librespot[1765]: time="2026-01-11T15:21:42+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 11 15:21:42 volumio go-librespot[1765]: time="2026-01-11T15:21:42+01:00" level=trace msg="emitting websocket event: volume" Jan 11 15:21:42 volumio volumio[1296]: SPOTIFY: received: {"type":"volume","data":{"value":23,"max":100}} Jan 11 15:21:42 volumio volumio[1296]: SPOTIFY: RECEIVED SPOTIFY VOLUME 23 Jan 11 15:21:42 volumio volumio[1296]: info: Setting Volumio Volume from Spotify: 23 Jan 11 15:21:42 volumio volumio[1296]: info: VolumeController::SetAlsaVolume23 Jan 11 15:21:42 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:21:42 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:42 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:21:42 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:21:42 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:21:43 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 11 15:21:52 volumio volumio[1296]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 11 15:21:52 volumio volumio[1296]: info: Received Get System Version Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 15:21:52 volumio volumio[1296]: info: Received Get System Info Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 11 15:21:52 volumio volumio[1296]: info: Discovery: Getting this device information Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::volumioGetState Jan 11 15:21:52 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:21:52 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 15:22:03 volumio volumio[1296]: info: CoreCommandRouter::volumioPlay Jan 11 15:22:03 volumio volumio[1296]: info: CoreStateMachine::play index undefined Jan 11 15:22:03 volumio volumio[1296]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 11 15:22:03 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:03 volumio volumio[1296]: info: CoreStateMachine::startPlaybackTimer Jan 11 15:22:03 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:04 volumio volumio[1296]: info: [1768141324001] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/love/mp3-192/volumio Jan 11 15:22:04 volumio volumio[1296]: info: [1768141324002] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=85&count=2 Jan 11 15:22:04 volumio volumio[1296]: info: [1768141324937] [80s80s] received new event containing 2 songs. Jan 11 15:22:04 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand stop Jan 11 15:22:04 volumio volumio[1296]: info: sendMpdCommand stop took 57 milliseconds Jan 11 15:22:04 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand clear Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:05 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand clear took 3 milliseconds Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:05 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:05 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:05 volumio volumio[1296]: error: updateQueue error: null Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces state update: options Jan 11 15:22:05 volumio volumio[1296]: error: updateQueue error: null Jan 11 15:22:05 volumio volumio[1296]: error: updateQueue error: null Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 72ms Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand consume 1 took 69 milliseconds Jan 11 15:22:05 volumio go-librespot[1765]: time="2026-01-11T15:22:05+01:00" level=trace msg="sent dealer ping" Jan 11 15:22:05 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 64ms Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 63ms Jan 11 15:22:05 volumio volumio[1296]: info: [1768141325128] [80s80s] adding url: http://streams.80s80s.de/love/mp3-192/volumio Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/love/mp3-192/volumio" Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces state update: options Jan 11 15:22:05 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces state update: options Jan 11 15:22:05 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:05 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand status took 42 milliseconds Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand add "http://streams.80s80s.de/love/mp3-192/volumio" took 41 milliseconds Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand status took 40 milliseconds Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand status took 6 milliseconds Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand play Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:05 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:05 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:05 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:05 volumio go-librespot[1765]: time="2026-01-11T15:22:05+01:00" level=trace msg="received dealer pong" Jan 11 15:22:05 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:05 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:05 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:05 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 413ms Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 537ms Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 504ms Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:05 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:05 volumio volumio[1296]: info: Jan 11 15:22:05 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:05 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 533ms Jan 11 15:22:05 volumio volumio[1296]: info: sendMpdCommand play took 433 milliseconds Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 33ms Jan 11 15:22:05 volumio volumio[1296]: info: ------------------------------ 73ms Jan 11 15:22:05 volumio volumio[1296]: info: [1768141325748] [80s80s] Pushing the next song state: Depeche Mode - Somebody Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:05 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:05 volumio volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is5-ssl.mzstatic.com/image/thumb/Music114/v4/39/68/f6/3968f6da-b5da-615e-9e1d-4f625dcde426/source/600x600bb.jpg","name":"Depeche Mode - Somebody","title":"Somebody","artist":"80s80s Love","album":"","streaming":true,"disableUiControls":true,"duration":"202","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jan 11 15:22:05 volumio volumio[1296]: verbose: CURRENT POSITION 0 Jan 11 15:22:05 volumio volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 11 15:22:05 volumio volumio[1296]: info: CoreStateMachine::syncState currentStatus stop Jan 11 15:22:05 volumio volumio[1296]: info: [1768141325802] [80s80s] PlayNextTrack API delay: 30 Jan 11 15:22:05 volumio volumio[1296]: info: [1768141325891] [80s80s] Setting timer to: 9198 milliseconds. Jan 11 15:22:06 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:22:06 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:22:06 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 37 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 35 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 35 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 47 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 47 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 48 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 47 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 26 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 13 milliseconds Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 165ms Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 163ms Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 163ms Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 95 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 54 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 53 milliseconds Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 157ms Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 130ms Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 116ms Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:09 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:09 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:09 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:09 volumio volumio[1296]: info: Jan 11 15:22:09 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 57ms Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 33 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 33ms Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 12 milliseconds Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 37ms Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand status took 43 milliseconds Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 49 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 49 milliseconds Jan 11 15:22:09 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 18 milliseconds Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:09 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:09 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:09 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 146ms Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 132ms Jan 11 15:22:09 volumio volumio[1296]: info: ------------------------------ 103ms Jan 11 15:22:15 volumio volumio[1296]: info: [1768141335144] [80s80s] Pushing the next song state Depeche Mode - Somebody and getting next track. Jan 11 15:22:15 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:15 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:15 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:15 volumio volumio[1296]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is5-ssl.mzstatic.com/image/thumb/Music114/v4/39/68/f6/3968f6da-b5da-615e-9e1d-4f625dcde426/source/600x600bb.jpg","name":"Depeche Mode - Somebody","title":"Somebody","artist":"80s80s Love","album":"","streaming":true,"disableUiControls":true,"duration":"202","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jan 11 15:22:15 volumio volumio[1296]: verbose: CURRENT POSITION 0 Jan 11 15:22:15 volumio volumio[1296]: info: CoreStateMachine::syncState stateService play Jan 11 15:22:15 volumio volumio[1296]: info: CoreStateMachine::syncState currentStatus play Jan 11 15:22:15 volumio volumio[1296]: info: Received an update from plugin. extracting info from payload Jan 11 15:22:15 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:22:15 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:15 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 15:22:15 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:22:15 volumio volumio[1296]: info: CoreStateMachine::pushState Jan 11 15:22:15 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:15 volumio volumio[1296]: info: CoreCommandRouter::volumioPushState Jan 11 15:22:15 volumio volumio[1296]: info: [1768141335315] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=85&count=1 Jan 11 15:22:15 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:15 volumio volumio[1296]: info: CorePlayQueue::getTrack 1 Jan 11 15:22:15 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:22:15 volumio volumio[1296]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Jan 11 15:22:15 volumio volumio[1296]: error: touch_display: Error waking up the screen: Error: Command failed: /usr/bin/xset -display : s reset dpms force on Jan 11 15:22:15 volumio volumio[1296]: /usr/bin/xset: unable to open display ":" Jan 11 15:22:15 volumio volumio[1296]: error: touch_display: Error setting screensaver timeout: Error: ENOENT: no such file or directory, stat '/tmp/.X11-unix/X' Jan 11 15:22:17 volumio volumio[1296]: info: [1768141337495] [80s80s] received new event containing 1 songs. Jan 11 15:22:17 volumio volumio[1296]: info: [1768141337497] [80s80s] PlayNextTrack API delay: 30 Jan 11 15:22:17 volumio volumio[1296]: info: [1768141337501] [80s80s] Setting timer to: 202000 milliseconds. Jan 11 15:22:27 volumio volumio[1296]: info: Jan 11 15:22:27 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:27 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:27 volumio volumio[1296]: info: Jan 11 15:22:27 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:27 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:27 volumio volumio[1296]: info: Jan 11 15:22:27 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:27 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:27 volumio volumio[1296]: info: Jan 11 15:22:27 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:27 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:27 volumio volumio[1296]: info: Jan 11 15:22:27 volumio volumio[1296]: ---------------------------- MPD announces system playlist update Jan 11 15:22:27 volumio volumio[1296]: info: Ignoring MPD Status Update Jan 11 15:22:27 volumio volumio[1296]: info: Jan 11 15:22:27 volumio volumio[1296]: ---------------------------- MPD announces state update: player Jan 11 15:22:27 volumio volumio[1296]: info: ControllerMpd::getState Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand status Jan 11 15:22:27 volumio volumio[1296]: info: ------------------------------ 7ms Jan 11 15:22:27 volumio volumio[1296]: info: sendMpdCommand status took 6 milliseconds Jan 11 15:22:27 volumio volumio[1296]: info: ------------------------------ 5ms Jan 11 15:22:27 volumio volumio[1296]: info: sendMpdCommand status took 4 milliseconds Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:27 volumio volumio[1296]: info: ------------------------------ 8ms Jan 11 15:22:27 volumio volumio[1296]: info: sendMpdCommand status took 7 milliseconds Jan 11 15:22:27 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 11 15:22:27 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::parseState Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:27 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:27 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:27 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:27 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:27 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:27 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:27 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:27 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:27 volumio volumio[1296]: info: ------------------------------ 17ms Jan 11 15:22:27 volumio volumio[1296]: info: ------------------------------ 14ms Jan 11 15:22:27 volumio volumio[1296]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 11 15:22:27 volumio volumio[1296]: verbose: ControllerMpd::parseTrackInfo Jan 11 15:22:27 volumio volumio[1296]: info: ControllerMpd::pushState Jan 11 15:22:27 volumio volumio[1296]: info: CoreCommandRouter::servicePushState Jan 11 15:22:27 volumio volumio[1296]: info: CorePlayQueue::getTrack 0 Jan 11 15:22:27 volumio volumio[1296]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jan 11 15:22:27 volumio volumio[1296]: info: ------------------------------ 14ms Jan 11 15:22:33 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 11 15:22:33 volumio volumio[1296]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 11 15:22:35 volumio go-librespot[1765]: time="2026-01-11T15:22:35+01:00" level=trace msg="sent dealer ping" Jan 11 15:22:35 volumio go-librespot[1765]: time="2026-01-11T15:22:35+01:00" level=trace msg="received dealer pong" Jan 11 15:22:41 volumio volumio[1296]: info: Starting Uninstall of plugin user_interface - touch_display Jan 11 15:22:41 volumio volumio[1296]: info: Uninstalling plugin touch_display Jan 11 15:22:41 volumio sudo[2701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jan 11 15:22:41 volumio sudo[2701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:22:41 volumio sudo[2701]: pam_unix(sudo:session): session closed for user root Jan 11 15:22:41 volumio sudo[2703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Jan 11 15:22:41 volumio sudo[2703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:22:41 volumio volumio[1296]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Jan 11 15:22:41 volumio volumio[1296]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 15:22:41 volumio sudo[2705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Jan 11 15:22:41 volumio sudo[2705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:22:41 volumio volumio[1296]: TypeError: Cannot read properties of undefined (reading 'split') Jan 11 15:22:41 volumio volumio[1296]: at /data/plugins/user_interface/touch_display/index.js:1298:37 Jan 11 15:22:41 volumio volumio[1296]: at ChildProcess.exithandler (node:child_process:413:7) Jan 11 15:22:41 volumio volumio[1296]: at ChildProcess.emit (node:events:514:28) Jan 11 15:22:41 volumio volumio[1296]: at maybeClose (node:internal/child_process:1105:16) Jan 11 15:22:41 volumio volumio[1296]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) Jan 11 15:22:41 volumio volumio[1296]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 15:22:41 volumio sudo[2708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Jan 11 15:22:41 volumio sudo[2708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 11 15:22:41 volumio systemd[1]: Reloading. Jan 11 15:22:41 volumio sudo[2743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-11 15:21' Jan 11 15:22:41 volumio sudo[2743]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"