Bug#1006368: upowerd: cannot open '/dev/input/event3': Success

[Christian Göttsche]

Package: upower
Version: 0.99.16-1

Since the update to version 0.99.16-1 upowerd issues the following log
with priority warning:

cannot open '/dev/input/event3': Success

In verbose mode the output is:


Feb 24 12:21:02 dlaptop systemd[1]: Starting Daemon for power management...
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Acquired
inhibitor lock (7, delay)
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Starting
upowerd version 0.99.16
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 daemon now coldplug
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 registering
subsystem : power_supply
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 taking a
guess for power supply scope
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 added native-path: AC0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 object path
= /org/freedesktop/UPower/devices/line_power_AC0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 added AC0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 emitting
added: /org/freedesktop/UPower/devices/line_power_AC0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 on_battery = no
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 warning_level = none
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 taking a
guess for power supply scope
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 using min
design voltage
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 using min
design voltage
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 Setup poll
for 'BAT0' every 120 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 added
native-path: BAT0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 using id:
ASUS_Battery-56
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 loading 199
items of data from /var/lib/upower/history-rate-ASUS_Battery-56.dat
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 loading 120
items of data from /var/lib/upower/history-charge-ASUS_Battery-56.dat
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 loading 54
items of data from
/var/lib/upower/history-time-full-ASUS_Battery-56.dat
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 loading 156
items of data from
/var/lib/upower/history-time-empty-ASUS_Battery-56.dat
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 saving in 600 seconds
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 object path
= /org/freedesktop/UPower/devices/battery_BAT0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 added BAT0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 emitting
added: /org/freedesktop/UPower/devices/battery_BAT0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 on_battery = yes
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 registering
subsystem : usb
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-0:1.0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-0:1.0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.4
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.4
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.5
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.5
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1:1.0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 failed to
coldplug /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1:1.0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 registering
subsystem : usbmisc
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 registering
subsystem : input
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for /sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input13
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input13/event6
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/ATK4002:00/input/input12
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/ATK4002:00/input/input12/event4
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input9
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input9/event1
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 no device
file: /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0D:00/input/input10
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 cannot open
'/dev/input/event3': Success
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0E:00/input/input11
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0E:00/input/input11/event5
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input16
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input16/event9
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input17
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input17/event10
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input18
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input18/event11
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input19
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input19/event12
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input20
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:03.0/sound/card0/input20/event13
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:1b.0/sound/card1/input21
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:1b.0/sound/card1/input21/event14
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:1b.0/sound/card1/input22
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not the
watched switch:
/sys/devices/pci0000:00/0000:00:1b.0/sound/card1/input22/event15
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for /sys/devices/platform/asus-nb-wmi/input/input15
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/platform/asus-nb-wmi/input/input15/event8
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for /sys/devices/platform/i8042/serio0/input/input0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/platform/i8042/serio0/input/input0/event0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for /sys/devices/platform/i8042/serio4/input/input8
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/platform/i8042/serio4/input/input8/event2
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for
/sys/devices/platform/i8042/serio4/input/input8/mouse0
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for /sys/devices/platform/pcspkr/input/input14
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 invalid
bitmask entry for /sys/devices/platform/pcspkr/input/input14/event7
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not a switch
[/sys/devices/virtual/input/mice/../capabilities/sw]
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 not a switch
[/sys/devices/virtual/input/mice/capabilities/sw]
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 on_battery = yes
Feb 24 12:21:02 dlaptop upowerd[4395]: TI:12:21:02 daemon now
not coldplug
Feb 24 12:21:02 dlaptop systemd[1]: Started Daemon for power management.



-- System Information:
Debian Release: bookworm/sid
APT prefers unstable
APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)

Kernel: Linux 5.16.0-1-amd64 (SMP w/4 CPU threads; PREEMPT)
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), LANGUAGE=en_GB
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: SELinux: enabled - Mode: Permissive - Policy name: debian

Versions of packages upower depends on:
ii dbus 1.12.20-4
ii libc6 2.33-7
ii libglib2.0-0 2.70.4-1
ii libgudev-1.0-0 237-2
ii libimobiledevice6 1.3.0-6
ii libplist3 2.2.0-6
ii libupower-glib3 0.99.16-1
ii udev 250.3-2

Versions of packages upower recommends:
ii policykit-1 0.105-32

upower suggests no packages.

-- no debconf information


p.s.: it's not SELinux related, happens also in permissive mode

[Christian Göttsche]

Control: severity -1 serious

Bumping the severity since closing the laptop lid does not cause a sleep.

Looking at the opened file descriptors of upower

$ ls -la /proc/1198/fd
total 0
dr-x------. 2 root root 0 Feb 25 12:25 .
dr-xr-xr-x. 9 root root 0 Feb 25 12:25 ..
lrwx------. 1 root root 64 Feb 25 12:27 1 -> 'socket:[4678]'
lr-x------. 1 root root 64 Feb 25 12:27 10 ->
/sys/devices/platform/asus-nb-wmi/leds/asus::kbd_backlight/brightness_hw_changed
lrwx------. 1 root root 64 Feb 25 12:27 11 -> 'socket:[7205]'
lrwx------. 1 root root 64 Feb 25 12:27 2 -> 'socket:[4678]'
lrwx------. 1 root root 64 Feb 25 12:25 3 -> 'anon_inode:[eventfd]'
lrwx------. 1 root root 64 Feb 25 12:25 4 -> 'anon_inode:[eventfd]'
lrwx------. 1 root root 64 Feb 25 12:27 5 -> 'socket:[5540]'
lrwx------. 1 root root 64 Feb 25 12:27 6 -> 'anon_inode:[eventfd]'
l-wx------. 1 root root 64 Feb 25 12:27 7 -> /run/systemd/inhibit/2.ref
lrwx------. 1 root root 64 Feb 25 12:27 8 -> 'socket:[7203]'
lrwx------. 1 root root 64 Feb 25 12:27 9 ->
/sys/devices/platform/asus-nb-wmi/leds/asus::kbd_backlight/brightness

stdin, stdout and stderr are not opened.
Thus the open(2) call at
https://sources.debian.org/src/upower/0.99.16-1/src/linux/up-input.c/?hl=246#L2486

input->eventfp = open (device_file, O_RDONLY | O_NONBLOCK);
if (input->eventfp <= 0) {
g_warning ("cannot open '%s': %s", device_file, strerror (errno));
ret = FALSE;
goto out;
}

Probably returns successfully a new file descriptor with the value 0.
The condition should be "strictly less" instead of "less or equal".

See https://gitlab.freedesktop.org/upower/upower/-/commit/72469426b737f1398651efc360f62a86e3b2633b
for a fix
and https://gitlab.freedesktop.org/upower/upower/-/issues/174 for a
likewise bug report.