systemd kills gnome-shell or gnome-terminal if gnome-terminal uses much memory (50% over 20s)

[jeremyszu]

[Steps to reproduce]
0. Install Jammy image
1. open gnome terminal
2. issue stress_ng or Canonical certification tool checkbox as
"checkbox-cli run com.canonical.certification::memory/memory_stress_ng"
or
"stress-ng --stack 0 --timeout 300"
3. Terminal or Gnome-shell will be killed by systemd-oomd

It's because all stressors are under same cgroup belongs to terminal.

Both Wayland and Xorg can reproduce.

over ssh and in multi-user.target work good.

[Andy Chi (andch)]

I use xps 9310 with 22.04 but I change my windows server back to X.org and I passed the memory stress test.

[jeremyszu (os369510)]

I did read some threads / bugs.
From what I can see so far, it doesn't relate to swap because stressors will fill all memory / swap.

Although it's a stress test, I though if user has many tabs on browser will eventually meet this issue.

From what systemd-oomd current design, it will kill the process if memory pressure over 50% (or 60 or configured percentage) over 20 seconds (or configured settings).

Thus, the current behavior is by design.
However, it leads bad experience.

Since most of user processes will be counted into gnome, then gnome will frequently be killed if user launches heavy application.

I'm think about if expect a process can not use 5.60% memory is a correct expectation.

There are many reports from upstream or other distributions to complaint about it. or enhance it to have a notification before killing.

We could check why it won't happen in Xorg first.

[jeremyszu (os369510)]

okay, I can reproduce this issue in Xorg as well.

`stress-ng --stack 0 --timeout 300` and I can see

Tue Aug 16 03:13:49 PM CST 2022

./memory.pressure
some avg10=64.25 avg60=28.75 avg300=7.33 total=23575913
full avg10=62.74 avg60=28.13 avg300=7.17 total=23107632

./vte-spawn-9dbf6c12-a335-464f-b337-c3b5b6d1ac30.scope/memory.pressure
some avg10=63.79 avg60=29.06 avg300=7.44 total=23418603
full avg10=62.34 avg60=28.46 avg300=7.29 total=22962690

./gnome-terminal-server.service/memory.pressure
some avg10=3.99 avg60=1.22 avg300=0.28 total=1098016
full avg10=3.99 avg60=1.22 avg300=0.28 total=1098016

already over 50% as
Aug 16 15:13:49 ubuntu systemd-oomd[795]: Killed /user.slice/user-1001.slice/[e-mail]/app.slice/app-org.gnome.Terminal.slice/vte-spawn-9dbf6c12-a335-464f-b337-c3b5b6d1ac30.scope due to memory pressure for /user.slice/user-1001.slice/[e-mail] being 70.58% > 50.00% for > 20s with reclaim activity

[jeremyszu (os369510)]

systemd-oomd doesn't care about the slices other than user slice, it's why the sshd won't be killed but it also use a lot of memory:

/sys/fs/cgroup/user.slice/user-1001.slice/session-4.scope/memory.pressure
some avg10=69.94 avg60=69.56 avg300=43.64 total=202010660
full avg10=69.07 avg60=68.73 avg300=43.07 total=199371697
Tue Aug 16 03:32:11 PM CST 2022

Dry Run: no
Swap Used Limit: 90.00%
Default Memory Pressure Limit: 60.00%
Default Memory Pressure Duration: 20s
System Context:
        Memory: Used: 3.5G Total: 3.5G
        Swap: Used: 1.9G Total: 1.9G
Swap Monitored CGroups:
Memory Pressure Monitored CGroups:
        Path: /user.slice/user-1001.slice/[e-mail]
                Memory Pressure Limit: 50.00%
                Pressure: Avg10: 25.40 Avg60: 24.64 Avg300: 12.24 Total: 1min 15s
                Current Memory Usage: 74.5M
                Memory Min: 0B
                Memory Low: 0B
                Pgscan: 24554223
                Last Pgscan: 24533954

---

only [e-mail] in monitoring score.

[Nick Rosbrook (enr0n)]

