Jun 23 08:17:09 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 23 08:17:09 volumiopi4 volumio[1242]: info: Discovery: Getting this device information Jun 23 08:17:09 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetState Jun 23 08:17:09 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 23 08:17:18 volumiopi4 ntpd[998]: CLOCK: time stepped by 0.397686 Jun 23 08:17:18 volumiopi4 ntpd[998]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jun 23 08:17:18 volumiopi4 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 23 08:17:18 volumiopi4 dbus-daemon[702]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.83' (uid=0 pid=3320 comm="timedatectl show --property=NTPSynchronized --valu") Jun 23 08:17:29 volumiopi4 systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 23 08:17:29 volumiopi4 dbus-daemon[702]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 23 08:17:29 volumiopi4 systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 23 08:17:29 volumiopi4 setdatetime-helper.sh[3319]: Time is not synchronized. Attempting to sync... Jun 23 08:17:29 volumiopi4 sudo[3377]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Mon, 23 Jun 2025 06:17:29 GMT#015' Jun 23 08:17:29 volumiopi4 sudo[3377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 23 08:17:29 volumiopi4 setdatetime-helper.sh[3378]: Mon Jun 23 08:17:29 SAST 2025 Jun 23 08:17:29 volumiopi4 systemd-journald[347]: Time jumped backwards, rotating. Jun 23 08:17:29 volumiopi4 setdatetime-helper.sh[3319]: Time synchronized successfully. Jun 23 08:17:29 volumiopi4 sudo[3377]: pam_unix(sudo:session): session closed for user root Jun 23 08:17:29 volumiopi4 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 23 08:17:29 volumiopi4 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: Pool skipping: 196.49.100.57 Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: Pool taking: 196.10.55.57 Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: Pool taking: 102.64.113.151 Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: Pool skipping: 41.175.49.55 Jun 23 08:17:39 volumiopi4 ntpd[998]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Received Get System Info Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Discovery: Getting this device information Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces system playlist update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Ignoring MPD Status Update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces state update: player Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::getState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand status Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces system playlist update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Ignoring MPD Status Update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces state update: player Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::getState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand status Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces system playlist update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Ignoring MPD Status Update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces state update: player Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::getState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand status Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces system playlist update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Ignoring MPD Status Update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces state update: player Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::getState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand status Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces system playlist update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Ignoring MPD Status Update Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Jun 23 08:17:45 volumiopi4 volumio[1242]: ---------------------------- MPD announces state update: player Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::getState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand status Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 19ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand status took 17 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 16ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand status took 12 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 11ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand status took 9 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 9ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand status took 7 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 30ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand status took 27 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand playlistinfo took 22 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand playlistinfo took 22 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand playlistinfo took 21 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand playlistinfo took 20 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseState Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseTrackInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseTrackInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseTrackInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseTrackInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::servicePushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CorePlayQueue::getTrack 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89607,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"130 Kbps","isStreaming":false,"title":"Jack White - That's How I'm Feeling - Jack White - That's How I'm Feeling","artist":null,"album":null,"uri":"https://mediaworks.streamguys1.com/rock_net_icy?Dist=TuneIn","trackType":""} Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: CURRENT POSITION 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState stateService play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState currentStatus play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Received an update from plugin. extracting info from payload Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::servicePushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CorePlayQueue::getTrack 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89607,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"130 Kbps","isStreaming":false,"title":"Jack White - That's How I'm Feeling - Jack White - That's How I'm Feeling","artist":null,"album":null,"uri":"https://mediaworks.streamguys1.com/rock_net_icy?Dist=TuneIn","trackType":""} Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: CURRENT POSITION 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState stateService play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState currentStatus play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Received an update from plugin. extracting info from payload Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::servicePushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CorePlayQueue::getTrack 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89607,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"130 Kbps","isStreaming":false,"title":"Jack White - That's How I'm Feeling - Jack White - That's How I'm Feeling","artist":null,"album":null,"uri":"https://mediaworks.streamguys1.com/rock_net_icy?Dist=TuneIn","trackType":""} Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: CURRENT POSITION 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState stateService play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState currentStatus play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Received an update from plugin. extracting info from payload Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::servicePushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CorePlayQueue::getTrack 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89607,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"130 Kbps","isStreaming":false,"title":"Jack White - That's How I'm Feeling - Jack White - That's How I'm Feeling","artist":null,"album":null,"uri":"https://mediaworks.streamguys1.com/rock_net_icy?Dist=TuneIn","trackType":""} Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: CURRENT POSITION 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState stateService play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState currentStatus play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Received an update from plugin. extracting info from payload Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 115ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 109ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 107ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 104ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: sendMpdCommand playlistinfo took 87 milliseconds Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: ControllerMpd::parseTrackInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ControllerMpd::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::servicePushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CorePlayQueue::getTrack 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: STATE SERVICE {"status":"play","position":0,"seek":89607,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"130 Kbps","isStreaming":false,"title":"Jack White - That's How I'm Feeling - Jack White - That's How I'm Feeling","artist":null,"album":null,"uri":"https://mediaworks.streamguys1.com/rock_net_icy?Dist=TuneIn","trackType":""} Jun 23 08:17:45 volumiopi4 volumio[1242]: verbose: CURRENT POSITION 0 Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState stateService play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::syncState currentStatus play Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Received an update from plugin. extracting info from payload Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreStateMachine::pushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioPushState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: ------------------------------ 131ms Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Discovery: Getting this device information Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 23 08:17:45 volumiopi4 volumio[1242]: info: Discovery: Getting this device information Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetState Jun 23 08:17:45 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 23 08:17:50 volumiopi4 volumio[1242]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not access weather service: missing geographic coordinates. Jun 23 08:17:50 volumiopi4 volumio[1242]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:95:19) Jun 23 08:17:50 volumiopi4 volumio[1242]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:116:37) Jun 23 08:17:50 volumiopi4 volumio[1242]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:51:13 Jun 23 08:17:50 volumiopi4 volumio[1242]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Jun 23 08:17:50 volumiopi4 volumio[1242]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:149:13) Jun 23 08:17:50 volumiopi4 volumio[1242]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:119:3) Jun 23 08:17:50 volumiopi4 volumio[1242]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Jun 23 08:17:50 volumiopi4 volumio[1242]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Jun 23 08:17:50 volumiopi4 volumio[1242]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Jun 23 08:17:50 volumiopi4 volumio[1242]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Jun 23 08:17:50 volumiopi4 volumio[1242]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Jun 23 08:17:50 volumiopi4 volumio[1242]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Jun 23 08:17:50 volumiopi4 volumio[1242]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Jun 23 08:17:50 volumiopi4 volumio[1242]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Jun 23 08:17:50 volumiopi4 volumio[1242]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Jun 23 08:17:50 volumiopi4 volumio[1242]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Jun 23 08:17:50 volumiopi4 volumio[1242]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jun 23 08:17:51 volumiopi4 volumio[1242]: info: Listing playlists Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetQueue Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CoreStateMachine::getQueue Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CorePlayQueue::getQueue Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetVisibleSources Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 23 08:17:51 volumiopi4 volumio[1242]: info: CoreCommandRouter::volumioGetState Jun 23 08:17:58 volumiopi4 systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 23 08:18:03 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 23 08:18:03 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 23 08:18:07 volumiopi4 volumio[1242]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 23 08:18:15 volumiopi4 volumio[1242]: info: CALLMETHOD: user_interface touch_display savePointerConf [object Object] Jun 23 08:18:15 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: touch_display , savePointerConf Jun 23 08:18:19 volumiopi4 systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 23 08:18:19 volumiopi4 dbus-daemon[702]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.85' (uid=0 pid=3465 comm="timedatectl show --property=NTPSynchronized --valu") Jun 23 08:18:20 volumiopi4 sudo[3449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e '/ExecStart=\\/usr\\/bin\\/startx \\/etc\\/X11\\/Xsession \\/opt\\/volumiokiosk.sh/c\\ExecStart=\\/usr\\/bin\\/startx \\/etc\\/X11\\/Xsession \\/opt\\/volumiokiosk.sh -- -nocursor' /lib/systemd/system/volumio-kiosk.service Jun 23 08:18:20 volumiopi4 sudo[3449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 23 08:18:22 volumiopi4 volumio[1242]: info: CALLMETHOD: user_interface touch_display savePointerConf [object Object] Jun 23 08:18:22 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: touch_display , savePointerConf Jun 23 08:18:22 volumiopi4 sudo[3470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e '/ExecStart=\\/usr\\/bin\\/startx \\/etc\\/X11\\/Xsession \\/opt\\/volumiokiosk.sh/c\\ExecStart=\\/usr\\/bin\\/startx \\/etc\\/X11\\/Xsession \\/opt\\/volumiokiosk.sh -- -nocursor' /lib/systemd/system/volumio-kiosk.service Jun 23 08:18:22 volumiopi4 sudo[3470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 23 08:18:27 volumiopi4 systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 23 08:18:27 volumiopi4 dbus-daemon[702]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 23 08:18:27 volumiopi4 systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 23 08:18:27 volumiopi4 setdatetime-helper.sh[3464]: Time is not synchronized. Attempting to sync... Jun 23 08:18:27 volumiopi4 sudo[3478]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Mon, 23 Jun 2025 06:18:28 GMT#015' Jun 23 08:18:27 volumiopi4 sudo[3478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 23 08:18:28 volumiopi4 setdatetime-helper.sh[3479]: Mon Jun 23 08:18:28 SAST 2025 Jun 23 08:18:28 volumiopi4 sudo[3478]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:28 volumiopi4 setdatetime-helper.sh[3464]: Time synchronized successfully. Jun 23 08:18:28 volumiopi4 systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 23 08:18:28 volumiopi4 systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 23 08:18:28 volumiopi4 sudo[3449]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:28 volumiopi4 sudo[3495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jun 23 08:18:28 volumiopi4 sudo[3495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 23 08:18:28 volumiopi4 systemd[1]: Reloading. Jun 23 08:18:32 volumiopi4 sudo[3470]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:32 volumiopi4 sudo[3515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jun 23 08:18:32 volumiopi4 sudo[3515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 23 08:18:32 volumiopi4 sudo[3495]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:32 volumiopi4 volumio[1242]: info: touch_display: systemctl daemon-reload succeeded. Jun 23 08:18:32 volumiopi4 systemd[1]: Reloading. Jun 23 08:18:32 volumiopi4 sudo[3518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk.service Jun 23 08:18:32 volumiopi4 sudo[3518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 23 08:18:33 volumiopi4 sudo[3515]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:33 volumiopi4 volumio[1242]: info: touch_display: systemctl daemon-reload succeeded. Jun 23 08:18:33 volumiopi4 startx[3067]: xinit: connection to X server lost Jun 23 08:18:33 volumiopi4 startx[3067]: Jun 23 08:18:33 volumiopi4 systemd[1]: Stopping volumio-kiosk.service - Volumio Kiosk... Jun 23 08:18:33 volumiopi4 sudo[3539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk.service Jun 23 08:18:33 volumiopi4 sudo[3539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 23 08:18:33 volumiopi4 startx[3067]: waiting for X server to shut down Jun 23 08:18:33 volumiopi4 startx[3068]: (II) Server terminated successfully (0). Closing log file. Jun 23 08:18:34 volumiopi4 volumio[1242]: info: CALLMETHOD: user_interface touch_display savePointerConf [object Object] Jun 23 08:18:34 volumiopi4 volumio[1242]: info: CoreCommandRouter::executeOnPlugin: touch_display , savePointerConf Jun 23 08:18:34 volumiopi4 startx[3067]: xinit: unexpected signal 15 Jun 23 08:18:34 volumiopi4 systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Jun 23 08:18:41 volumiopi4 systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Jun 23 08:18:41 volumiopi4 systemd[1]: Stopped volumio-kiosk.service - Volumio Kiosk. Jun 23 08:18:41 volumiopi4 systemd[1]: volumio-kiosk.service: Consumed 9.274s CPU time. Jun 23 08:18:41 volumiopi4 systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Jun 23 08:18:41 volumiopi4 sudo[3518]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:41 volumiopi4 sudo[3539]: pam_unix(sudo:session): session closed for user root Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: systemctl restart volumio-kiosk.service succeeded. Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: Volumio Kiosk restarted. Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: systemctl restart volumio-kiosk.service succeeded. Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: Volumio Kiosk restarted. Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:41 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: Jun 23 08:18:42 volumiopi4 startx[3609]: X.Org X Server 1.21.1.7 Jun 23 08:18:42 volumiopi4 startx[3609]: X Protocol Version 11, Revision 0 Jun 23 08:18:42 volumiopi4 startx[3609]: Current Operating System: Linux volumiopi4 6.12.27-v7l+ #1876 SMP Tue May 6 15:10:05 BST 2025 armv7l Jun 23 08:18:42 volumiopi4 startx[3609]: Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 numa=fake=1 system_heap.max_order=0 smsc95xx.macaddr=E4:5F:01:CF:18:B1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=0ca921d0-ed29-48f1-bc74-550f2ad8e370 imgfile=/volumio_current.sqsh bootpart=UUID=E54B-2C41 datapart=UUID=9cfbeebe-d04d-4377-b93c-47b70d48adf5 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jun 23 08:18:42 volumiopi4 startx[3609]: xorg-server 2:21.1.7-3+rpt3+deb12u9 (https://www.debian.org/support) Jun 23 08:18:42 volumiopi4 startx[3609]: Current version of pixman: 0.44.0 Jun 23 08:18:42 volumiopi4 startx[3609]: Before reporting problems, check http://wiki.x.org Jun 23 08:18:42 volumiopi4 startx[3609]: to make sure that you have the latest version. Jun 23 08:18:42 volumiopi4 startx[3609]: Markers: (--) probed, (**) from config file, (==) default setting, Jun 23 08:18:42 volumiopi4 startx[3609]: (++) from command line, (!!) notice, (II) informational, Jun 23 08:18:42 volumiopi4 startx[3609]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jun 23 08:18:42 volumiopi4 startx[3609]: (==) Log file: "/var/log/Xorg.0.log", Time: Mon Jun 23 08:18:42 2025 Jun 23 08:18:42 volumiopi4 startx[3609]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jun 23 08:18:42 volumiopi4 startx[3609]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:42 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jun 23 08:18:43 volumiopi4 volumio[1242]: info: touch_display: X display number found: 0 Jun 23 08:18:43 volumiopi4 volumio[1242]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 23 08:18:43 volumiopi4 volumio[1242]: Error: connect EISCONN /tmp/.X11-unix/X0 Jun 23 08:18:43 volumiopi4 volumio[1242]: at PipeConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jun 23 08:18:43 volumiopi4 volumio[1242]: errno: -106, Jun 23 08:18:43 volumiopi4 volumio[1242]: code: 'EISCONN', Jun 23 08:18:43 volumiopi4 volumio[1242]: syscall: 'connect', Jun 23 08:18:43 volumiopi4 volumio[1242]: address: '/tmp/.X11-unix/X0' Jun 23 08:18:43 volumiopi4 volumio[1242]: } Jun 23 08:18:43 volumiopi4 volumio[1242]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 23 08:18:44 volumiopi4 sudo[3855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-23 08:17' Jun 23 08:18:44 volumiopi4 sudo[3855]: 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="cee9bb5b0ee50e4898478097a64b5c6c77d5a212" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="b0310d60a07948a2a8a2e8db322034758c86aad6" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 21 15:01:23 UTC 2025" VOLUMIO_VERSION="4.013" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6df2d5f0b86e6f2c0cd4dc68c66de48c"