Re: [RFC] mm/kasan: Add Allocation, Free, Error timestamps to KASAN report

[Dmitry Vyukov]

On Mon, 30 Oct 2023 at 12:32, Juntong Deng <juntong.deng@xxxxxxxxxxx> wrote:
>
> On 2023/10/30 18:10, Dmitry Vyukov wrote:
> > On Mon, 30 Oct 2023 at 10:28, Juntong Deng <juntong.deng@xxxxxxxxxxx> wrote:
> >>
> >> On 2023/10/30 14:29, Dmitry Vyukov wrote:
> >>> On Sun, 29 Oct 2023 at 10:05, Juntong Deng <juntong.deng@xxxxxxxxxxx> wrote:
> >>>>
> >>>> On 2023/10/26 3:22, Andrey Konovalov wrote:
> >>>>> On Tue, Oct 17, 2023 at 9:40 PM Juntong Deng <juntong.deng@xxxxxxxxxxx> wrote:
> >>>>>>
> >>>>>> The idea came from the bug I was fixing recently,
> >>>>>> 'KASAN: slab-use-after-free Read in tls_encrypt_done'.
> >>>>>>
> >>>>>> This bug is caused by subtle race condition, where the data structure
> >>>>>> is freed early on another CPU, resulting in use-after-free.
> >>>>>>
> >>>>>> Like this bug, some of the use-after-free bugs are caused by race
> >>>>>> condition, but it is not easy to quickly conclude that the cause of the
> >>>>>> use-after-free is race condition if only looking at the stack trace.
> >>>>>>
> >>>>>> I did not think this use-after-free was caused by race condition at the
> >>>>>> beginning, it took me some time to read the source code carefully and
> >>>>>> think about it to determine that it was caused by race condition.
> >>>>>>
> >>>>>> By adding timestamps for Allocation, Free, and Error to the KASAN
> >>>>>> report, it will be much easier to determine if use-after-free is
> >>>>>> caused by race condition.
> >>>>>
> >>>>> An alternative would be to add the CPU number to the alloc/free stack
> >>>>> traces. Something like:
> >>>>>
> >>>>> Allocated by task 42 on CPU 2:
> >>>>> (stack trace)
> >>>>>
> >>>>> The bad access stack trace already prints the CPU number.
> >>>>
> >>>> Yes, that is a great idea and the CPU number would help a lot.
> >>>>
> >>>> But I think the CPU number cannot completely replace the free timestamp,
> >>>> because some freeing really should be done at another CPU.
> >>>>
> >>>> We need the free timestamp to help us distinguish whether it was freed
> >>>> a long time ago or whether it was caused to be freed during the
> >>>> current operation.
> >>>>
> >>>> I think both the CPU number and the timestamp should be displayed, more
> >>>> information would help us find the real cause of the error faster.
> >>>>
> >>>> Should I implement these features?
> >>>
> >>> Hi Juntong,
> >>>
> >>> There is also an aspect of memory consumption. KASAN headers increase
> >>> the size of every heap object. So we tried to keep them as compact as
> >>> possible. At some point CPU numbers and timestamps (IIRC) were already
> >>> part of the header, but we removed them to shrink the header to 16
> >>> bytes.
> >>> PID gives a good approximation of potential races. I usually look at
> >>> PIDs to understand if it's a "plain old single-threaded
> >>> use-after-free", or free and access happened in different threads.
> >>> Re timestamps, I see you referenced a syzbot report. With syzkaller
> >>> most timestamps will be very close even for non-racing case.
> >>> So if this is added, this should be added at least under a separate config.
> >>>
> >>> If you are looking for potential KASAN improvements, here is a good list:
> >>> https://bugzilla.kernel.org/buglist.cgi?bug_status=__open__&component=Sanitizers&list_id=1134168&product=Memory%20Management
> >>
> >> Hi Dmitry,
> >>
> >> I think PID cannot completely replace timestamp for reason similar to
> >> CPU number, some frees really should be done in another thread, but it
> >> is difficult for us to distinguish if it is a free that was done some
> >> time ago, or under subtle race conditions.
> >
> > I agree it's not a complete replacement, it just does not consume
> > additional memory.
> >
> >> As to whether most of the timestamps will be very close even for
> >> non-racing case, this I am not sure, because I do not have
> >> enough samples.
> >>
> >> I agree that these features should be in a separate config and
> >> the user should be free to choose whether to enable them or not.
> >>
> >> We can divide KASAN into normal mode and depth mode. Normal mode
> >> records only minimal critical information, while depth mode records
> >> more potentially useful information.
> >>
> >> Also, honestly, I think a small amount of extra memory consumption
> >> should not stop us from recording more information.
> >>
> >> Because if someone enables KASAN for debugging, then memory consumption
> >> and performance are no longer his main concern.
> >
> > There are a number of debugging tools created with the "performance
> > does not matter" attitude. They tend to be barely usable, not usable
> > in wide scale testing, not usable in canaries, etc.
> > All of sanitizers were created with lots of attention to performance,
> > attention on the level of the most performance critical production
> > code (sanitizer code is hotter than any production piece of code).
> > That's what made them so widely used. Think of interactive uses,
> > smaller devices, etc. Please let's keep this attitude.
>
> Yes, I agree that debugging tools used at a wide scale need to have
> more rigorous performance considerations.
>
> Do you think it is worth using the extra bytes to record more
> information? If this is a user-configurable feature.

If it's user-configurable, then it is OK.