It seems that systemd-oomd is doing what it is supposed to do -- you're running a memory stress test that is exceeding the memory pressure limits set by systemd-oomd, so it is killing the offending cgroup(s). If you want to run the stress tests in a separate cgroup, try making a script called e.g. `stress.sh`, and execute the script with systemd-run:

$ systemd-run --user ./stress.sh

Further, you can always make changes to Ubuntu's default systemd-oomd configuration[1] if it better suits your stress testing environment.

There are some complaints about the current state of "swap kill" in systemd-oomd, but that has been discussed in [2] and [3].

[1] https://www.freedesktop.org/software/systemd/man/systemd.resource-control.html#ManagedOOMSwap=auto%7Ckill
[2] https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1972159
[3] https://lists.ubuntu.com/archives/ubuntu-devel/2022-June/042116.html

[jeremyszu (os369510)]

yes, it same as what I understand.
systemd-run and over ssh could have a session out of monitored by systemd-oomd.

I'm trying to understand if any use case will similar to stressors?
something like launching a lot of tabs from chrome/firefox browsers, I suppose all tabs will belong to same cgroup to see if memory will > 50% over 20 seconds.

[jeremyszu (os369510)]

alright, although the children are belong to same cgroup but
> as a measurement of the CPU time lost due to lack of memory.

it seems to me there is no a normal case from users will hit it unless memory stressors.

Will have an internal discussion with CE team.

[jeremyszu (os369510)]

Closed it first because I can not find any normal use case as what stress-ng did.
Feel free to reopen and investigating if any normal use case got "being ...% > 50.00% for > 20s with reclaim activity".

[Daniel Johnson (djohnson-progman)]

I have a 'normal use case' that triggers this: Copying a large file. My system has 32GB of RAM and 4GB of swap. Trying to copy a 29,613MB file from a reasonably fast SD card to my local (cacheless) NVMe SSD is triggering systemd-oomd.

[jeremyszu (os369510)]

Hi Daniel,

could you please share the log (e.g. apport, sosreport or journalctl when issue happens)?

[Daniel Johnson (djohnson-progman)]

Embarrassingly it seems that this week I'm getting more proper behavior. I will keep trying to replicate here as time permits, but the system applied some updates automatically and I also installed a few things since the first incident (sane, wireshark, etc). Rolling everything back isn't much of an option for me right now.

[Daniel Johnson (djohnson-progman)]

I've had two more instances, one on the 18th and one (multiple, actually) today. Both were triggered by copying a file as I'd described (from CLI, "ionice -c3 nice cp -a SRC DST"). Today's OOM events also killed a Firefox window for some reason. I captured an sosreport on both days, but last week's event showed I'd neglected to activate sysstat/sar. I am only uploading today's sosreport, but if the older one may be useful I can add it as well.

All of the recent OOMs had this reason, with a varying initial percentage:
"due to memory pressure for /user.slice/user-1000.slice/[e-mail] being 99.00% > 50.00% for > 20s with reclaim activity"

[jeremyszu (os369510)]

It's interesting.
I would like to reproduce your scenario on my side.

Would you please share:
1. "ionice -c3 nice cp -a SRC DST" is mandatory? Does it reproducible through a normal "cp -a"?
2. What's the fail rate?
3. Would you please share the data type from "SRC"? a single large 29,613MB file? or a lot of small files? or 300MB * 100 files?

[Daniel Johnson (djohnson-progman)]

1. "ionice -c3 nice cp -a SRC DST" is mandatory? Does it reproducible through a normal "cp -a"?
A: Unknown. I've been using that out of habit for years to retain as much responsiveness as possible. For future copies I'll use just 'cp -a'.

2. What's the fail rate?
A: Over the last two weeks I had four such files to copy and two failed on their first attempt. So I'd say 2/6 total failure rate.

3. Would you please share the data type from "SRC"? a single large 29,613MB file? or a lot of small files? or 300MB * 100 files?
A: Sorry, I should have said that earlier. It's a single MP4 file, the size for the past three months has averaged 27,283MB (20 to 36GB). The two associated with the most recent OOMs were 30,710MB (stopped around 10.7 GB transferred) and 29,458MB.

The additional load of extraneous processes varies (Firefox, LibreOffice, Chrome, Thunderbird, etc). My own failed attempts to reproduce this on-demand were initially done with no other programs running.

