search

KlipperScreen / KlipperScreen

GUI for Klipper
https://klipperscreen.github.io/KlipperScreen/
GNU Affero General Public License v3.0
1.02k stars 319 forks source link

[BUG] /dev/null permissions broken after Uninstall #1297

Closed rdbahm closed 3 months ago

rdbahm commented 3 months ago

What happened?

During re-configuration of my Klipper-based printer (uses a Raspberry Pi 4, typically based on the latest build of MainsailOS), I had repeated difficulties with permissions on /dev/null after installing KlipperScreen. I eventually narrowed down that issue to something within KIAUH and opened an issue there, but investigation found that even without involving KIAUH, installing and uninstalling KlipperScreen results in an identical issue. image

What did you expect to happen instead?

I expect the "pi" user to be able to access /dev/null normally. Same system as previous screenshot, just before uninstall: image

How to reproduce this bug?

Before beginning, you can verify the issue is not present by running ls /dev/null (not as root or with sudo)

  1. On a Debian Bullseye-based system (tested on MainsailOS arm64, Raspberry Pi OS arm64, and Debian Bullseye amd64 on a VM), install KlipperScreen via KlipperScreen-install.sh (not via KIAUH, or you may run into another issue that causes this same symptom).
  2. When installing KlipperScreen, be sure to say "Yes" to service install.
  3. Uninstall KlipperScreen using Uninstall.sh
  4. Run ls /dev/null to see the error.

Additional information:

I opened an issue for a similar issue in a different part of the KlipperScreen installation on the KIAUH repository, Issue 448. In that case, installing KlipperScreeen via KIAUH (but not via KlipperScreen-install.sh) causes the exact same symptom. I expect they're related, but I don't yet understand how.

As implied in the repro steps, the issue doesn't happen if the service is not installed before uninstalling.

Log output

