[SOLVED] systemd 250 error log

robson75 · 2021-12-27 13:19:45

After updating systemd today, the following error appeared in the journalctl log

Dec 27 14:08:02 pc dbus-daemon[513]: writing oom_score_adj error: Permission denied

Last edited by robson75 (2021-12-29 23:34:54)

seth · 2021-12-27 14:34:54

stat /proc/513
stat /proc/513/oom_score_adj
ps up 513

Alter the PID accordingly if the process has changed (eg. for a reboot)

merlock · 2021-12-27 15:16:00

Interesting. My error is:

Dec 27 09:07:42 Jammin1 at-spi-bus-launcher[1566]: dbus-daemon[1566]: writing oom_score_adj error: Permission denied

I would hazard to assume (for me) it's because:

systemctl list-unit-files|grep oom
dbus-org.freedesktop.oom1.service       alias           -
systemd-oomd.service                    disabled        disabled
systemd-oomd.socket                     disabled        disabled

I don't want to use it.

For grins:

stat /proc/1566
  File: /proc/1566
  Size: 0         	Blocks: 0          IO Block: 1024   directory
Device: 0,21	Inode: 14042       Links: 9
Access: (0555/dr-xr-xr-x)  Uid: ( 1000/  merell)   Gid: ( 1000/  merell)
Access: 2021-12-27 09:07:42.277494690 -0500
Modify: 2021-12-27 09:07:42.277494690 -0500
Change: 2021-12-27 09:07:42.277494690 -0500
 Birth: -

stat /proc/1566/oom_score_adj
  File: /proc/1566/oom_score_adj
  Size: 0         	Blocks: 0          IO Block: 1024   regular empty file
Device: 0,21	Inode: 14043       Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1000/  merell)   Gid: ( 1000/  merell)
Access: 2021-12-27 09:07:42.277494690 -0500
Modify: 2021-12-27 09:07:42.277494690 -0500
Change: 2021-12-27 09:07:42.277494690 -0500
 Birth: -

ps up 1566
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
merell      1566  0.0  0.0 161412  6076 ?        Sl   09:07   0:00 /usr/lib/at-spi2-registryd --use-gnome-session

seth · 2021-12-27 15:43:55

Can you write into that file as your user (just echo 1 > /proc/1566/oom_score_adj)?

robson75 · 2021-12-27 20:11:34

seth wrote:

stat /proc/513
stat /proc/513/oom_score_adj
ps up 513

stat /proc/1122

device  20
inode   18312
mode    16749
nlink   9
uid     1000
gid     1000
rdev    0
size    0
atime   1640635150
mtime   1640635150
ctime   1640635150
blksize 1024
blocks  0
link

stat /proc/1122/oom_score_adj

device  20
inode   18313
mode    33188
nlink   1
uid     1000
gid     1000
rdev    0
size    0
atime   1640635150
mtime   1640635150
ctime   1640635150
blksize 1024
blocks  0
link

ps up 1122

USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
robson      1122  0.0  0.0  15656  6444 ?        S    20:59   0:00 /usr/lib/gconfd-2

Last edited by robson75 (2021-12-27 20:12:36)

seth · 2021-12-27 20:13:26

seth wrote:

Can you write into that file as your user (just echo 1 > /proc/1566/oom_score_adj)?

robson75 · 2021-12-28 11:20:38

seth wrote:

Can you write into that file as your user (just echo 1 > /proc/1566/oom_score_adj)?

No, I cannot write as a regular user, only as root.

seth · 2021-12-28 13:56:44

It's probably only the dbus process and it's probably running w/ some capacities.
You still can

echo 1 > /proc/self/oom_score_adj

?

xerxes_ · 2021-12-28 17:32:44

I have 3 of that processes:

journalctl -b -g oom
gru 28 17:55:24 home at-spi-bus-launcher[413]: dbus-daemon[413]: writing oom_score_adj error: Permission denied
gru 28 17:59:59 home dbus-daemon[1400]: writing oom_score_adj error: Permission denied
gru 28 18:00:01 home dbus-daemon[1411]: writing oom_score_adj error: Permission denied

ps up 413 1400 1413
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
user         413  0.0  0.1 161468  6624 ?        Sl   17:55   0:00 /usr/lib/at-spi2-registryd --use-gnome-session
user        1400  0.0  1.2 558928 42080 ?        Sl   17:59   0:00 /usr/lib/goa-daemon
user        1411  0.0  0.2 311704  8924 ?        Sl   18:00   0:00 /usr/lib/goa-identity-service

and I can't do without admin rights:

echo 1 > /proc/413/oom_score_adj
bash: echo: write error: Permission denied

but I can do:

echo 1 > /proc/self/oom_score_adj

