Aug 28 11:31:01 volumiobt volumio[1295]: info: Enabling plugin touch_display Aug 28 11:31:01 volumiobt volumio[1295]: info: Loading plugin "touch_display"... Aug 28 11:31:02 volumiobt volumio[1295]: info: PLUGIN START: touch_display Aug 28 11:31:02 volumiobt volumio[1295]: info: Loading i18n strings for locale en Aug 28 11:31:02 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 11:31:02 volumiobt sudo[3418]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Aug 28 11:31:02 volumiobt sudo[3418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:02 volumiobt sudo[3418]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:02 volumiobt sudo[3421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Aug 28 11:31:02 volumiobt sudo[3421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:02 volumiobt volumio[1295]: info: touch_display: No backlight interface detected. Aug 28 11:31:02 volumiobt sudo[3423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Aug 28 11:31:02 volumiobt sudo[3425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 28 11:31:02 volumiobt sudo[3425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:02 volumiobt sudo[3423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:02 volumiobt volumio[1295]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Aug 28 11:31:02 volumiobt systemd[1]: Stopping getty@tty1.service - Getty on tty1... Aug 28 11:31:02 volumiobt systemd[1]: getty@tty1.service: Deactivated successfully. Aug 28 11:31:02 volumiobt systemd[1]: Stopped getty@tty1.service - Getty on tty1. Aug 28 11:31:02 volumiobt sudo[3430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Aug 28 11:31:02 volumiobt sudo[3430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:02 volumiobt sudo[3430]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:02 volumiobt volumio[1295]: info: touch_display: IframeKeyboardBridge extension installed successfully Aug 28 11:31:02 volumiobt volumio[1295]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Aug 28 11:31:02 volumiobt sudo[3435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Aug 28 11:31:02 volumiobt sudo[3435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:02 volumiobt sudo[3435]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:02 volumiobt volumio[1295]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Aug 28 11:31:04 volumiobt bluetoothd[838]: profiles/audio/avdtp.c:avdtp_connect_cb() connect to 1C:D3:AF:4D:08:3B: Host is down (112) Aug 28 11:31:04 volumiobt volumio[1295]: warn: [Wireless Output Manager][Bluetooth] Selected Bluetooth audio device is unavailable: busctl exited with code 1 Aug 28 11:31:06 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] flip_done timed out Aug 28 11:31:16 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:31:16 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] commit wait timed out Aug 28 11:31:19 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:31:19 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Reconnecting preferred device 1C:D3:AF:4D:08:3B Aug 28 11:31:19 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:31:24 volumiobt bluetoothd[838]: profiles/audio/avdtp.c:avdtp_connect_cb() connect to 1C:D3:AF:4D:08:3B: Host is down (112) Aug 28 11:31:24 volumiobt volumio[1295]: warn: [Wireless Output Manager][Bluetooth] Selected Bluetooth audio device is unavailable: busctl exited with code 1 Aug 28 11:31:26 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:31:26 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [CONNECTOR:33:HDMI-A-1] commit wait timed out Aug 28 11:31:27 volumiobt sudo[3421]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:27 volumiobt volumio[1295]: info: touch_display: systemctl stop getty@tty1.service succeeded. Aug 28 11:31:36 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:31:36 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [PLANE:89:plane-3] commit wait timed out Aug 28 11:31:39 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:31:39 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Reconnecting preferred device 1C:D3:AF:4D:08:3B Aug 28 11:31:39 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:31:45 volumiobt bluetoothd[838]: profiles/audio/avdtp.c:avdtp_connect_cb() connect to 1C:D3:AF:4D:08:3B: Host is down (112) Aug 28 11:31:45 volumiobt volumio[1295]: warn: [Wireless Output Manager][Bluetooth] Selected Bluetooth audio device is unavailable: busctl exited with code 1 Aug 28 11:31:47 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:31:47 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* Timed out waiting for commit Aug 28 11:31:55 volumiobt volumio[1295]: info: Enabling plugin touch_display Aug 28 11:31:55 volumiobt volumio[1295]: info: Loading plugin "touch_display"... Aug 28 11:31:55 volumiobt volumio[1295]: info: Applying required configuration parameters for plugin touch_display Aug 28 11:31:55 volumiobt volumio[1295]: info: PLUGIN START: touch_display Aug 28 11:31:55 volumiobt volumio[1295]: info: Loading i18n strings for locale en Aug 28 11:31:55 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 28 11:31:55 volumiobt sudo[3571]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Aug 28 11:31:55 volumiobt sudo[3571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:55 volumiobt sudo[3571]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:55 volumiobt volumio[1295]: info: touch_display: No backlight interface detected. Aug 28 11:31:55 volumiobt sudo[3576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Aug 28 11:31:55 volumiobt sudo[3576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:55 volumiobt sudo[3574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Aug 28 11:31:55 volumiobt sudo[3574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:55 volumiobt sudo[3578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Aug 28 11:31:55 volumiobt sudo[3578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:55 volumiobt volumio[1295]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Aug 28 11:31:55 volumiobt sudo[3584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Aug 28 11:31:55 volumiobt sudo[3584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:55 volumiobt sudo[3587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Aug 28 11:31:55 volumiobt sudo[3587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:31:55 volumiobt sudo[3584]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:55 volumiobt sudo[3587]: pam_unix(sudo:session): session closed for user root Aug 28 11:31:55 volumiobt volumio[1295]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Aug 28 11:31:55 volumiobt volumio[1295]: info: touch_display: IframeKeyboardBridge extension installed successfully Aug 28 11:31:57 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] flip_done timed out Aug 28 11:31:58 volumiobt volumio[1295]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 28 11:31:58 volumiobt volumio[1295]: info: touch_display: About to detect HDMI ports... Aug 28 11:31:58 volumiobt volumio[1295]: info: touch_display: X server not ready, cannot detect HDMI ports yet. Aug 28 11:32:00 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:32:00 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Reconnecting preferred device 1C:D3:AF:4D:08:3B Aug 28 11:32:00 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:32:05 volumiobt bluetoothd[838]: profiles/audio/avdtp.c:avdtp_connect_cb() connect to 1C:D3:AF:4D:08:3B: Host is down (112) Aug 28 11:32:05 volumiobt volumio[1295]: warn: [Wireless Output Manager][Bluetooth] Selected Bluetooth audio device is unavailable: busctl exited with code 1 Aug 28 11:32:05 volumiobt volumio[1295]: info: CALLMETHOD: user_interface touch_display saveScreensaverConf [object Object] Aug 28 11:32:05 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: touch_display , saveScreensaverConf Aug 28 11:32:05 volumiobt volumio[1295]: info: CoreCommandRouter::volumioGetState Aug 28 11:32:05 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:05 volumiobt volumio[1295]: error: touch_display: Error setting screensaver timeout: Error: ENOENT: no such file or directory, stat '/tmp/.X11-unix/Xundefined' Aug 28 11:32:07 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:32:07 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] commit wait timed out Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPlay Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::play index undefined Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::startPlaybackTimer Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::clearAddPlayTracks USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand stop Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand stop took 5 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand clear Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand clear took 1 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand add "USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac" Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces system playlist update Aug 28 11:32:10 volumiobt volumio[1295]: info: Ignoring MPD Status Update Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces system playlist update Aug 28 11:32:10 volumiobt volumio[1295]: info: Ignoring MPD Status Update Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces system playlist update Aug 28 11:32:10 volumiobt volumio[1295]: info: Ignoring MPD Status Update Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces system playlist update Aug 28 11:32:10 volumiobt volumio[1295]: info: Ignoring MPD Status Update Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand add "USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac" took 7 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 6ms Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 4ms Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand play Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces system playlist update Aug 28 11:32:10 volumiobt volumio[1295]: info: Ignoring MPD Status Update Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces system playlist update Aug 28 11:32:10 volumiobt volumio[1295]: info: Ignoring MPD Status Update Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 9ms Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 9ms Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand play took 6 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 5ms Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 4ms Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces state update: player Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::getState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces state update: player Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::getState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces state update: player Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::getState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces state update: player Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand status took 26 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::getState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand status took 28 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand status took 28 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand status took 4 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseTrackInfo Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::servicePushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":761,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Hang On To A Dream","artist":"The Nice","album":"Elegy","uri":"USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac","trackType":"flac"} Aug 28 11:32:10 volumiobt volumio[1295]: verbose: CURRENT POSITION 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState stateService play Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState currentStatus stop Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 39ms Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces state update: player Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::getState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Aug 28 11:32:10 volumiobt volumio[1295]: info: Aug 28 11:32:10 volumiobt volumio[1295]: ---------------------------- MPD announces state update: player Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::getState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand playlistinfo took 9 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand playlistinfo took 9 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand playlistinfo took 9 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand status took 3 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand status took 2 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseTrackInfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseTrackInfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseTrackInfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseState Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::servicePushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":389,"duration":761,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"653 Kbps","isStreaming":false,"title":"Hang On To A Dream","artist":"The Nice","album":"Elegy","uri":"USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac","trackType":"flac"} Aug 28 11:32:10 volumiobt volumio[1295]: verbose: CURRENT POSITION 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState stateService play Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState currentStatus play Aug 28 11:32:10 volumiobt volumio[1295]: info: Received an update from plugin. extracting info from payload Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::servicePushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":761,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"605 Kbps","isStreaming":false,"title":"Hang On To A Dream","artist":"The Nice","album":"Elegy","uri":"USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac","trackType":"flac"} Aug 28 11:32:10 volumiobt volumio[1295]: verbose: CURRENT POSITION 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState stateService play Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState currentStatus play Aug 28 11:32:10 volumiobt volumio[1295]: info: Received an update from plugin. extracting info from payload Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::servicePushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":761,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"605 Kbps","isStreaming":false,"title":"Hang On To A Dream","artist":"The Nice","album":"Elegy","uri":"USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac","trackType":"flac"} Aug 28 11:32:10 volumiobt volumio[1295]: verbose: CURRENT POSITION 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState stateService play Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState currentStatus play Aug 28 11:32:10 volumiobt volumio[1295]: info: Received an update from plugin. extracting info from payload Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 112ms Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 111ms Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 91ms Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand playlistinfo took 72 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: info: sendMpdCommand playlistinfo took 73 milliseconds Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseTrackInfo Aug 28 11:32:10 volumiobt volumio[1295]: verbose: ControllerMpd::parseTrackInfo Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::servicePushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":761,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"605 Kbps","isStreaming":false,"title":"Hang On To A Dream","artist":"The Nice","album":"Elegy","uri":"USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac","trackType":"flac"} Aug 28 11:32:10 volumiobt volumio[1295]: verbose: CURRENT POSITION 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState stateService play Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState currentStatus play Aug 28 11:32:10 volumiobt volumio[1295]: info: Received an update from plugin. extracting info from payload Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: ControllerMpd::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::servicePushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":962,"duration":761,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"605 Kbps","isStreaming":false,"title":"Hang On To A Dream","artist":"The Nice","album":"Elegy","uri":"USB/MUSIC/.Trashes/501/The Nice/Elegy/01 - Hang On To A Dream.flac","trackType":"flac"} Aug 28 11:32:10 volumiobt volumio[1295]: verbose: CURRENT POSITION 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState stateService play Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::syncState currentStatus play Aug 28 11:32:10 volumiobt volumio[1295]: info: Received an update from plugin. extracting info from payload Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreStateMachine::pushState Aug 28 11:32:10 volumiobt volumio[1295]: info: CorePlayQueue::getTrack 0 Aug 28 11:32:10 volumiobt volumio[1295]: info: CoreCommandRouter::volumioPushState Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 126ms Aug 28 11:32:10 volumiobt volumio[1295]: info: ------------------------------ 124ms Aug 28 11:32:17 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:32:17 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [CONNECTOR:33:HDMI-A-1] commit wait timed out Aug 28 11:32:20 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:32:20 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Reconnecting preferred device 1C:D3:AF:4D:08:3B Aug 28 11:32:20 volumiobt volumio[1295]: info: [Wireless Output Manager][Bluetooth] Resolved 1C:D3:AF:4D:08:3B to /org/bluez/hci0/dev_1C_D3_AF_4D_08_3B on adapter E4:5F:01:84:D3:2C Aug 28 11:32:25 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 28 11:32:25 volumiobt volumio[1295]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 28 11:32:25 volumiobt bluetoothd[838]: profiles/audio/avdtp.c:avdtp_connect_cb() connect to 1C:D3:AF:4D:08:3B: Host is down (112) Aug 28 11:32:25 volumiobt volumio[1295]: warn: [Wireless Output Manager][Bluetooth] Selected Bluetooth audio device is unavailable: busctl exited with code 1 Aug 28 11:32:28 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Aug 28 11:32:28 volumiobt kernel: vc4-drm gpu: [drm] *ERROR* [PLANE:89:plane-3] commit wait timed out Aug 28 11:32:29 volumiobt volumio[1295]: info: Starting Uninstall of plugin user_interface - touch_display Aug 28 11:32:29 volumiobt volumio[1295]: info: Uninstalling plugin touch_display Aug 28 11:32:29 volumiobt sudo[3719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Aug 28 11:32:29 volumiobt sudo[3719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:32:29 volumiobt sudo[3719]: pam_unix(sudo:session): session closed for user root Aug 28 11:32:29 volumiobt sudo[3721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Aug 28 11:32:29 volumiobt sudo[3721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:32:29 volumiobt sudo[3723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Aug 28 11:32:29 volumiobt sudo[3723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:32:29 volumiobt volumio[1295]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Aug 28 11:32:29 volumiobt volumio[1295]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 11:32:29 volumiobt sudo[3727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Aug 28 11:32:29 volumiobt volumio[1295]: TypeError: Cannot read properties of undefined (reading 'split') Aug 28 11:32:29 volumiobt volumio[1295]: at /data/plugins/user_interface/touch_display/index.js:1298:37 Aug 28 11:32:29 volumiobt volumio[1295]: at ChildProcess.exithandler (node:child_process:413:7) Aug 28 11:32:29 volumiobt volumio[1295]: at ChildProcess.emit (node:events:514:28) Aug 28 11:32:29 volumiobt volumio[1295]: at maybeClose (node:internal/child_process:1105:16) Aug 28 11:32:29 volumiobt volumio[1295]: at Socket. (node:internal/child_process:457:11) Aug 28 11:32:29 volumiobt volumio[1295]: at Socket.emit (node:events:514:28) Aug 28 11:32:29 volumiobt volumio[1295]: at Pipe. (node:net:337:12) Aug 28 11:32:29 volumiobt volumio[1295]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 11:32:29 volumiobt sudo[3727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 11:32:29 volumiobt sudo[3744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-28 11:31' Aug 28 11:32:29 volumiobt sudo[3744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"