[PATCH v4 12/12] sched,signal,ptrace: Rework TASK_TRACED, TASK_STOPPED state

[Sven Schnelle]

Sven Schnelle <svens at linux.ibm.com> writes:

> Steven Rostedt <rostedt at goodmis.org> writes:
>
>> On Tue, 21 Jun 2022 17:15:47 +0200
>> Alexander Gordeev <agordeev at linux.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.

I think there's a race in ptrace_check_attach(). It first calls
ptrace_freeze_task(), which checks whether JOBCTL_TRACED is set.
If it is (and a few other conditions match) it will set ret = 0.

Later outside of siglock and tasklist_lock it will call
wait_task_inactive, assuming the target is in TASK_TRACED, but it isn't.

ptrace_stop(), which runs on another CPU, does:

set_special_state(TASK_TRACED);
current->jobctl |= JOBCTL_TRACED;

which looks ok on first sight, but in this case JOBCTL is already set,
so the reading CPU will immediately move on to wait_task_inactive(),
before JOBCTL_TRACED is set. I don't know whether this is a valid
combination. I never looked into JOBCTL_* semantics, but i guess now
is a good time to do so. I added some debugging statements, and that
gives:

[   86.218488] kill_chi-300545    2d.... 79990135us : ptrace_stop: state 8
[   86.218492] kill_chi-300545    2d.... 79990136us : signal_generate: sig=17 errno=0 code=4 comm=strace pid=300542 grp=1 res=1
[   86.218496] kill_chi-300545    2d.... 79990136us : sched_stat_runtime: comm=kill_child pid=300545 runtime=3058 [ns] vruntime=606165713178 [ns]
[   86.218500] kill_chi-300545    2d.... 79990136us : sched_switch: prev_comm=kill_child prev_pid=300545 prev_prio=120 prev_state=t ==> next_comm=swapper/2 next_pid=0 next_prio=120
[   86.218504]   strace-300542    7..... 79990139us : sys_ptrace -> 0x50
[   86.218508]   strace-300542    7..... 79990139us : sys_write(fd: 2, buf: 2aa198f7ad0, count: 12)
[   86.218512]   strace-300542    7..... 79990140us : sys_write -> 0x12
[   86.218515]   <idle>-0         6dNh.. 79990140us : sched_wakeup: comm=kill_child pid=343805 prio=120 target_cpu=006
[   86.218519]   <idle>-0         6d.... 79990140us : sched_switch: prev_comm=swapper/6 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=kill_child next_pid=343805 next_prio=120
[   86.218524]   strace-300542    7..... 79990140us : sys_write(fd: 2, buf: 2aa198f7ad0, count: 19)
[   86.218527]   strace-300542    7..... 79990141us : sys_write -> 0x19
[   86.218531] kill_chi-343805    6..... 79990141us : sys_sched_yield -> 0xffffffffffffffda
[   86.218535]   strace-300542    7..... 79990141us : sys_ptrace(request: 18, pid: 53efd, addr: 0, data: 0)
[   86.218539] kill_chi-343805    6d.... 79990141us : signal_deliver: sig=9 errno=0 code=0 sa_handler=0 sa_flags=0
[   86.218543]   strace-300542    7d.... 79990141us : ptrace_check_attach: task_is_traced: 1, fatal signal pending: 0
[   86.218547]   strace-300542    7..... 79990141us : ptrace_check_attach: child->pid = 343805, child->__flags=0
[   86.218551] kill_chi-343805    6d.... 79990141us : ptrace_stop: JOBCTL_TRACED already set, state=0 <------ valid combination of flags?
[   86.218554] kill_chi-343805    6d.... 79990141us : ptrace_stop: state 8
[   86.218558] kill_chi-343805    6d.... 79990142us : signal_generate: sig=17 errno=0 code=4 comm=strace pid=300542 grp=1 res=1
[   86.218562] kill_chi-343805    6d.... 79990142us : sched_stat_runtime: comm=kill_child pid=343805 runtime=2135 [ns] vruntime=556109013931 [ns]
[   86.218566]   strace-300542    7..... 79990142us : wait_task_inactive: NO MATCH: state 0, match_state 8, pid 343805
[   86.218570] kill_chi-343805    6d.... 79990142us : sched_switch: prev_comm=kill_child prev_pid=343805 prev_prio=120 prev_state=t ==>next_comm=swapper/6 next_pid=0 next_prio=120

-------------- next part --------------
A non-text attachment was scrubbed...
Name: ptrace-debug.patch
Type: text/x-diff
Size: 2758 bytes
Desc: not available
URL: <http://lists.infradead.org/pipermail/linux-um/attachments/20220705/4754c7e4/attachment.bin>
-------------- next part --------------

I'll continue debugging tomorrow, but maybe this helps already.