[Daniel Johnson (djohnson-progman)]

Yesterday's copies did not trigger systemd-oomd, but one of them did cause systemd-journald to timeout and restart.

Oct 16 14:00:07 Boromir systemd[1]: systemd-journald.service: Watchdog timeout (limit 3min)!
Oct 16 14:00:07 Boromir systemd[1]: systemd-journald.service: Killing process 578 (systemd-journal) with signal SIGABRT.

[jeremyszu (os369510)]

Hi Daniel,

Finally, I tried to reproduce your scenario on my side but not able to reproduce.

* Environment:
ubuntu 22.04
64G RAM (allocated a process to occupy 32G RAN)
NVMe storage
32G micron SD card (dd /dev/random to a 29G file)

* A script to reproduce:
#!/bin/bash

count=0
file="29G-file"
while [ 1 ]; do
    count=$((count+1))
    echo "--the $count times"
    rm ${HOME}/${file}
    sync
    echo 3 | sudo tee /proc/sys/vm/drop_caches
    ionice -c3 nice cp -a /mnt/mmc/${file} ${HOME}/${file}
    sync
done

The result is it was pass 25 times of copying file.
I was monitor the system resource that in my case, the swapping was not trigger and the copy action didn't consume too many memory.

Could you please help to monitor the memory usage when you try to copy file?

[Daniel Johnson (djohnson-progman)]

Starting today I will be running the copy next to an htop window ready to capture screenshots (before, during, and after failure). The first run today did not fail. I used a variation of your script to copy the source file multiple times to different file names, in the hope that taking my main storage to nearly-full might have an impact but it still did not fail.

There will be another copy tonight / tomorrow. I will keep you updated. Thank you for your aid in trying to reproduce this on your system, too!

[Daniel Johnson (djohnson-progman)]

The morning copy ran without incident but the evening copy triggered a fault between 1944 and 1952 CST (UTC-5). I'm attaching a TAR which contains three screenshots (before, during, and just after the fault) as well as the time-relevant output of 'journalctl', and an sosreport. The sosreport contains 'sar' data which can be nicely graphed by 'ksar' (https://github.com/vlsi/ksar) if you, like me, would rather see a graph of the values instead of reading them line-by-line.

The relevant systemd-oomd text today was this:
=-=-=-=-=-
Nov 13 19:44:41 Boromir systemd-oomd[1084]: Killed /user.slice/user-1000.slice/[e-mail]/app.slice/app-org.gnome.Terminal.slice/vte-spawn-d21ca39b-f66d-4b6c-aa6b-e087b2171268.scope due to memory pressure for /user.slice/user-1000.slice/[e-mail] being 59.43% > 50.00% for > 20s with reclaim activity
Nov 13 19:44:41 Boromir systemd[2457]: vte-spawn-d21ca39b-f66d-4b6c-aa6b-e087b2171268.scope: systemd-oomd killed 2 process(es) in this unit.
Nov 13 19:44:57 Boromir systemd-oomd[1084]: Killed /user.slice/user-1000.slice/[e-mail]/app.slice/app-org.gnome.Terminal.slice/vte-spawn-552a2d8e-2b19-483b-824a-dd4a5138012b.scope due to memory pressure for /user.slice/user-1000.slice/[e-mail] being 60.58% > 50.00% for > 20s with reclaim activity
Nov 13 19:51:55 Boromir systemd-oomd[1084]: Killed /user.slice/user-1000.slice/[e-mail]/app.slice/app-org.gnome.Terminal.slice/vte-spawn-48215c41-bdeb-4430-a3f1-eae7f6af30d3.scope due to memory pressure for /user.slice/user-1000.slice/[e-mail] being 67.81% > 50.00% for > 20s with reclaim activity
=-=-=-=-=-

The immediately obvious symptom before oomd kicked in was the load average climbing and the system responsiveness falling. I tried taking two other screenshots during that time (load avg 30-40) but the clipboard didn't update or Gimp hung.

[Launchpad Janitor (janitor)]

[Expired for systemd (Ubuntu) because there has been no activity for 60 days.]