What to do now: do something with it or leave it/live with it?

Last edited by xerxes_ (2021-12-28 22:20:30)

seth · 2021-12-28 22:43:50

https://github.com/systemd/systemd/issues/21921
You gotta love lennartworld…

So, oom_score_adj controls how much likely a process will be killed by the OOM killer.
The affected processes seem to be the dbus activated ones

Usually the UID of a process can write that parameter except if the binary has any https://man.archlinux.org/man/core/man- … ities.7.en or you try to write a negative value ("echo -1 > /proc/self/oom_score_adj" should™ fail)
Since the process is owned by your users but you cannot write a positive value into the parameter, they're somehow provided w/ some caps by (likely) systemd which are not dropped (ever, since you still cannot write into it - this is not a race condition)

What's the output of

getpcaps 413 # again, adjust the PID

robson75 · 2021-12-29 13:12:54

@seth And isn't there a parameter to add to the grub file to get rid of this log entry?

seth · 2021-12-29 13:15:07

There's rather a shit-hits-the-fan situation where systemd equips random dbus-activcated processes w/ extended capabilities…
check getpcaps, this may be a cve (and I'm not rebooting this year anymore)

robson75 · 2021-12-29 13:28:20

getpcaps 526
526: =

seth · 2021-12-29 14:17:25

Ok, at least that's not the cause.
Poblem is that I've no idea why this is access restricted…

Shifted limit?

cat /proc/526/oom_score_adj
echo 1000 > /proc/526/oom_score_adj

robson75 · 2021-12-29 15:31:32

cat /proc/526/oom_score_adj
200

seth · 2021-12-29 15:33:39

So it's above 0, can you raise it? ("echo 1000 > /proc/526/oom_score_adj")

robson75 · 2021-12-29 15:57:39

seth wrote:

So it's above 0, can you raise it? ("echo 1000 > /proc/526/oom_score_adj")

Yes, the command is correctly executed on a normal user.

seth · 2021-12-29 16:05:48

Ok, what happens is that an elevated process (likely some root process) raises (for whatever reason) the score to 200 and then afterwards a regular process (run by your own user) tries to set it (for whatever reason) below the value set by the elevated process.
This is denied and yells the error.

There's no harm or danger here, just a lot of clumsyness.
I don't udnerstand why systemd feels like changing the value, let alone twice - but I can see why it's stumbling over its own feet in the effort.

seth · 2021-12-29 22:18:40

https://github.com/systemd/systemd/comm … 4cb9a3591e
Check /usr/lib/systemd/system/user@.service and remove that line.
Reboot.
Message gone?
What's the oom_score_adj now? Still 200?

robson75 · 2021-12-29 23:33:42

You are great @seth, indeed removing the line OOMScoreAdjust=100
solved the problem. Thank you so much.

seth · 2021-12-30 08:43:39

It'll return w/ the next update if we don't really fix it.
Before I head over and shit on that systemd dude for being cavalier about a report that a UID can unexpectedly not control an owned process, we need to figure where the 200 comes from.

for PID in $(pidof dbus-daemon); do printf "$PID : "; cat /proc/$PID/oom_score_adj; done
pacman -Qs dbus
loginctl session-status

robson75 · 2021-12-30 12:22:38

seth wrote:

It'll return w/ the next update

No matter what, the important thing is that you found the source causing the error.

seth · 2021-12-30 13:29:38

What helps the three people reading this thread… please check the commands in #21 so that we can identify the source of the collision and I get to talk some sense into Mr. "if i mark it invalid, it's not a bug"…

robson75 · 2021-12-30 13:46:01

seth wrote:

pacman -Qs dbus
loginctl session-status

local/dbus 1.12.20-1
    Freedesktop.org message bus system
local/dbus-broker 29-1
    Linux D-Bus Message Broker
local/dbus-c++ 0.9.0-9
    A C++ API for D-BUS
local/dbus-glib 0.112-2
    GLib bindings for DBUS
local/dbus-python 1.2.18-3
    Python bindings for DBUS
local/jack2-dbus 1.9.19-2
    The JACK low-latency audio server (dbus integration)
local/kdbusaddons 5.89.0-1 (kf5)
    Addons to QtDBus
local/libdbusmenu-glib 16.04.0-4
    Library for passing menus over DBus
local/libdbusmenu-gtk3 16.04.0-4
    Library for passing menus over DBus (GTK+ 3 library)
local/libdbusmenu-qt5 0.9.3+16.04.20160218-6
    A library that provides a Qt implementation of the DBusMenu spec
local/perl-net-dbus 1.2.0-3
    Binding for DBus messaging protocol
local/xdg-dbus-proxy 0.1.2-3
    Filtering proxy for D-Bus connections

1 - robson (1000)
	   Since: Thu 2021-12-30 14:29:24 CET; 12min ago
	  Leader: 384 (lightdm)
	    Seat: seat0; vc7
	 Display: :0
	 Service: lightdm-autologin; type x11; class user
	 Desktop: xfce
	   State: active
	    Unit: session-1.scope
		  ├─ 384 lightdm --session-child 12 15
		  ├─ 411 /usr/bin/gnome-keyring-daemon --daemonize --login
		  ├─ 421 xfce4-session
		  ├─ 535 xfsettingsd
		  ├─ 540 xfce4-panel
		  ├─ 544 Thunar --daemon
		  ├─ 552 xfdesktop
		  ├─ 555 /usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/panel/plugins/libwhiskermenu.so 1 12582919 whiskermenu "Menu Whisker" "Wyświetla aktywatory zainstalowanych programów rozmieszczone w menu"
		  ├─ 559 /usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/panel/plugins/libxfce4-sensors-plugin.so 5 12582932 xfce4-sensors-plugin "Wtyczka czujników" "Wyświetla wskazania czujników sprzętowych"
		  ├─ 560 /usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/panel/plugins/libsystray.so 2 12582933 systray "Wtyczka zasobnika stanu" "Zapewnia elementy powiadamiające o stanie (wskaźniki aplikacji) i starsze elementy zasobnika systemowego"
		  ├─ 585 pa-applet
		  ├─ 587 python3 /usr/bin/redshift-gtk
		  ├─ 602 compiz --replace ccp
		  ├─ 603 conky -c /home/robson/.conky/conkyrc_info
		  ├─ 604 conky -c /home/robson/.conky/mail_info
		  ├─ 605 emerald --replace
		  ├─ 607 /usr/lib/polkit-gnome/polkit-gnome-authentication-agent-1
		  ├─ 613 nm-applet
		  ├─ 618 xfce4-power-manager
		  ├─ 626 /usr/lib/xfce4/notifyd/xfce4-notifyd
		  ├─ 629 clipit
		  ├─ 645 /usr/lib/geoclue-2.0/demos/agent
		  ├─ 857 /usr/bin/redshift -v
		  ├─5703 xfce4-terminal
		  ├─5720 zsh
		  └─5757 loginctl session-status

seth · 2021-12-30 13:49:29

for PID in $(pidof dbus-daemon); do printf "$PID : "; cat /proc/$PID/oom_score_adj; done

Also (wild guess) what if you kick dbus-broker?

Arch Linux

#1 2021-12-27 13:19:45

[SOLVED] systemd 250 error log

#2 2021-12-27 14:34:54

Re: [SOLVED] systemd 250 error log

#3 2021-12-27 15:16:00

Re: [SOLVED] systemd 250 error log

#4 2021-12-27 15:43:55

Re: [SOLVED] systemd 250 error log

#5 2021-12-27 20:11:34

Re: [SOLVED] systemd 250 error log

#6 2021-12-27 20:13:26

Re: [SOLVED] systemd 250 error log

#7 2021-12-28 11:20:38

Re: [SOLVED] systemd 250 error log

#8 2021-12-28 13:56:44

Re: [SOLVED] systemd 250 error log

#9 2021-12-28 17:32:44

Re: [SOLVED] systemd 250 error log

#10 2021-12-28 22:43:50

Re: [SOLVED] systemd 250 error log

#11 2021-12-29 13:12:54

Re: [SOLVED] systemd 250 error log

#12 2021-12-29 13:15:07

Re: [SOLVED] systemd 250 error log

#13 2021-12-29 13:28:20

Re: [SOLVED] systemd 250 error log

#14 2021-12-29 14:17:25

Re: [SOLVED] systemd 250 error log

#15 2021-12-29 15:31:32

Re: [SOLVED] systemd 250 error log

#16 2021-12-29 15:33:39

Re: [SOLVED] systemd 250 error log

#17 2021-12-29 15:57:39

Re: [SOLVED] systemd 250 error log

#18 2021-12-29 16:05:48

Re: [SOLVED] systemd 250 error log

#19 2021-12-29 22:18:40

Re: [SOLVED] systemd 250 error log

#20 2021-12-29 23:33:42

Re: [SOLVED] systemd 250 error log

#21 2021-12-30 08:43:39

Re: [SOLVED] systemd 250 error log

#22 2021-12-30 12:22:38

Re: [SOLVED] systemd 250 error log

#23 2021-12-30 13:29:38

Re: [SOLVED] systemd 250 error log

#24 2021-12-30 13:46:01

Re: [SOLVED] systemd 250 error log

#25 2021-12-30 13:49:29

Re: [SOLVED] systemd 250 error log

Board footer