Discussion:
Failed to apply ACLs: Invalid argument
(too old to reply)
Matwey V. Kornilov
2017-07-18 13:28:09 UTC
Permalink
Raw Message
Hello,

I am running systemd 228. And one one particular system installation
there are messages 'Failed to apply ACLs: Invalid argument' from
systemd-logind. Moreover, ACL on /dev/dri/* are not set correctly
after user log in. How could I figure out which argument is invalid?
Managing ACLs on /dev filesystem using setfacl works fine. I've tried
using debug log_level, but nothing helpful here:


июл 18 16:21:00 photon systemd-logind[12814]: Got message
type=method_call sender=:1.59 destination=org.freedesktop.login1 obj
ect=/org/freedesktop/login1 interface=org.freedesktop.login1.Manager
member=CreateSession cookie=2 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Sent message
type=method_call sender=n/a destination=org.freedesktop.DBus object
=/org/freedesktop/DBus interface=org.freedesktop.DBus
member=GetConnectionUnixUser cookie=108 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Got message
type=method_return sender=org.freedesktop.DBus destination=:1.53 obj
ect=n/a interface=n/a member=n/a cookie=33 reply_cookie=108 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Sent message type=signal
sender=n/a destination=n/a object=/org/freedesktop/logi
n1/seat/seat0 interface=org.freedesktop.DBus.Properties
member=PropertiesChanged cookie=109 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Sent message
type=method_call sender=n/a destination=org.freedesktop.systemd1
object=/org/freedesktop/systemd1
interface=org.freedesktop.systemd1.Manager member=StartTransientUnit
cookie=110 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Got message
type=method_return sender=:1.0 destination=:1.53 object=n/a
interface=n/a member=n/a cookie=2075 reply_cookie=110 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: New session 6 of user matwey.
июл 18 16:21:00 photon systemd-logind[12814]: VT changed to 7
июл 18 16:21:00 photon systemd-logind[12814]: Sent message type=signal
sender=n/a destination=n/a object=/org/freedesktop/login1/session/_35
interface=org.freedesktop.DBus.Properties member=PropertiesChanged
cookie=111 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Failed to apply ACLs:
Invalid argument
июл 18 16:21:00 photon systemd-logind[12814]: Electing new display for
user matwey
июл 18 16:21:00 photon systemd-logind[12814]: Choosing session 6 in
preference to 4
июл 18 16:21:00 photon systemd-logind[12814]: Ignoring session 2
июл 18 16:21:00 photon systemd-logind[12814]: Sent message type=signal
sender=n/a destination=n/a object=/org/freedesktop/login1
interface=org.freedesktop.login1.Manager member=SessionNew cookie=112
reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Sent message type=signal
sender=n/a destination=n/a object=/org/freedesktop/login1/user/_1001
interface=org.freedesktop.DBus.Properties member=PropertiesChanged
cookie=113 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Sent message type=signal
sender=n/a destination=n/a object=/org/freedesktop/login1/seat/seat0
interface=org.freedesktop.DBus.Properties member=PropertiesChanged
cookie=114 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Got message type=signal
sender=:1.0 destination=n/a object=/org/freedesktop/systemd1
interface=org.freedesktop.systemd1.Manager member=JobRemoved
cookie=2078 reply_cookie=0 error=n/a
июл 18 16:21:00 photon systemd-logind[12814]: Sending reply about
created session: id=6 object_path=/org/freedesktop/login1/session/_36
uid=1001 runtime_path=/run/user/1001 session_fd=22 seat=seat0 vtnr=7
июл 18 16:21:00 photon systemd-logind[12814]: Sent message
type=method_return sender=n/a destination=:1.59 object=n/a
interface=n/a member=n/a cookie=115 reply_cookie=2 error=n/a
--
With best regards,
Matwey V. Kornilov
Lennart Poettering
2017-07-19 08:51:45 UTC
Permalink
Raw Message
Post by Matwey V. Kornilov
Hello,
I am running systemd 228. And one one particular system installation
there are messages 'Failed to apply ACLs: Invalid argument' from
systemd-logind. Moreover, ACL on /dev/dri/* are not set correctly
after user log in. How could I figure out which argument is invalid?
Managing ACLs on /dev filesystem using setfacl works fine. I've tried
No idea, but I'd recommend strace'ing logind when this happens, and
tracking looking for relevant operations on the device nodes...

logind doesn't do anything particularly magic... We just invoke
libacl, and normally libacl should validate enough what we pass
there...

do you use any MAC or so? selinux? smack? apparmor?

Do you any non-standard UIDs? i.e. 65535 or so?

Lennart
--
Lennart Poettering, Red Hat
Matwey V. Kornilov
2017-07-19 09:38:37 UTC
Permalink
Raw Message
This is all that is relevant to Invalid Argument errno in strace:

readlinkat(AT_FDCWD, "/sys/devices/pci0000:00/0000:00:02.0/drm/card0",
0x55d7a4d59230, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-DP-1",
0x55d7a4d57190, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-HDMI-A-1",
0x55d7a4d555f0, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-VGA-1",
0x55d7a4d555f0, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-eDP-1",
0x55d7a4d555f0, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/pci0000:00/0000:00:02.0/graphics/fb0", 0x55d7a4d555f0,
99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input1/event1",
0x55d7a4d54c70, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input2/event2",
0x55d7a4d54b60, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD,
"/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input0/event0",
0x55d7a4d54cd0, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/devices/virtual/input/input7/event7",
0x55d7a4d54bb0, 99) = -1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport_pc", 0x55d7a4d63350, 99) =
-1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d63350, 99) = -1
EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport_pc", 0x55d7a4d60f90, 99) =
-1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d60f90, 99) = -1
EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport_pc", 0x55d7a4d60fb0, 99) =
-1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d60fb0, 99) = -1
EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport_pc", 0x55d7a4d60fb0, 99) =
-1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d60fb0, 99) = -1
EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport_pc", 0x55d7a4d5d940, 99) =
-1 EINVAL (Invalid argument)
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)

The files are present, but all of them are directories, not symlinks:

drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/LNXSYSTM:00/LNXPWRBN:00/input/input1/event1
drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input2/event2
drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input0/event0
drwxr-xr-x 7 root root 0 июл 19 12:35
/sys/devices/pci0000:00/0000:00:02.0/drm/card0
drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-DP-1
drwxr-xr-x 4 root root 0 июл 19 12:35
/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-eDP-1
drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-HDMI-A-1
drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-VGA-1
drwxr-xr-x 3 root root 0 июл 19 12:35
/sys/devices/pci0000:00/0000:00:02.0/graphics/fb0
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc

It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Post by Lennart Poettering
Post by Matwey V. Kornilov
Hello,
I am running systemd 228. And one one particular system installation
there are messages 'Failed to apply ACLs: Invalid argument' from
systemd-logind. Moreover, ACL on /dev/dri/* are not set correctly
after user log in. How could I figure out which argument is invalid?
Managing ACLs on /dev filesystem using setfacl works fine. I've tried
No idea, but I'd recommend strace'ing logind when this happens, and
tracking looking for relevant operations on the device nodes...
logind doesn't do anything particularly magic... We just invoke
libacl, and normally libacl should validate enough what we pass
there...
do you use any MAC or so? selinux? smack? apparmor?
Do you any non-standard UIDs? i.e. 65535 or so?
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
Lennart Poettering
2017-07-19 09:47:47 UTC
Permalink
Raw Message
[...]
Post by Matwey V. Kornilov
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)
realinkat() returns EINVAL when invoked on a non-symlinks. It's not a
real error, just a way to report that mismatch.
Post by Matwey V. Kornilov
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc
It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Not sure what else I can suggest then, except attaching gdb to logind
and check what happens when you switch VTs... it should be sufficient
to set a breakpoint onto devnode_acl_all() and wait until it gets
triggered, and then follow the code until you see EINVAL thrown.

Unless you know gdb well enough you shouldn't attempt that though...

Lennart
--
Lennart Poettering, Red Hat
Matwey V. Kornilov
2017-07-19 10:10:17 UTC
Permalink
Raw Message
Post by Lennart Poettering
[...]
Post by Matwey V. Kornilov
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)
realinkat() returns EINVAL when invoked on a non-symlinks. It's not a
real error, just a way to report that mismatch.
Post by Matwey V. Kornilov
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc
It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Not sure what else I can suggest then, except attaching gdb to logind
and check what happens when you switch VTs... it should be sufficient
to set a breakpoint onto devnode_acl_all() and wait until it gets
triggered, and then follow the code until you see EINVAL thrown.
Unless you know gdb well enough you shouldn't attempt that though...
Ok, it is udev_enumerate_scan_devices who returns -22
Post by Lennart Poettering
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
Matwey V. Kornilov
2017-07-19 10:32:23 UTC
Permalink
Raw Message
Post by Matwey V. Kornilov
Post by Lennart Poettering
[...]
Post by Matwey V. Kornilov
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)
realinkat() returns EINVAL when invoked on a non-symlinks. It's not a
real error, just a way to report that mismatch.
Post by Matwey V. Kornilov
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc
It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Not sure what else I can suggest then, except attaching gdb to logind
and check what happens when you switch VTs... it should be sufficient
to set a breakpoint onto devnode_acl_all() and wait until it gets
triggered, and then follow the code until you see EINVAL thrown.
Unless you know gdb well enough you shouldn't attempt that though...
Ok, it is udev_enumerate_scan_devices who returns -22
Now I see that something wrong happens inside

enumerator_scan_devices_children

at

sd_device_get_syspath
Post by Matwey V. Kornilov
Post by Lennart Poettering
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
Matwey V. Kornilov
2017-07-19 12:12:33 UTC
Permalink
Raw Message
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Lennart Poettering
[...]
Post by Matwey V. Kornilov
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)
realinkat() returns EINVAL when invoked on a non-symlinks. It's not a
real error, just a way to report that mismatch.
Post by Matwey V. Kornilov
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc
It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Not sure what else I can suggest then, except attaching gdb to logind
and check what happens when you switch VTs... it should be sufficient
to set a breakpoint onto devnode_acl_all() and wait until it gets
triggered, and then follow the code until you see EINVAL thrown.
Unless you know gdb well enough you shouldn't attempt that though...
Ok, it is udev_enumerate_scan_devices who returns -22
Now I see that something wrong happens inside
enumerator_scan_devices_children
at
sd_device_get_syspath
k = sd_device_new_from_device_id(&device, dent->d_name);

inside enumerator_scan_devices_tag() returns -22 for some entry.
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Lennart Poettering
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
Matwey V. Kornilov
2017-07-19 19:53:24 UTC
Permalink
Raw Message
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Lennart Poettering
[...]
Post by Matwey V. Kornilov
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)
realinkat() returns EINVAL when invoked on a non-symlinks. It's not a
real error, just a way to report that mismatch.
Post by Matwey V. Kornilov
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc
It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Not sure what else I can suggest then, except attaching gdb to logind
and check what happens when you switch VTs... it should be sufficient
to set a breakpoint onto devnode_acl_all() and wait until it gets
triggered, and then follow the code until you see EINVAL thrown.
Unless you know gdb well enough you shouldn't attempt that though...
Ok, it is udev_enumerate_scan_devices who returns -22
Now I see that something wrong happens inside
enumerator_scan_devices_children
at
sd_device_get_syspath
k = sd_device_new_from_device_id(&device, dent->d_name);
inside enumerator_scan_devices_tag() returns -22 for some entry.
I suspect 21d6220fe0bf24fda7df9833961e022cafa439bc will fix my issue.
I will check tomorrow.
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Lennart Poettering
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
Matwey V. Kornilov
2017-07-20 07:45:44 UTC
Permalink
Raw Message
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Lennart Poettering
[...]
Post by Matwey V. Kornilov
readlinkat(AT_FDCWD, "/sys/module/parport", 0x55d7a4d5d940, 99) = -1
EINVAL (Invalid argument)
realinkat() returns EINVAL when invoked on a non-symlinks. It's not a
real error, just a way to report that mismatch.
Post by Matwey V. Kornilov
drwxr-xr-x 3 root root 0 июл 19 12:35 /sys/devices/virtual/input/input7/event7
drwxr-xr-x 5 root root 0 июл 19 12:31 /sys/module/parport
drwxr-xr-x 7 root root 0 июл 19 12:33 /sys/module/parport_pc
It is brand-new openSUSE 42.2 installation. No selinux or something like that.
Not sure what else I can suggest then, except attaching gdb to logind
and check what happens when you switch VTs... it should be sufficient
to set a breakpoint onto devnode_acl_all() and wait until it gets
triggered, and then follow the code until you see EINVAL thrown.
Unless you know gdb well enough you shouldn't attempt that though...
Ok, it is udev_enumerate_scan_devices who returns -22
Now I see that something wrong happens inside
enumerator_scan_devices_children
at
sd_device_get_syspath
k = sd_device_new_from_device_id(&device, dent->d_name);
inside enumerator_scan_devices_tag() returns -22 for some entry.
I suspect 21d6220fe0bf24fda7df9833961e022cafa439bc will fix my issue.
I will check tomorrow.
I've just found that

sd_device_new_from_subsystem_sysname returns -22 for parport_pc
device, because subsys variable has no ':' and driver == NULL which
leads to -EINVAL in systemd v228.
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
Post by Lennart Poettering
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
--
With best regards,
Matwey V. Kornilov
Lennart Poettering
2017-07-20 08:05:12 UTC
Permalink
Raw Message
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
I suspect 21d6220fe0bf24fda7df9833961e022cafa439bc will fix my issue.
I will check tomorrow.
I've just found that
sd_device_new_from_subsystem_sysname returns -22 for parport_pc
device, because subsys variable has no ':' and driver == NULL which
leads to -EINVAL in systemd v228.
And did 21d6220fe0bf24fda7df9833961e022cafa439bc fix the issue for
you? Is this still a problem on more current versions?

Lennart
--
Lennart Poettering, Red Hat
Matwey V. Kornilov
2017-07-20 09:17:37 UTC
Permalink
Raw Message
Post by Lennart Poettering
Post by Matwey V. Kornilov
Post by Matwey V. Kornilov
I suspect 21d6220fe0bf24fda7df9833961e022cafa439bc will fix my issue.
I will check tomorrow.
I've just found that
sd_device_new_from_subsystem_sysname returns -22 for parport_pc
device, because subsys variable has no ':' and driver == NULL which
leads to -EINVAL in systemd v228.
And did 21d6220fe0bf24fda7df9833961e022cafa439bc fix the issue for
you? Is this still a problem on more current versions?
Yes, it helped. Seemingly, this needs to be backported to openSUSE's v228.
Post by Lennart Poettering
Lennart
--
Lennart Poettering, Red Hat
--
With best regards,
Matwey V. Kornilov
Loading...