linux-kernel - Re: [PATCH v4 12/12] sched,signal,ptrace: Rework TASK_TRACED, TASK

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <yt9d5ykbekn3.fsf@linux.ibm.com>
Date:   Tue, 05 Jul 2022 15:47:44 +0200
From:   Sven Schnelle <svens@...ux.ibm.com>
To:     Steven Rostedt <rostedt@...dmis.org>
Cc:     Alexander Gordeev <agordeev@...ux.ibm.com>,
        "Eric W. Biederman" <ebiederm@...ssion.com>,
        linux-kernel@...r.kernel.org, rjw@...ysocki.net,
        Oleg Nesterov <oleg@...hat.com>, mingo@...nel.org,
        vincent.guittot@...aro.org, dietmar.eggemann@....com,
        mgorman@...e.de, bigeasy@...utronix.de,
        Will Deacon <will@...nel.org>, tj@...nel.org,
        linux-pm@...r.kernel.org, Peter Zijlstra <peterz@...radead.org>,
        Richard Weinberger <richard@....at>,
        Anton Ivanov <anton.ivanov@...bridgegreys.com>,
        Johannes Berg <johannes@...solutions.net>,
        linux-um@...ts.infradead.org, Chris Zankel <chris@...kel.net>,
        Max Filippov <jcmvbkbc@...il.com>,
        linux-xtensa@...ux-xtensa.org, Kees Cook <keescook@...omium.org>,
        Jann Horn <jannh@...gle.com>, linux-ia64@...r.kernel.org
Subject: Re: [PATCH v4 12/12] sched,signal,ptrace: Rework TASK_TRACED,
 TASK_STOPPED state

Hi,

Steven Rostedt <rostedt@...dmis.org> writes:

> On Tue, 21 Jun 2022 17:15:47 +0200
> Alexander Gordeev <agordeev@...ux.ibm.com> wrote:
>
>> So I assume (checked actually) the return 0 below from kernel/sched/core.c:
>> wait_task_inactive() is where it bails out:
>> 
>> 3303                 while (task_running(rq, p)) {
>> 3304                         if (match_state && unlikely(READ_ONCE(p->__state) != match_state))
>> 3305                                 return 0;
>> 3306                         cpu_relax();
>> 3307                 }
>> 
>> Yet, the child task is always found in __TASK_TRACED state (as seen
>> in crash dumps):
>> 
>> > 101447  11342  13      ce3a8100      RU   0.0   10040   4412  strace  
>>   101450  101447   0      bb04b200      TR   0.0    2272   1136  kill_child
>>   108261  101447   2      d0b10100      TR   0.0    2272    532  kill_child
>> crash> task bb04b200 __state  
>> PID: 101450  TASK: bb04b200          CPU: 0   COMMAND: "kill_child"
>>   __state = 8,
>> 
>> crash> task d0b10100 __state  
>> PID: 108261  TASK: d0b10100          CPU: 2   COMMAND: "kill_child"
>>   __state = 8,
>
> If you are using crash, can you enable all trace events?
>
> Then you should be able to extract the ftrace ring buffer from crash using
> the trace.so extend (https://github.com/fujitsu/crash-trace)
>
> I guess it should still work with s390.
>
> Then you can see the events that lead up to the crash.

Alexander is busy with other stuff, so I took over. I enabled the
sys,signal,sched and task tracepoints and ftrace_dump_on_oops. The last
lines from the trace buffer are:

[  281.043459]   strace-1177215   0d.... 269457070us : sched_waking: comm=kill_child pid=1178157 prio=120 target_cpu=003
[  281.043463] kill_chi-1177218   1d.... 269457070us : signal_generate: sig=17 errno=0 code=4 comm=strace pid=1177215 grp=1 res=1
[  281.043467] kill_chi-1177218   1d.... 269457070us : sched_stat_runtime: comm=kill_child pid=1177218 runtime=5299 [ns] vruntime=1830714210855 [ns]
[  281.043471] kill_chi-1177218   1d.... 269457071us : sched_switch: prev_comm=kill_child prev_pid=1177218 prev_prio=120 prev_state=t ==> next_comm=swapper/1 next_pid=0 next_prio=120
[  281.043475]   strace-1177215   0..... 269457071us : sys_ptrace -> 0x50
[  281.043478]   strace-1177215   0..... 269457071us : sys_write(fd: 2, buf: 2aa15db3ad0, count: 12)
[  281.043482]   strace-1177215   0..... 269457072us : sys_write -> 0x12
[  281.043485]   <idle>-0         3dNh.. 269457072us : sched_wakeup: comm=kill_child pid=1178157 prio=120 target_cpu=003
[  281.043489]   <idle>-0         3d.... 269457073us : sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kill_child next_pid=1178157 next_prio=120
[  281.043493]   strace-1177215   0..... 269457073us : sys_write(fd: 2, buf: 2aa15db3ad0, count: 1a)
[  281.043496]   strace-1177215   0..... 269457073us : sys_write -> 0x1a
[  281.043500] kill_chi-1178157   3..... 269457073us : sys_sched_yield -> 0xffffffffffffffda
[  281.043504]   strace-1177215   0..... 269457073us : sys_ptrace(request: 18, pid: 11fa2d, addr: 0, data: 0)
[  281.043508] kill_chi-1178157   3d.... 269457073us : signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
[  281.043511] kill_chi-1178157   3d.... 269457074us : signal_generate: sig=17 errno=0 code=4 comm=strace pid=1177215 grp=1 res=1
[  281.043515] kill_chi-1178157   3d.... 269457074us : sched_stat_runtime: comm=kill_child pid=1178157 runtime=2408 [ns] vruntime=1983050055579 [ns]
[  281.043519] kill_chi-1178157   3d.... 269457075us : sched_switch: prev_comm=kill_child prev_pid=1178157 prev_prio=120 prev_state=t ==> next_comm=swapper/3 next_pid=0 next_prio=120

I attached the full output to this mail. I haven't yet tried to
understand the problem, i just wanted to send you the requested
information in the hope that it will help you.

Regards
Sven


Download attachment "dmesg.xz" of type "application/x-xz" (29004 bytes)