-
Bug
-
Resolution: Duplicate
-
Normal
-
None
-
rhel-8.7.0
-
None
-
Moderate
-
rhel-sst-cs-plumbers
-
ssg_core_services
-
5
-
False
-
-
None
-
None
-
None
-
None
-
If docs needed, set a value
-
-
All
-
None
Description of problem:
We have a customer seeing spikes of CPU consumption of polkitd and dbus-daemon happening every minute:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
902 polkitd 20 0 1670256 51696 16964 R 44.4 0.2 250:00.33 polkitd
917 dbus 20 0 88132 8884 4888 R 11.1 0.0 46:21.10 dbus-da+
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
This spike is due to "CheckAuthorization" queries being performed by every single graphical session instance, and this twice, every time the number of user sessions changes (e.g. a new session appears or a session is destroyed):
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
- grep "CheckAuthorization" gnome-shell.strace
1717 09:48:13.930859 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[Unknown macro: {iov_base="l101211000\200245000101g020(sa{sv})sa{ss}us\0\0\0\1\1o\0%\0\0\0/org/freedesktop/PolicyKit1/Authority\0\0\0\3\1s\0\22\0\0\0CheckAuthorization\0\0\0\0\0\0\2\1s\0$\0\0\0org.freedesktop.PolicyKit1.Authority\0\0\0\0\6\1s\0\4\0\0\0:1.7\0\0\0\0\f\0\0\0unix-process\0\0\0\0@\0\0\0\3\0\0\0pid\0\1u\0\0\201\6\0\0\n\0\0\0start-time\0\1t\0\0\0\0\0\0\0\264\3\0\0\0\0\0\0\3\0\0\0uid\0\1i\0\0*\0\0\0\33\0\0\0org.freedesktop.bolt.enroll\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=321}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 321 <0.000015>
1717 09:48:13.931141 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\241\0\0\0]\2\0\0\245\0\0\0\10\1g\0\20(sa{sv})sa{ss}us\0\0\0\1\1o\0%\0\0\0/org/freedesktop/PolicyKit1/Authority\0\0\0\3\1s\0\22\0\0\0CheckAuthorization\0\0\0\0\0\0\2\1s\0$\0\0\0org.freedesktop.PolicyKit1.Authority\0\0\0\0\6\1s\0\4\0\0\0:1.7\0\0\0\0\f\0\0\0unix-process\0\0\0\0@\0\0\0\3\0\0\0pid\0\1u\0\0\201\6\0\0\n\0\0\0start-time\0\1t\0\0\0\0\0\0\0\264\3\0\0\0\0\0\0\3\0\0\0uid\0\1i\0\0*\0\0\0001\0\0\0org.freedesktop.packagekit.trigger-offline-update\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=345}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL <unfinished ...>
1717 09:48:13.931486 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\231\0\0\0^\2\0\0\245\0\0\0\10\1g\0\20(sa{sv})sa{ss}us00011o0%000/org/freedesktop/PolicyKit1/Authority00031s022000CheckAuthorization00000021s0$000org.freedesktop.PolicyKit1.Authority000061s04000}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 337 <0.000007>
1717 09:48:13.932241 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[Unknown macro: {iov_base="l101211000_200245000101g020(sa{sv})sa{ss}us\0\0\0\1\1o\0%\0\0\0/org/freedesktop/PolicyKit1/Authority\0\0\0\3\1s\0\22\0\0\0CheckAuthorization\0\0\0\0\0\0\2\1s\0$\0\0\0org.freedesktop.PolicyKit1.Authority\0\0\0\0\6\1s\0\4\0\0\0:1.7\0\0\0\0\f\0\0\0unix-process\0\0\0\0@\0\0\0\3\0\0\0pid\0\1u\0\0\201\6\0\0\n\0\0\0start-time\0\1t\0\0\0\0\0\0\0\264\3\0\0\0\0\0\0\3\0\0\0uid\0\1i\0\0*\0\0\0\33\0\0\0org.freedesktop.bolt.enroll\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=321}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 321 <0.000011>
1717 09:48:13.932370 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\241\0\0\0`\2\0\0\245\0\0\0\10\1g\0\20(sa{sv})sa{ss}us\0\0\0\1\1o\0%\0\0\0/org/freedesktop/PolicyKit1/Authority\0\0\0\3\1s\0\22\0\0\0CheckAuthorization\0\0\0\0\0\0\2\1s\0$\0\0\0org.freedesktop.PolicyKit1.Authority\0\0\0\0\6\1s\0\4\0\0\0:1.7\0\0\0\0\f\0\0\0unix-process\0\0\0\0@\0\0\0\3\0\0\0pid\0\1u\0\0\201\6\0\0\n\0\0\0start-time\0\1t\0\0\0\0\0\0\0\264\3\0\0\0\0\0\0\3\0\0\0uid\0\1i\0\0*\0\0\0001\0\0\0org.freedesktop.packagekit.trigger-offline-update\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=345}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 345 <0.000009>
1717 09:48:13.932475 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\231\0\0\0a\2\0\0\245\0\0\0\10\1g\0\20(sa{sv})sa{ss}us00011o0%000/org/freedesktop/PolicyKit1/Authority00031s022000CheckAuthorization00000021s0$000org.freedesktop.PolicyKit1.Authority000061s04000}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 337 <0.000006>
1717 09:48:13.932552 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[Unknown macro: {iov_base="l101211000b200245000101g020(sa{sv})sa{ss}us\0\0\0\1\1o\0%\0\0\0/org/freedesktop/PolicyKit1/Authority\0\0\0\3\1s\0\22\0\0\0CheckAuthorization\0\0\0\0\0\0\2\1s\0$\0\0\0org.freedesktop.PolicyKit1.Authority\0\0\0\0\6\1s\0\4\0\0\0:1.7\0\0\0\0\f\0\0\0unix-process\0\0\0\0@\0\0\0\3\0\0\0pid\0\1u\0\0\201\6\0\0\n\0\0\0start-time\0\1t\0\0\0\0\0\0\0\264\3\0\0\0\0\0\0\3\0\0\0uid\0\1i\0\0*\0\0\0\33\0\0\0org.freedesktop.bolt.enroll\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=321}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 321 <0.000006>
1717 09:48:13.932637 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\241\0\0\0c\2\0\0\245\0\0\0\10\1g\0\20(sa{sv})sa{ss}us\0\0\0\1\1o\0%\0\0\0/org/freedesktop/PolicyKit1/Authority\0\0\0\3\1s\0\22\0\0\0CheckAuthorization\0\0\0\0\0\0\2\1s\0$\0\0\0org.freedesktop.PolicyKit1.Authority\0\0\0\0\6\1s\0\4\0\0\0:1.7\0\0\0\0\f\0\0\0unix-process\0\0\0\0@\0\0\0\3\0\0\0pid\0\1u\0\0\201\6\0\0\n\0\0\0start-time\0\1t\0\0\0\0\0\0\0\264\3\0\0\0\0\0\0\3\0\0\0uid\0\1i\0\0*\0\0\0001\0\0\0org.freedesktop.packagekit.trigger-offline-update\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", iov_len=345}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 345 <0.000006>
1717 09:48:13.932715 sendmsg(6<UNIX:[35289->35290]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\1\0\1\231\0\0\0d\2\0\0\245\0\0\0\10\1g\0\20(sa{sv})sa{ss}us00011o0%000/org/freedesktop/PolicyKit1/Authority00031s022000CheckAuthorization00000021s0$000org.freedesktop.PolicyKit1.Authority000061s04000}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 337 <0.000006>
-
-
-
-
-
-
- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
-
-
-
-
-
-
Such operation is performed by all gnome-shell processes executing on the system, which can be high, e.g. when having VNC servers.
Note that the spike can be seen as soon as a few gnome-shell are executing (e.g. GDM greeter + 2 VNC servers).
After much digging, I was able to find out that this operation was due to reloading systemd sessions, which happens due to changes in /run/systemd/sessions directory upon session creation/deleting:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
(gdb) bt
#0 _GI__open64_nocancel (file=0x7efe1063fb1e "/run/systemd/sessions/", oflag=591872)
at ../sysdeps/unix/sysv/linux/open64_nocancel.c:45
#1 0x00007efe122d6309 in __opendir (name=name@entry=0x7efe1063fb1e "/run/systemd/sessions/")
at ../sysdeps/posix/opendir.c:92
#2 0x00007efe105f5a68 in get_files_in_directory (path=0x7efe1063fb1e "/run/systemd/sessions/", list=0x7fff1fadda88)
at ../src/basic/fs-util.c:450
#3 0x00007efe105bc3d7 in sd_get_sessions (sessions=sessions@entry=0x7fff1fadda88)
at ../src/libsystemd/sd-login/sd-login.c:790
#4 0x00007efdc432058a in reload_systemd_sessions (manager=0x561685af95e0)
at ../src/libaccountsservice/act-user-manager.c:1988
#5 0x00007efdc4320961 in on_session_monitor_event (stream=<optimized out>, manager=0x561685af95e0)
at ../src/libaccountsservice/act-user-manager.c:2040
#6 0x00007efe141c995d in g_main_dispatch (context=0x561685af4b40) at gmain.c:3193
#7 g_main_context_dispatch (context=context@entry=0x561685af4b40) at gmain.c:3873
#8 0x00007efe141c9d18 in g_main_context_iterate (context=0x561685af4b40, block=block@entry=1,
dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3946
#9 0x00007efe141ca042 in g_main_loop_run (loop=0x561686913400) at gmain.c:4142
#10 0x00007efe1265bf00 in meta_run () at ../src/core/main.c:685
#11 0x000056168415256f in main (argc=<optimized out>, argv=<optimized out>) at ../src/main.c:503
(gdb) f 5
#5 0x00007efdc4320961 in on_session_monitor_event (stream=<optimized out>, manager=0x561685af95e0)
at ../src/libaccountsservice/act-user-manager.c:2040
2040 reload_systemd_sessions (manager);
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
Clearly this code is sub-optimal and needs enhancement.
Version-Release number of selected component (if applicable):
accountsservice-0.6.55-4.el8.x86_64
How reproducible:
Always
Steps to Reproduce:
1. Set up several users that will have VNC services
- for i in $(seq 1 10); do useradd user$i; done
- for i in $(seq 1 10); do mkdir /home/user$i/.vnc; echo -n "redhat" | vncpasswd -f > /home/user$i/.vnc/passwd; chmod 600 /home/user$i/.vnc/passwd; chown -R user$i:user$i /home/user$i/.vnc; done
2. Enable+Start the services
- for i in $(seq 1 10); do systemctl enable vncserver@:$i.service --now; done
3. Login, logout or execute a cron (anything that creates a session)
$ ssh localhost
Actual results:
Spike of polkitd and dbus-daemon
Expected results:
No spike, no CheckAuthorization for current sessions
Additional info:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
- top -d 1 -b -p 899 -p 905
[...]
top - 10:11:48 up 5 min, 2 users, load average: 1.02, 4.16, 2.54
Tasks: 2 total, 1 running, 1 sleeping, 0 stopped, 0 zombie
%Cpu(s): 12.6 us, 9.6 sy, 0.0 ni, 76.3 id, 0.5 wa, 0.5 hi, 0.5 si, 0.0 st
MiB Mem : 7955.7 total, 675.0 free, 6126.2 used, 1154.5 buff/cache
MiB Swap: 2048.0 total, 2048.0 free, 0.0 used. 1474.6 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
905 polkitd 20 0 1823904 34672 18316 S 5.9 0.4 0:11.55 polkitd
899 dbus 20 0 71516 16564 4268 R 3.0 0.2 0:02.60 dbus-daemon
top - 10:11:49 up 5 min, 2 users, load average: 1.02, 4.16, 2.54
Tasks: 2 total, 1 running, 1 sleeping, 0 stopped, 0 zombie
%Cpu(s): 32.0 us, 22.3 sy, 0.0 ni, 43.7 id, 0.0 wa, 1.0 hi, 0.5 si, 0.5 st
MiB Mem : 7955.7 total, 675.0 free, 6126.2 used, 1154.5 buff/cache
MiB Swap: 2048.0 total, 2048.0 free, 0.0 used. 1474.6 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
905 polkitd 20 0 1823904 34792 18316 S 30.0 0.4 0:11.85 polkitd
899 dbus 20 0 71516 16564 4268 R 10.0 0.2 0:02.70 dbus-daemon
top - 10:11:50 up 5 min, 2 users, load average: 1.02, 4.16, 2.54
Tasks: 2 total, 0 running, 2 sleeping, 0 stopped, 0 zombie
%Cpu(s): 7.0 us, 4.0 sy, 0.0 ni, 88.0 id, 0.0 wa, 0.5 hi, 0.5 si, 0.0 st
MiB Mem : 7955.7 total, 670.5 free, 6130.6 used, 1154.6 buff/cache
MiB Swap: 2048.0 total, 2048.0 free, 0.0 used. 1470.2 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
905 polkitd 20 0 1824928 34828 18316 S 6.0 0.4 0:11.91 polkitd
899 dbus 20 0 71516 16564 4268 S 2.0 0.2 0:02.72 dbus-daemon
[...]
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
With stracing polkit and logging in:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
- strace -fttTvyy -s 512 -p 905 -o polkit.strace
strace: Process 905 attached with 6 threads
strace: Process 12194 attached
strace: Process 12201 attached
strace: Process 12206 attached
strace: Process 12235 attached
strace: Process 12236 attached
...
^C
- grep -c CheckAuthorization polkit.strace
43
- grep CheckAuthorization polkit.strace | grep -c trigger-offline-update
21-
-
-
-
-
-
- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
-
-
-
-
-
-
If you enable sssd and use remote users, the spike is even more visible because of the sssd work induced by querying the users.
- external trackers