Re: [PATCH] coredump: Limit what can interrupt coredumps

[Jens Axboe <axboe@kernel.dk>]

On 8/17/21 12:15 PM, Jens Axboe wrote:
> On 8/15/21 2:42 PM, Olivier Langlois wrote:
>> On Wed, 2021-08-11 at 19:55 -0600, Jens Axboe wrote:
>>> On 8/10/21 3:48 PM, Tony Battersby wrote:
>>>> On 8/5/21 9:06 AM, Olivier Langlois wrote:
>>>>>
>>>>> Hi all,
>>>>>
>>>>> I didn't forgot about this remaining issue and I have kept thinking
>>>>> about it on and off.
>>>>>
>>>>> I did try the following on 5.12.19:
>>>>>
>>>>> diff --git a/fs/coredump.c b/fs/coredump.c
>>>>> index 07afb5ddb1c4..614fe7a54c1a 100644
>>>>> --- a/fs/coredump.c
>>>>> +++ b/fs/coredump.c
>>>>> @@ -41,6 +41,7 @@
>>>>>  #include <linux/fs.h>
>>>>>  #include <linux/path.h>
>>>>>  #include <linux/timekeeping.h>
>>>>> +#include <linux/io_uring.h>
>>>>>  
>>>>>  #include <linux/uaccess.h>
>>>>>  #include <asm/mmu_context.h>
>>>>> @@ -625,6 +626,8 @@ void do_coredump(const kernel_siginfo_t
>>>>> *siginfo)
>>>>>                 need_suid_safe = true;
>>>>>         }
>>>>>  
>>>>> +       io_uring_files_cancel(current->files);
>>>>> +
>>>>>         retval = coredump_wait(siginfo->si_signo, &core_state);
>>>>>         if (retval < 0)
>>>>>                 goto fail_creds;
>>>>> --
>>>>> 2.32.0
>>>>>
>>>>> with my current understanding, io_uring_files_cancel is supposed to
>>>>> cancel everything that might set the TIF_NOTIFY_SIGNAL.
>>>>>
>>>>> I must report that in my testing with generating a core dump
>>>>> through a
>>>>> pipe with the modif above, I still get truncated core dumps.
>>>>>
>>>>> systemd is having a weird error:
>>>>> [ 2577.870742] systemd-coredump[4056]: Failed to get COMM: No such
>>>>> process
>>>>>
>>>>> and nothing is captured
>>>>>
>>>>> so I have replaced it with a very simple shell:
>>>>> $ cat /proc/sys/kernel/core_pattern 
>>>>>> /home/lano1106/bin/pipe_core.sh %e %p
>>>>>
>>>>> ~/bin $ cat pipe_core.sh 
>>>>> #!/bin/sh
>>>>>
>>>>> cat > /home/lano1106/core/core.$1.$2
>>>>>
>>>>> BFD: warning: /home/lano1106/core/core.test.10886 is truncated:
>>>>> expected core file size >= 24129536, found: 61440
>>>>>
>>>>> I conclude from my attempt that maybe io_uring_files_cancel is not
>>>>> 100%
>>>>> cleaning everything that it should clean.
>>>>>
>>>>>
>>>>>
>>>> I just ran into this problem also - coredumps from an io_uring
>>>> program
>>>> to a pipe are truncated.  But I am using kernel 5.10.57, which does
>>>> NOT
>>>> have commit 12db8b690010 ("entry: Add support for TIF_NOTIFY_SIGNAL")
>>>> or
>>>> commit 06af8679449d ("coredump: Limit what can interrupt coredumps").
>>>> Kernel 5.4 works though, so I bisected the problem to commit
>>>> f38c7e3abfba ("io_uring: ensure async buffered read-retry is setup
>>>> properly") in kernel 5.9.  Note that my io_uring program uses only
>>>> async
>>>> buffered reads, which may be why this particular commit makes a
>>>> difference to my program.
>>>>
>>>> My io_uring program is a multi-purpose long-running program with many
>>>> threads.  Most threads don't use io_uring but a few of them do. 
>>>> Normally, my core dumps are piped to a program so that they can be
>>>> compressed before being written to disk, but I can also test writing
>>>> the
>>>> core dumps directly to disk.  This is what I have found:
>>>>
>>>> *) Unpatched 5.10.57: if a thread that doesn't use io_uring triggers
>>>> a
>>>> coredump, the core file is written correctly, whether it is written
>>>> to
>>>> disk or piped to a program, even if another thread is using io_uring
>>>> at
>>>> the same time.
>>>>
>>>> *) Unpatched 5.10.57: if a thread that uses io_uring triggers a
>>>> coredump, the core file is truncated, whether written directly to
>>>> disk
>>>> or piped to a program.
>>>>
>>>> *) 5.10.57+backport 06af8679449d: if a thread that uses io_uring
>>>> triggers a coredump, and the core is written directly to disk, then
>>>> it
>>>> is written correctly.
>>>>
>>>> *) 5.10.57+backport 06af8679449d: if a thread that uses io_uring
>>>> triggers a coredump, and the core is piped to a program, then it is
>>>> truncated.
>>>>
>>>> *) 5.10.57+revert f38c7e3abfba: core dumps are written correctly,
>>>> whether written directly to disk or piped to a program.
>>>
>>> That is very interesting. Like Olivier mentioned, it's not that actual
>>> commit, but rather the change of behavior implemented by it. Before
>>> that
>>> commit, we'd hit the async workers more often, whereas after we do the
>>> correct retry method where it's driven by the wakeup when the page is
>>> unlocked. This is purely speculation, but perhaps the fact that the
>>> process changes state potentially mid dump is why the dump ends up
>>> being
>>> truncated?
>>>
>>> I'd love to dive into this and try and figure it out. Absent a test
>>> case, at least the above gives me an idea of what to try out. I'll see
>>> if it makes it easier for me to create a case that does result in a
>>> truncated core dump.
>>>
>> Jens,
>>
>> When I have first encountered the issue, the very first thing that I
>> did try was to create a simple test program that would synthetize the
>> problem.
>>
>> After few time consumming failed attempts, I just gave up the idea and
>> simply settle to my prod program that showcase systematically the
>> problem every time that I kill the process with a SEGV signal.
>>
>> In a nutshell, all the program does is to issue read operations with
>> io_uring on a TCP socket on which there is a constant data stream.
>>
>> Now that I have a better understanding of what is going on, I think
>> that one way that could reproduce the problem consistently could be
>> along those lines:
>>
>> 1. Create a pipe
>> 2. fork a child
>> 3. Initiate a read operation on the pipe with io_uring from the child
>> 4. Let the parent kill its child with a core dump generating signal.
>> 5. Write something in the pipe from the parent so that the io_uring
>> read operation completes while the core dump is generated.
>>
>> I guess that I'll end up doing that if I cannot fix the issue with my
>> current setup but here is what I have attempted so far:
>>
>> 1. Call io_uring_files_cancel from do_coredump
>> 2. Same as #1 but also make sure that TIF_NOTIFY_SIGNAL is cleared on
>> returning from io_uring_files_cancel
>>
>> Those attempts didn't work but lurking in the io_uring dev mailing list
>> is starting to pay off. I thought that I did reach the bottom of the
>> rabbit hole in my journey of understanding io_uring but the recent
>> patch set sent by Hao Xu
>>
>> https://lore.kernel.org/io-uring/90fce498-968e-6812-7b6a-fdf8520ea8d9@kernel.dk/T/#t
>>
>> made me realize that I still haven't assimilated all the small io_uring
>> nuances...
>>
>> Here is my feedback. From my casual io_uring code reader point of view,
>> it is not 100% obvious what the difference is between
>> io_uring_files_cancel and io_uring_task_cancel
>>
>> It seems like io_uring_files_cancel is cancelling polls only if they
>> have the REQ_F_INFLIGHT flag set.
>>
>> I have no idea what an inflight request means and why someone would
>> want to call io_uring_files_cancel over io_uring_task_cancel.
>>
>> I guess that if I was to meditate on the question for few hours, I
>> would at some point get some illumination strike me but I believe that
>> it could be a good idea to document in the code those concepts for
>> helping casual readers...
>>
>> Bottomline, I now understand that io_uring_files_cancel does not cancel
>> all the requests. Therefore, without fully understanding what I am
>> doing, I am going to replace my call to io_uring_files_cancel from
>> do_coredump with io_uring_task_cancel and see if this finally fix the
>> issue for good.
>>
>> What I am trying to do is to cancel pending io_uring requests to make
>> sure that TIF_NOTIFY_SIGNAL isn't set while core dump is generated.
>>
>> Maybe another solution would simply be to modify __dump_emit to make it
>> resilient to TIF_NOTIFY_SIGNAL as Eric W. Biederman originally
>> suggested.
>>
>> or maybe do both...
>>
>> Not sure which approach is best. If someone has an opinion, I would be
>> curious to hear it.
> 
> It does indeed sound like it's TIF_NOTIFY_SIGNAL that will trigger some
> signal_pending() and cause an interruption of the core dump. Just out of
> curiosity, what is your /proc/sys/kernel/core_pattern set to? If it's
> set to some piped process, can you try and set it to 'core' and see if
> that eliminates the truncation of the core dumps for your case?

And assuming that works, then I suspect this one would fix your issue
even with a piped core dump:

diff --git a/fs/coredump.c b/fs/coredump.c
index 07afb5ddb1c4..852737a9ccbf 100644
--- a/fs/coredump.c
+++ b/fs/coredump.c
@@ -41,6 +41,7 @@
 #include <linux/fs.h>
 #include <linux/path.h>
 #include <linux/timekeeping.h>
+#include <linux/io_uring.h>
 
 #include <linux/uaccess.h>
 #include <asm/mmu_context.h>
@@ -603,6 +604,7 @@ void do_coredump(const kernel_siginfo_t *siginfo)
 	};
 
 	audit_core_dumps(siginfo->si_signo);
+	io_uring_task_cancel();
 
 	binfmt = mm->binfmt;
 	if (!binfmt || !binfmt->core_dump)

-- 
Jens Axboe