Re: pids.current with invalid value for hours [5.0.0 rc3 git]

From: Tetsuo Handa
Date: Sat Jan 26 2019 - 02:55:25 EST

Next message: Nathan Chancellor: "Re: [PATCH v2] drm/i915: Disable -Wuninitialized"
Previous message: Jonas Bonn: "Re: [PATCH 1/2] spi: support inter-word delay requirement for devices"
In reply to: Tetsuo Handa: "Re: pids.current with invalid value for hours [5.0.0 rc3 git]"
Next in thread: Tetsuo Handa: "Re: pids.current with invalid value for hours [5.0.0 rc3 git]"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On 2019/01/26 15:10, Tetsuo Handa wrote:
> On 2019/01/26 11:41, Arkadiusz MiÅkiewicz wrote:
>> dmesg:
>> http://ixion.pld-linux.org/~arekm/cgroup-oom-2.txt

OK. There is a refcount leak bug in wake_oom_reaper()
which became visible by enabling oom_group setting.

static void wake_oom_reaper(struct task_struct *tsk)
{
/* tsk is already queued? */
if (tsk == oom_reaper_list || tsk->oom_reaper_list)
return;

get_task_struct(tsk);

spin_lock(&oom_reaper_lock);
tsk->oom_reaper_list = oom_reaper_list;
oom_reaper_list = tsk;
spin_unlock(&oom_reaper_lock);
trace_wake_reaper(tsk->pid);
wake_up(&oom_reaper_wait);
}

(1) oom_reaper_list and tsk(*)->oom_reaper_list are initially NULL.
(2) Since tsk(2160) != oom_reaper_list && tsk(2160)->oom_reaper_list == NULL,
get_task_struct(tsk(2160)) is called.
(3) tsk(2160)->oom_reaper_list = oom_reaper_list (which is NULL).
(4) oom_reaper_list = tsk(2160) (which is not NULL).
(5) Since tsk(2150) != oom_reaper_list (which is tsk(2160)) && tsk(2150)->oom_reaper_list == NULL,
get_task_struct(tsk(2150)) is called.
(6) Step (5) repeats on tsk(2153, 2164. 2166, 2163, 2159, 2161, 2154).
(7) Since tsk(2160) != oom_reaper_list (which is tsk(2154)) && tsk(2160)->oom_reaper_list == NULL
(because it was NULL as of (2)), get_task_struct(tsk(2160)) is called again.
(8) oom_reap_task() calls put_task_struct(tsk(2160)) for only once because
tsk(2160) appears on the oom_reaper_list for only once; leaking refcount.

Jan 26 03:33:49 xps kernel: Memory cgroup out of memory: Kill process 2160 (python3) score 66 or sacrifice child
Jan 26 03:33:49 xps kernel: Killed process 2160 (python3) total-vm:272176kB, anon-rss:31668kB, file-rss:3248kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Tasks in /test_2149 are going to be killed due to memory.oom.group set
Jan 26 03:33:49 xps kernel: Killed process 2150 (python3) total-vm:272176kB, anon-rss:27572kB, file-rss:3248kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2153 (python3) total-vm:261936kB, anon-rss:17396kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2164 (python3) total-vm:272176kB, anon-rss:27572kB, file-rss:3248kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2166 (python3) total-vm:261936kB, anon-rss:15088kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2163 (python3) total-vm:261936kB, anon-rss:21496kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2159 (python3) total-vm:282420kB, anon-rss:23944kB, file-rss:3128kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2161 (python3) total-vm:251692kB, anon-rss:11172kB, file-rss:3060kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2154 (python3) total-vm:261936kB, anon-rss:15084kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2160 (python3) total-vm:272176kB, anon-rss:31668kB, file-rss:3248kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2155 (python3) total-vm:261936kB, anon-rss:17364kB, file-rss:3056kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2168 (python3) total-vm:272176kB, anon-rss:29620kB, file-rss:3108kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2156 (python3) total-vm:251692kB, anon-rss:11204kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2157 (python3) total-vm:251692kB, anon-rss:11172kB, file-rss:3088kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2169 (python3) total-vm:261936kB, anon-rss:19448kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2158 (python3) total-vm:272176kB, anon-rss:23944kB, file-rss:3192kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2170 (python3) total-vm:251692kB, anon-rss:13252kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2171 (python3) total-vm:261936kB, anon-rss:17396kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2173 (python3) total-vm:251692kB, anon-rss:11204kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2152 (python3) total-vm:261936kB, anon-rss:13724kB, file-rss:3100kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2174 (python3) total-vm:251692kB, anon-rss:11160kB, file-rss:3120kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2172 (python3) total-vm:251692kB, anon-rss:9128kB, file-rss:3116kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2187 (python3) total-vm:261936kB, anon-rss:23516kB, file-rss:3116kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2184 (python3) total-vm:251692kB, anon-rss:13500kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2151 (python3) total-vm:251692kB, anon-rss:9108kB, file-rss:3096kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2182 (python3) total-vm:251692kB, anon-rss:12196kB, file-rss:3140kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2175 (python3) total-vm:261936kB, anon-rss:13996kB, file-rss:3124kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2183 (python3) total-vm:251692kB, anon-rss:9124kB, file-rss:3112kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2177 (python3) total-vm:251692kB, anon-rss:9148kB, file-rss:3140kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2186 (python3) total-vm:261936kB, anon-rss:15336kB, file-rss:3152kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2189 (python3) total-vm:251692kB, anon-rss:9156kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2178 (python3) total-vm:251692kB, anon-rss:11204kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2185 (python3) total-vm:261936kB, anon-rss:15084kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2190 (python3) total-vm:251692kB, anon-rss:11204kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2179 (python3) total-vm:251692kB, anon-rss:9156kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2180 (python3) total-vm:251692kB, anon-rss:5060kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2181 (python3) total-vm:261936kB, anon-rss:21492kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2176 (python3) total-vm:261936kB, anon-rss:15348kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2188 (python3) total-vm:251692kB, anon-rss:7108kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2191 (python3) total-vm:261936kB, anon-rss:14556kB, file-rss:3188kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: Killed process 2192 (python3) total-vm:241448kB, anon-rss:3456kB, file-rss:2712kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2163 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2192 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2191 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2188 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2176 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2181 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2180 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2179 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2190 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2185 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2178 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2189 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2186 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2177 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2175 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2182 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2151 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2184 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2187 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2172 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2174 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2173 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2171 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2158 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2169 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2157 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2156 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2168 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2155 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2160 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2154 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:49 xps kernel: oom_reaper: reaped process 2161 (python3), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Jan 26 03:33:50 xps kernel: python3 invoked oom-killer: gfp_mask=0x6000c0(GFP_KERNEL), order=0, oom_score_adj=0
Jan 26 03:33:50 xps kernel: CPU: 1 PID: 2217 Comm: python3 Tainted: G E T 5.0.0-rc3-00104-gc04e2a780caf-dirty #289

Since we assumed that wake_oom_reaper() is called for only once
for one out_of_memory() request,

/* tsk is already queued? */
if (tsk == oom_reaper_list || tsk->oom_reaper_list)
return;

no longer works.

Next message: Nathan Chancellor: "Re: [PATCH v2] drm/i915: Disable -Wuninitialized"
Previous message: Jonas Bonn: "Re: [PATCH 1/2] spi: support inter-word delay requirement for devices"
In reply to: Tetsuo Handa: "Re: pids.current with invalid value for hours [5.0.0 rc3 git]"
Next in thread: Tetsuo Handa: "Re: pids.current with invalid value for hours [5.0.0 rc3 git]"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]