pi@debian:~/KlipperScreen$ systemctl status KlipperScreen
Warning: The unit file, source configuration file or drop-ins of KlipperScreen.service changed on disk. Run 'systemctl daemon-reload' to reload units.
● KlipperScreen.service - KlipperScreen
     Loaded: loaded (/etc/systemd/system/KlipperScreen.service; bad; vendor preset: enabled)
     Active: inactive (dead) since Sat 2024-03-09 10:36:58 PST; 20s ago
    Process: 11099 ExecStart=/home/pi/KlipperScreen/scripts/KlipperScreen-start.sh (code=killed, signal=TERM)
   Main PID: 11099 (code=killed, signal=TERM)
        CPU: 430ms

Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [screen.py:init_klipper()] - Printer initialized
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [printer.py:change_state()] - Changing state from 'disconnected' to 'error'
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [printer.py:change_state()] - Adding callback for state: error
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,853 [screen.py:show_panel()] - Reinitializing panel
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,858 [screen.py:attach_panel()] - Current panel hierarchy: splash_screen
Mar 09 10:36:57 debian KlipperScreen-start.sh[11102]: /usr/bin/xinit: connection to X server lost
Mar 09 10:36:57 debian KlipperScreen-start.sh[11102]:
Mar 09 10:36:57 debian KlipperScreen-start.sh[11102]: waiting for X server to shut down
Mar 09 10:36:57 debian KlipperScreen-start.sh[11103]: (II) Server terminated successfully (0). Closing log file.
Mar 09 10:36:58 debian KlipperScreen-start.sh[11102]: /usr/bin/xinit: unexpected signal 15
pi@debian:~/KlipperScreen$ journalctl -xe -u KlipperScreen
Hint: You are currently not seeing messages from other users and the system.
      Users in groups 'adm', 'systemd-journal' can see all messages.
      Pass -q to turn off this notice.
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,369 [config.py:__init__()] - Config path location: /home/pi/KlipperScreen/ks_includes/defaults.conf
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,371 [config.py:__init__()] - Configured printers: [
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:   {
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:     "Printer": {
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:       "moonraker_host": "127.0.0.1",
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:       "moonraker_port": "7125",
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:       "moonraker_api_key": ""
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:     }
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]:   }
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: ]
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,379 [config.py:create_translations()] - Selected lang: None OS lang: en_US
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,379 [config.py:install_language()] - Using lang en
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,381 [screen.py:__init__()] - Monitors: 1 using number: 0
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,382 [screen.py:__init__()] - Screen resolution: 1024x768
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,382 [KlippyGtk.py:__init__()] - Font size: 23.8 (medium)
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,456 [screen.py:set_screenblanking_timeout()] - Changing screen blanking to: 3600
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,458 [screen.py:set_screenblanking_timeout()] - Using DPMS
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,460 [screen.py:initial_connection()] - Default printer: None
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,465 [screen.py:connect_printer()] - Connecting to printer: Printer
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,466 [screen.py:_load_panel()] - Loading panel: splash_screen
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,472 [screen.py:attach_panel()] - Current panel hierarchy: splash_screen
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,473 [KlippyWebsocket.py:connect()] - Attempting to connect
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,473 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/server/info
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,476 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/access/oneshot_token
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,477 [KlippyWebsocket.py:connect()] - Starting websocket thread
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,479 [_logging.py:info()] - Websocket connected
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,479 [KlippyWebsocket.py:on_open()] - Moonraker Websocket Open
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,481 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/server/info
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,482 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/server/webcams/list
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,483 [printer.py:configure_cameras()] - Cameras: []
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,483 [screen.py:init_klipper()] - Moonraker info {'klippy_connected': True, 'klippy_state': 'error', 'components': ['secrets', 'template>
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,484 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/info
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,485 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/objects/query?configfile
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,597 [screen.py:init_klipper()] - {'configfile': {'config': {'mcu': {'serial': '/dev/serial/by-id/<your-mcu-id>'}, 'virtual_sdcard': {'p>
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,597 [printer.py:stop_tempstore_updates()] - Stopping tempstore
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [printer.py:reinit()] - Klipper version: v0.12.0-117-g71604b71
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [printer.py:reinit()] - # Extruders: 0
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [printer.py:reinit()] - # Temperature devices: 0
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [printer.py:reinit()] - # Fans: 0
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [printer.py:reinit()] - # Output pins: 0
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [printer.py:reinit()] - # Leds: 0
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,598 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/gcode/help
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,599 [KlippyWebsocket.py:object_subscription()] - Sending printer.objects.subscribe
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,600 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/objects/query?bed_mesh&configfile&display_status&extru>
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,848 [files.py:set_gcodes_path()] - Gcodes path: /home/pi/printer_data/gcodes
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [KlippyWebsocket.py:get_file_list()] - Sending server.files.list
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [screen.py:init_klipper()] - Printer initialized
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [printer.py:change_state()] - Changing state from 'disconnected' to 'error'
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,849 [printer.py:change_state()] - Adding callback for state: error
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,853 [screen.py:show_panel()] - Reinitializing panel
Mar 09 10:36:51 debian KlipperScreen-start.sh[11115]: 2024-03-09 10:36:51,858 [screen.py:attach_panel()] - Current panel hierarchy: splash_screen
Mar 09 10:36:57 debian KlipperScreen-start.sh[11102]: /usr/bin/xinit: connection to X server lost
Mar 09 10:36:57 debian KlipperScreen-start.sh[11102]:
Mar 09 10:36:57 debian KlipperScreen-start.sh[11102]: waiting for X server to shut down
Mar 09 10:36:57 debian KlipperScreen-start.sh[11103]: (II) Server terminated successfully (0). Closing log file.
Mar 09 10:36:58 debian KlipperScreen-start.sh[11102]: /usr/bin/xinit: unexpected signal 15
pi@debian:~/KlipperScreen$ cat /var/log/Xorg.0.log
[   414.954]
X.Org X Server 1.20.11
X Protocol Version 11, Revision 0
[   414.954] Build Operating System: linux Debian
[   414.954] Current Operating System: Linux debian 5.10.0-28-amd64 #1 SMP Debian 5.10.209-2 (2024-01-31) x86_64
[   414.954] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.10.0-28-amd64 root=UUID=e08021d6-f000-4a51-883b-657433fe7a1f ro quiet
[   414.954] Build Date: 22 January 2024  06:21:42AM
[   414.954] xorg-server 2:1.20.11-1+deb11u11 (https://www.debian.org/support)
[   414.954] Current version of pixman: 0.40.0
[   414.954]    Before reporting problems, check http://wiki.x.org
        to make sure that you have the latest version.
[   414.954] Markers: (--) probed, (**) from config file, (==) default setting,
        (++) from command line, (!!) notice, (II) informational,
        (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
[   414.954] (==) Log file: "/var/log/Xorg.0.log", Time: Sat Mar  9 10:36:50 2024
[   414.954] (==) Using system config directory "/usr/share/X11/xorg.conf.d"
[   414.954] (==) No Layout section.  Using the first Screen section.
[   414.954] (==) No screen section available. Using defaults.
[   414.954] (**) |-->Screen "Default Screen Section" (0)
[   414.954] (**) |   |-->Monitor "<default monitor>"
[   414.955] (==) No monitor specified for screen "Default Screen Section".
        Using a default monitor configuration.
[   414.955] (==) Automatically adding devices
[   414.955] (==) Automatically enabling devices
[   414.955] (==) Automatically adding GPU devices
[   414.955] (==) Max clients allowed: 256, resource mask: 0x1fffff
[   414.955] (WW) The directory "/usr/share/fonts/X11/cyrillic" does not exist.
[   414.955]    Entry deleted from font path.
[   414.955] (WW) The directory "/usr/share/fonts/X11/100dpi/" does not exist.
[   414.955]    Entry deleted from font path.
[   414.955] (WW) The directory "/usr/share/fonts/X11/75dpi/" does not exist.
[   414.955]    Entry deleted from font path.
[   414.955] (WW) The directory "/usr/share/fonts/X11/Type1" does not exist.
[   414.955]    Entry deleted from font path.
[   414.955] (WW) The directory "/usr/share/fonts/X11/100dpi" does not exist.
[   414.955]    Entry deleted from font path.
[   414.955] (WW) The directory "/usr/share/fonts/X11/75dpi" does not exist.
[   414.955]    Entry deleted from font path.
[   414.955] (==) FontPath set to:
        /usr/share/fonts/X11/misc,
        built-ins
[   414.955] (==) ModulePath set to "/usr/lib/xorg/modules"
[   414.955] (II) The server relies on udev to provide the list of input devices.
        If no devices become available, reconfigure udev or disable AutoAddDevices.
[   414.955] (II) Loader magic: 0x560bc921ce40
[   414.955] (II) Module ABI versions:
[   414.955]    X.Org ANSI C Emulation: 0.4
[   414.955]    X.Org Video Driver: 24.1
[   414.955]    X.Org XInput driver : 24.1
[   414.955]    X.Org Server Extension : 10.0
[   414.956] (--) using VT number 2

[   414.956] (II) systemd-logind: logind integration requires -keeptty and -keeptty was not provided, disabling logind integration
[   414.956] (II) no primary bus or device found
[   414.956] (II) LoadModule: "glx"
[   414.956] (II) Loading /usr/lib/xorg/modules/extensions/libglx.so
[   414.960] (II) Module glx: vendor="X.Org Foundation"
[   414.960]    compiled for 1.20.11, module version = 1.0.0
[   414.960]    ABI class: X.Org Server Extension, version 10.0
[   414.960] (==) Matched modesetting as autoconfigured driver 0
[   414.960] (==) Matched fbdev as autoconfigured driver 1
[   414.960] (==) Matched vesa as autoconfigured driver 2
[   414.960] (==) Assigned the driver to the xf86ConfigLayout
[   414.960] (II) LoadModule: "modesetting"
[   414.960] (II) Loading /usr/lib/xorg/modules/drivers/modesetting_drv.so
[   414.961] (II) Module modesetting: vendor="X.Org Foundation"
[   414.961]    compiled for 1.20.11, module version = 1.20.11
[   414.961]    Module class: X.Org Video Driver
[   414.961]    ABI class: X.Org Video Driver, version 24.1
[   414.961] (II) LoadModule: "fbdev"
[   414.961] (II) Loading /usr/lib/xorg/modules/drivers/fbdev_drv.so
[   414.961] (II) Module fbdev: vendor="X.Org Foundation"
[   414.961]    compiled for 1.20.0, module version = 0.5.0
[   414.961]    Module class: X.Org Video Driver
[   414.961]    ABI class: X.Org Video Driver, version 24.0
[   414.961] (II) LoadModule: "vesa"
[   414.961] (WW) Warning, couldn't open module vesa
[   414.961] (EE) Failed to load module "vesa" (module does not exist, 0)
[   414.961] (II) modesetting: Driver for Modesetting Kernel Drivers: kms
[   414.961] (II) FBDEV: driver for framebuffer: fbdev
[   414.962] (WW) Falling back to old probe method for modesetting
[   414.962] (EE) open /dev/dri/card0: No such file or directory
[   414.962] (WW) Falling back to old probe method for fbdev
[   414.962] (II) Loading sub module "fbdevhw"
[   414.962] (II) LoadModule: "fbdevhw"
[   414.962] (II) Loading /usr/lib/xorg/modules/libfbdevhw.so
[   414.962] (II) Module fbdevhw: vendor="X.Org Foundation"
[   414.962]    compiled for 1.20.11, module version = 0.0.2
[   414.962]    ABI class: X.Org Video Driver, version 24.1
[   414.962] (II) FBDEV(0): using default device
[   414.962] (II) FBDEV(0): Creating default Display subsection in Screen section
        "Default Screen Section" for depth/fbbpp 24/32
[   414.962] (==) FBDEV(0): Depth 24, (==) framebuffer bpp 32
[   414.962] (==) FBDEV(0): RGB weight 888
[   414.962] (==) FBDEV(0): Default visual is TrueColor
[   414.962] (==) FBDEV(0): Using gamma correction (1.0, 1.0, 1.0)
[   414.962] (II) FBDEV(0): hardware: hyperv_fb (video memory: 3072kB)
[   414.962] (DB) xf86MergeOutputClassOptions unsupported bus type 0
[   414.962] (II) FBDEV(0): checking modes against framebuffer device...
[   414.962] (II) FBDEV(0): checking modes against monitor...
[   414.962] (II) FBDEV(0): Virtual size is 1024x768 (pitch 1024)
[   414.962] (**) FBDEV(0):  Built-in mode "current"
[   414.962] (==) FBDEV(0): DPI set to (96, 96)
[   414.962] (II) Loading sub module "fb"
[   414.962] (II) LoadModule: "fb"
[   414.962] (II) Loading /usr/lib/xorg/modules/libfb.so
[   414.963] (II) Module fb: vendor="X.Org Foundation"
[   414.963]    compiled for 1.20.11, module version = 1.0.0
[   414.963]    ABI class: X.Org ANSI C Emulation, version 0.4
[   414.963] (**) FBDEV(0): using shadow framebuffer
[   414.963] (II) Loading sub module "shadow"
[   414.963] (II) LoadModule: "shadow"
[   414.963] (II) Loading /usr/lib/xorg/modules/libshadow.so
[   414.964] (II) Module shadow: vendor="X.Org Foundation"
[   414.964]    compiled for 1.20.11, module version = 1.1.0
[   414.964]    ABI class: X.Org ANSI C Emulation, version 0.4
[   414.964] (II) UnloadModule: "modesetting"
[   414.964] (II) Unloading modesetting
[   414.965] (==) FBDEV(0): Backing store enabled
[   414.965] (==) FBDEV(0): DPMS enabled
[   414.965] (II) Initializing extension Generic Event Extension
[   414.965] (II) Initializing extension SHAPE
[   414.965] (II) Initializing extension MIT-SHM
[   414.965] (II) Initializing extension XInputExtension
[   414.966] (II) Initializing extension XTEST
[   414.966] (II) Initializing extension BIG-REQUESTS
[   414.966] (II) Initializing extension SYNC
[   414.966] (II) Initializing extension XKEYBOARD
[   414.966] (II) Initializing extension XC-MISC
[   414.966] (II) Initializing extension SECURITY
[   414.966] (II) Initializing extension XFIXES
[   414.966] (II) Initializing extension RENDER
[   414.966] (II) Initializing extension RANDR
[   414.966] (II) Initializing extension COMPOSITE
[   414.966] (II) Initializing extension DAMAGE
[   414.967] (II) Initializing extension MIT-SCREEN-SAVER
[   414.967] (II) Initializing extension DOUBLE-BUFFER
[   414.967] (II) Initializing extension RECORD
[   414.967] (II) Initializing extension DPMS
[   414.967] (II) Initializing extension Present
[   414.967] (II) Initializing extension DRI3
[   414.967] (II) Initializing extension X-Resource
[   414.967] (II) Initializing extension XVideo
[   414.967] (II) Initializing extension XVideo-MotionCompensation
[   414.967] (II) Initializing extension SELinux
[   414.967] (II) SELinux: Disabled on system
[   414.967] (II) Initializing extension GLX
[   414.967] (II) AIGLX: Screen 0 is not DRI2 capable
[   415.031] (II) IGLX: Loaded and initialized swrast
[   415.031] (II) GLX: Initialized DRISWRAST GL provider for screen 0
[   415.031] (II) Initializing extension XFree86-VidModeExtension
[   415.031] (II) Initializing extension XFree86-DGA
[   415.031] (II) Initializing extension XFree86-DRI
[   415.031] (II) Initializing extension DRI2
[   415.053] (II) config/udev: Adding input device Microsoft Vmbus HID-compliant Mouse (/dev/input/event0)
[   415.053] (**) Microsoft Vmbus HID-compliant Mouse: Applying InputClass "evdev pointer catchall"
[   415.053] (**) Microsoft Vmbus HID-compliant Mouse: Applying InputClass "libinput pointer catchall"
[   415.053] (II) LoadModule: "libinput"
[   415.053] (II) Loading /usr/lib/xorg/modules/input/libinput_drv.so
[   415.056] (II) Module libinput: vendor="X.Org Foundation"
[   415.056]    compiled for 1.20.8, module version = 0.30.0
[   415.056]    Module class: X.Org XInput Driver
[   415.056]    ABI class: X.Org XInput driver, version 24.1
[   415.056] (II) Using input driver 'libinput' for 'Microsoft Vmbus HID-compliant Mouse'
[   415.056] (**) Microsoft Vmbus HID-compliant Mouse: always reports core events
[   415.056] (**) Option "Device" "/dev/input/event0"
[   415.056] (**) Option "_source" "server/udev"
[   415.062] (II) event0  - Microsoft Vmbus HID-compliant Mouse: is tagged by udev as: Mouse
[   415.062] (II) event0  - Microsoft Vmbus HID-compliant Mouse: device is a pointer
[   415.062] (II) event0  - Microsoft Vmbus HID-compliant Mouse: device removed
[   415.096] (**) Option "config_info" "udev:/sys/devices/0006:045E:0621.0001/input/input0/event0"
[   415.096] (II) XINPUT: Adding extended input device "Microsoft Vmbus HID-compliant Mouse" (type: MOUSE, id 6)
[   415.096] (**) Option "AccelerationScheme" "none"
[   415.096] (**) Microsoft Vmbus HID-compliant Mouse: (accel) selected scheme none/0
[   415.096] (**) Microsoft Vmbus HID-compliant Mouse: (accel) acceleration factor: 2.000
[   415.096] (**) Microsoft Vmbus HID-compliant Mouse: (accel) acceleration threshold: 4
[   415.096] (II) event0  - Microsoft Vmbus HID-compliant Mouse: is tagged by udev as: Mouse
[   415.096] (II) event0  - Microsoft Vmbus HID-compliant Mouse: device is a pointer
[   415.096] (II) config/udev: Adding input device Microsoft Vmbus HID-compliant Mouse (/dev/input/js0)
[   415.096] (II) No input driver specified, ignoring this device.
[   415.096] (II) This device may have been added with another device file.
[   415.097] (II) config/udev: Adding input device Microsoft Vmbus HID-compliant Mouse (/dev/input/mouse0)
[   415.097] (II) No input driver specified, ignoring this device.
[   415.097] (II) This device may have been added with another device file.
[   415.097] (II) config/udev: Adding input device AT Translated Set 2 keyboard (/dev/input/event2)
[   415.097] (**) AT Translated Set 2 keyboard: Applying InputClass "evdev keyboard catchall"
[   415.097] (**) AT Translated Set 2 keyboard: Applying InputClass "libinput keyboard catchall"
[   415.097] (II) Using input driver 'libinput' for 'AT Translated Set 2 keyboard'
[   415.097] (**) AT Translated Set 2 keyboard: always reports core events
[   415.097] (**) Option "Device" "/dev/input/event2"
[   415.097] (**) Option "_source" "server/udev"
[   415.097] (II) event2  - AT Translated Set 2 keyboard: is tagged by udev as: Keyboard
[   415.097] (II) event2  - AT Translated Set 2 keyboard: device is a keyboard
[   415.098] (II) event2  - AT Translated Set 2 keyboard: device removed
[   415.112] (**) Option "config_info" "udev:/sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/d34b2567-b9b6-42b9-8778-0a4ec0b955bf/serio0/input/input2/event2"
[   415.112] (II) XINPUT: Adding extended input device "AT Translated Set 2 keyboard" (type: KEYBOARD, id 7)
[   415.112] (II) event2  - AT Translated Set 2 keyboard: is tagged by udev as: Keyboard
[   415.112] (II) event2  - AT Translated Set 2 keyboard: device is a keyboard
[   415.113] (II) config/udev: Adding input device PC Speaker (/dev/input/event1)
[   415.113] (II) No input driver specified, ignoring this device.
[   415.113] (II) This device may have been added with another device file.
[   421.728] (II) event0  - Microsoft Vmbus HID-compliant Mouse: device removed
[   421.776] (II) event2  - AT Translated Set 2 keyboard: device removed
[   421.792] (II) UnloadModule: "libinput"
[   421.792] (II) UnloadModule: "libinput"
[   421.795] (II) Server terminated successfully (0). Closing log file.
pi@debian:~/printer_data/logs$ cat KlipperScreen.log
2024-03-09 10:36:51,352 [functions.py:log_start()] - --------------------KlipperScreen Log Start--------------------
2024-03-09 10:36:51,352 [functions.py:log_start()] - KlipperScreen Version: v0.3.9-28-gb7d9517
2024-03-09 10:36:51,352 [functions.py:log_start()] - Python version: 3.9
2024-03-09 10:36:51,369 [config.py:get_config_file_location()] - Passed config (-c): .
2024-03-09 10:36:51,369 [config.py:__init__()] - Config path location: /home/pi/KlipperScreen/ks_includes/defaults.conf
2024-03-09 10:36:51,371 [config.py:__init__()] - Configured printers: [
  {
    "Printer": {
      "moonraker_host": "127.0.0.1",
      "moonraker_port": "7125",
      "moonraker_api_key": ""
    }
  }
]
2024-03-09 10:36:51,379 [config.py:create_translations()] - Selected lang: None OS lang: en_US
2024-03-09 10:36:51,379 [config.py:install_language()] - Using lang en
2024-03-09 10:36:51,381 [screen.py:__init__()] - Monitors: 1 using number: 0
2024-03-09 10:36:51,382 [screen.py:__init__()] - Screen resolution: 1024x768
2024-03-09 10:36:51,382 [KlippyGtk.py:__init__()] - Font size: 23.8 (medium)
2024-03-09 10:36:51,456 [screen.py:set_screenblanking_timeout()] - Changing screen blanking to: 3600
2024-03-09 10:36:51,458 [screen.py:set_screenblanking_timeout()] - Using DPMS
2024-03-09 10:36:51,460 [screen.py:initial_connection()] - Default printer: None
2024-03-09 10:36:51,465 [screen.py:connect_printer()] - Connecting to printer: Printer
2024-03-09 10:36:51,466 [screen.py:_load_panel()] - Loading panel: splash_screen
2024-03-09 10:36:51,472 [screen.py:attach_panel()] - Current panel hierarchy: splash_screen
2024-03-09 10:36:51,473 [KlippyWebsocket.py:connect()] - Attempting to connect
2024-03-09 10:36:51,473 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/server/info
2024-03-09 10:36:51,476 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/access/oneshot_token
2024-03-09 10:36:51,477 [KlippyWebsocket.py:connect()] - Starting websocket thread
2024-03-09 10:36:51,479 [_logging.py:info()] - Websocket connected
2024-03-09 10:36:51,479 [KlippyWebsocket.py:on_open()] - Moonraker Websocket Open
2024-03-09 10:36:51,481 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/server/info
2024-03-09 10:36:51,482 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/server/webcams/list
2024-03-09 10:36:51,483 [printer.py:configure_cameras()] - Cameras: []
2024-03-09 10:36:51,483 [screen.py:init_klipper()] - Moonraker info {'klippy_connected': True, 'klippy_state': 'error', 'components': ['secrets', 'template', 'klippy_connection', 'jsonrpc', 'internal_transport', 'application', 'websockets', 'dbus_manager', 'database', 'file_manager', 'authorization', 'klippy_apis', 'shell_command', 'machine', 'data_store', 'proc_stats', 'job_state', 'job_queue', 'http_client', 'announcements', 'webcam', 'extensions', 'history', 'update_manager', 'octoprint_compat'], 'failed_components': [], 'registered_directories': ['config', 'logs', 'gcodes', 'config_examples', 'docs'], 'warnings': ["[update_manager mobileraker]: Moonraker is not permitted to restart service 'mobileraker'.  To enable management of this service add mobileraker to the bottom of the file /home/pi/printer_data/moonraker.asvc.  To disable management for this service set 'is_system_service: False' in the configuration for this section."], 'websocket_count': 2, 'moonraker_version': 'v0.8.0-320-g6b1b8c5', 'missing_klippy_requirements': [], 'api_version': [1, 4, 0], 'api_version_string': '1.4.0'}
2024-03-09 10:36:51,484 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/info
2024-03-09 10:36:51,485 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/objects/query?configfile
2024-03-09 10:36:51,597 [screen.py:init_klipper()] - {'configfile': {'config': {'mcu': {'serial': '/dev/serial/by-id/<your-mcu-id>'}, 'virtual_sdcard': {'path': '/home/pi/printer_data/gcodes', 'on_error_gcode': 'CANCEL_PRINT'}, 'printer': {'kinematics': 'none', 'max_velocity': '1000', 'max_accel': '1000'}}, 'settings': {'mcu': {'serial': '/dev/serial/by-id/<your-mcu-id>', 'baud': 250000, 'max_stepper_error': 2.5e-05}, 'virtual_sdcard': {'path': '/home/pi/printer_data/gcodes', 'on_error_gcode': 'CANCEL_PRINT'}, 'printer': {'max_velocity': 1000.0, 'max_accel': 1000.0, 'max_accel_to_decel': 500.0, 'square_corner_velocity': 5.0, 'kinematics': 'none'}, 'idle_timeout': {'timeout': 600.0, 'gcode': "\n{% if 'heaters' in printer %}\n   TURN_OFF_HEATERS\n{% endif %}\nM84\n"}}, 'warnings': [], 'save_config_pending': False, 'save_config_pending_items': {}}}
2024-03-09 10:36:51,597 [printer.py:stop_tempstore_updates()] - Stopping tempstore
2024-03-09 10:36:51,598 [printer.py:reinit()] - Klipper version: v0.12.0-117-g71604b71
2024-03-09 10:36:51,598 [printer.py:reinit()] - # Extruders: 0
2024-03-09 10:36:51,598 [printer.py:reinit()] - # Temperature devices: 0
2024-03-09 10:36:51,598 [printer.py:reinit()] - # Fans: 0
2024-03-09 10:36:51,598 [printer.py:reinit()] - # Output pins: 0
2024-03-09 10:36:51,598 [printer.py:reinit()] - # Leds: 0
2024-03-09 10:36:51,598 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/gcode/help
2024-03-09 10:36:51,599 [KlippyWebsocket.py:object_subscription()] - Sending printer.objects.subscribe
2024-03-09 10:36:51,600 [KlippyRest.py:_do_request()] - Sending get to http://127.0.0.1:7125/printer/objects/query?bed_mesh&configfile&display_status&extruder&fan&gcode_move&heater_bed&idle_timeout&pause_resume&print_stats&toolhead&virtual_sdcard&webhooks&motion_report&firmware_retraction&exclude_object&manual_probe
2024-03-09 10:36:51,848 [files.py:set_gcodes_path()] - Gcodes path: /home/pi/printer_data/gcodes
2024-03-09 10:36:51,849 [KlippyWebsocket.py:get_file_list()] - Sending server.files.list
2024-03-09 10:36:51,849 [screen.py:init_klipper()] - Printer initialized
2024-03-09 10:36:51,849 [printer.py:change_state()] - Changing state from 'disconnected' to 'error'
2024-03-09 10:36:51,849 [printer.py:change_state()] - Adding callback for state: error
2024-03-09 10:36:51,853 [screen.py:show_panel()] - Reinitializing panel
2024-03-09 10:36:51,858 [screen.py:attach_panel()] - Current panel hierarchy: splash_screen
rdbahm commented 3 months ago

I did a git bisect on this issue, since it doesn't seem to repro in v0.3.9. The issue seems to start at commit 74e9f61c40b0c784939f9b34a060200341fcfa7f.

alfrix commented 3 months ago

just did an install of the old bullseye, and i could reproduce the issue after fighting my screen that didn't want to show up,

apparently this is caused by %I in the service changing %I to tty7 and rebooting fixes the issue did not happen on bookworm but i always install and use zsh so maybe that's the difference

rdbahm commented 3 months ago

Yep, new commit seems to be working in my test scenario as well. Thanks for the fast fix.