Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Sun, 7 Mar 2021 12:01:42 +0800 Peter Chen wrote: > On 21-03-02 09:56:05, Steven Rostedt wrote: > > On Tue, 2 Mar 2021 16:23:55 +0800 > > Peter Chen wrote: > > > > s it looks like it uses %pa which IIUC from the printk code, it > > > > >> dereferences the pointer to find it's virtual address. The event has > > > > >> this as the field: > > > > >> > > > > >> __field(struct cdns3_trb *, start_trb_addr) > > > > >> > > > > >> Assigns it with: > > > > >> > > > > >> __entry->start_trb_addr = req->trb; > > > > >> > > > > >> And prints that with %pa, which will dereference pointer at the time > > > > >> of > > > > >> reading, where the address in question may no longer be around. That > > > > >> looks to me as a potential bug. > > > > > > Steven, thanks for reporting. Do you mind sending patch to fix it? > > > If you have no time to do it, I will do it later. > > > > > > > I would have already fixed it, but I wasn't exactly sure how this is used. > > > > In Documentation/core-api/printk-formats.rst we have: > > > >Physical address types phys_addr_t > >-- > > > >:: > > > >%pa[p] 0x01234567 or 0x0123456789abcdef > > > >For printing a phys_addr_t type (and its derivatives, such as > >resource_size_t) which can vary based on build options, regardless of the > >width of the CPU data path. > > > > So it only looks like it is used to for the size of the pointer. > > > > I guess something like this might work: > > > > diff --git a/drivers/usb/cdns3/cdns3-trace.h > > b/drivers/usb/cdns3/cdns3-trace.h > > index 8648c7a7a9dd..d3b8624fc427 100644 > > --- a/drivers/usb/cdns3/cdns3-trace.h > > +++ b/drivers/usb/cdns3/cdns3-trace.h > > @@ -214,7 +214,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > > __field(int, no_interrupt) > > __field(int, start_trb) > > __field(int, end_trb) > > - __field(struct cdns3_trb *, start_trb_addr) > > + __field(phys_addr_t, start_trb_addr) > > __field(int, flags) > > __field(unsigned int, stream_id) > > ), > > @@ -230,7 +230,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > > __entry->no_interrupt = req->request.no_interrupt; > > __entry->start_trb = req->start_trb; > > __entry->end_trb = req->end_trb; > > - __entry->start_trb_addr = req->trb; > > + __entry->start_trb_addr = *(const phys_addr_t *)req->trb; > > __entry->flags = req->flags; > > __entry->stream_id = req->request.stream_id; > > ), > > @@ -244,7 +244,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > > __entry->status, > > __entry->start_trb, > > __entry->end_trb, > > - __entry->start_trb_addr, > > + /* %pa dereferences */ &__entry->start_trb_addr, > > __entry->flags, > > __entry->stream_id > > ) > > > > > > Can you please test it? I don't have the hardware, but I also want to make > > sure I don't break anything. > > > > Thanks, > > > > Since the virtual address for req->trb is NULL before using it. It will > trigger below oops using your change. There is already index > (start_trb/end_trb) for which TRB it has handled, it is not necessary > to trace information for its physical address. I decide to delete this > trace entry, thanks for reporting it. Thanks for fixing / removing it. But I should have added a NULL check before dereferencing, because that's what the vsnprintf() code does. -- Steve
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On 21-03-02 09:56:05, Steven Rostedt wrote: > On Tue, 2 Mar 2021 16:23:55 +0800 > Peter Chen wrote: > > s it looks like it uses %pa which IIUC from the printk code, it > > > >> dereferences the pointer to find it's virtual address. The event has > > > >> this as the field: > > > >> > > > >> __field(struct cdns3_trb *, start_trb_addr) > > > >> > > > >> Assigns it with: > > > >> > > > >> __entry->start_trb_addr = req->trb; > > > >> > > > >> And prints that with %pa, which will dereference pointer at the time of > > > >> reading, where the address in question may no longer be around. That > > > >> looks to me as a potential bug. > > > > Steven, thanks for reporting. Do you mind sending patch to fix it? > > If you have no time to do it, I will do it later. > > > > I would have already fixed it, but I wasn't exactly sure how this is used. > > In Documentation/core-api/printk-formats.rst we have: > >Physical address types phys_addr_t >-- > >:: > >%pa[p] 0x01234567 or 0x0123456789abcdef > >For printing a phys_addr_t type (and its derivatives, such as >resource_size_t) which can vary based on build options, regardless of the >width of the CPU data path. > > So it only looks like it is used to for the size of the pointer. > > I guess something like this might work: > > diff --git a/drivers/usb/cdns3/cdns3-trace.h b/drivers/usb/cdns3/cdns3-trace.h > index 8648c7a7a9dd..d3b8624fc427 100644 > --- a/drivers/usb/cdns3/cdns3-trace.h > +++ b/drivers/usb/cdns3/cdns3-trace.h > @@ -214,7 +214,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > __field(int, no_interrupt) > __field(int, start_trb) > __field(int, end_trb) > - __field(struct cdns3_trb *, start_trb_addr) > + __field(phys_addr_t, start_trb_addr) > __field(int, flags) > __field(unsigned int, stream_id) > ), > @@ -230,7 +230,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > __entry->no_interrupt = req->request.no_interrupt; > __entry->start_trb = req->start_trb; > __entry->end_trb = req->end_trb; > - __entry->start_trb_addr = req->trb; > + __entry->start_trb_addr = *(const phys_addr_t *)req->trb; > __entry->flags = req->flags; > __entry->stream_id = req->request.stream_id; > ), > @@ -244,7 +244,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > __entry->status, > __entry->start_trb, > __entry->end_trb, > - __entry->start_trb_addr, > + /* %pa dereferences */ &__entry->start_trb_addr, > __entry->flags, > __entry->stream_id > ) > > > Can you please test it? I don't have the hardware, but I also want to make > sure I don't break anything. > > Thanks, > Since the virtual address for req->trb is NULL before using it. It will trigger below oops using your change. There is already index (start_trb/end_trb) for which TRB it has handled, it is not necessary to trace information for its physical address. I decide to delete this trace entry, thanks for reporting it. [ 61.695160] Unable to handle kernel NULL pointer dereference at virtual address [ 61.704066] Mem abort info: [ 61.706910] ESR = 0x9606 [ 61.71] EC = 0x25: DABT (current EL), IL = 32 bits [ 61.715339] SET = 0, FnV = 0 [ 61.718416] EA = 0, S1PTW = 0 [ 61.721575] Data abort info: [ 61.724482] ISV = 0, ISS = 0x0006 [ 61.728323] CM = 0, WnR = 0 [ 61.731324] user pgtable: 4k pages, 48-bit VAs, pgdp=0008856dd000 [ 61.737816] [] pgd=00088577a003, p4d=00088577a003, pud=00088477c003, pmd= [ 61.748532] Internal error: Oops: 9606 [#1] PREEMPT SMP [ 61.754113] Modules linked in: fsl_jr_uio caam_jr caamkeyblob_desc caamhash_desc caamalg_desc crypto_engine rng_core authenc libdes crct10dif_ce mxc_jpeg_encdec imx8_media_dev(C) caam error Message from syslogd@imx8qmmek at Fri Jul 10 06:52:44 2020 ... imx8qmmek kernel: [ 61.748532] Internal error: Oops: 9606 [#1] PREEMPT SMP [ 61.784245] CPU: 3 PID: 188 Comm: 1-0050 Tainted: G C 5.10.0-rc7-04451-gfcfe23a5424-dirty #3 [ 61.793993] Hardware name: Freescale i.MX8QXP MEK (DT) [ 61.799139] pstate: 8005 (Nzcv daif -PAN -UAO -TCO BTYPE=--) [ 61.805162] pc : trace_event_raw_event_cdns3_log_request+0xf4/0x170 [ 61.811440] lr : trace_event_raw_event_cdns3_log_request+0x94/0x170 [ 61.817707] sp : 80001387ba40 [ 61.821019] x29: 80001387ba40 x28: 0002 [ 61.826336] x27: 000801e20080 x26: 000800e5c8c8 [ 61.831652] x25: 0008044e0c00 x24: 000800505308 [ 61.836969] x23: 800012464000 x22: 00040050 [ 61.842286] x21: 000801e0aa00 x20: 0008002e7f18 [ 61.847603] x19: 0008
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Wed, 3 Mar 2021 09:21:39 +0800
Peter Chen wrote:
> On 21-03-02 09:56:05, Steven Rostedt wrote:
> > On Tue, 2 Mar 2021 16:23:55 +0800
> > Peter Chen wrote:
> >
> > s it looks like it uses %pa which IIUC from the printk code, it
> > > > >> dereferences the pointer to find it's virtual address. The event has
> > > > >> this as the field:
> > > > >>
> > > > >> __field(struct cdns3_trb *, start_trb_addr)
> > > > >>
> > > > >> Assigns it with:
> > > > >>
> > > > >> __entry->start_trb_addr = req->trb;
> > > > >>
> > > > >> And prints that with %pa, which will dereference pointer at the time
> > > > >> of
> > > > >> reading, where the address in question may no longer be around. That
> > > > >> looks to me as a potential bug.
> > >
> > > Steven, thanks for reporting. Do you mind sending patch to fix it?
> > > If you have no time to do it, I will do it later.
> > >
> >
> > I would have already fixed it, but I wasn't exactly sure how this is used.
> >
> > In Documentation/core-api/printk-formats.rst we have:
> >
> >Physical address types phys_addr_t
> >--
> >
> >::
> >
> >%pa[p] 0x01234567 or 0x0123456789abcdef
> >
> >For printing a phys_addr_t type (and its derivatives, such as
> >resource_size_t) which can vary based on build options, regardless of the
> >width of the CPU data path.
> >
> > So it only looks like it is used to for the size of the pointer.
> >
> > I guess something like this might work:
> >
> > diff --git a/drivers/usb/cdns3/cdns3-trace.h
> > b/drivers/usb/cdns3/cdns3-trace.h
> > index 8648c7a7a9dd..d3b8624fc427 100644
> > --- a/drivers/usb/cdns3/cdns3-trace.h
> > +++ b/drivers/usb/cdns3/cdns3-trace.h
> > @@ -214,7 +214,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request,
> > __field(int, no_interrupt)
> > __field(int, start_trb)
> > __field(int, end_trb)
> > - __field(struct cdns3_trb *, start_trb_addr)
> > + __field(phys_addr_t, start_trb_addr)
> > __field(int, flags)
> > __field(unsigned int, stream_id)
> > ),
> > @@ -230,7 +230,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request,
> > __entry->no_interrupt = req->request.no_interrupt;
> > __entry->start_trb = req->start_trb;
> > __entry->end_trb = req->end_trb;
> > - __entry->start_trb_addr = req->trb;
> > + __entry->start_trb_addr = *(const phys_addr_t *)req->trb;
> > __entry->flags = req->flags;
> > __entry->stream_id = req->request.stream_id;
> > ),
> > @@ -244,7 +244,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request,
> > __entry->status,
> > __entry->start_trb,
> > __entry->end_trb,
> > - __entry->start_trb_addr,
> > + /* %pa dereferences */ &__entry->start_trb_addr,
> > __entry->flags,
> > __entry->stream_id
> > )
> >
> >
> > Can you please test it? I don't have the hardware, but I also want to make
> > sure I don't break anything.
> >
>
> Hi Steve,
>
> Regarding this issue, I have one question:
> - If the virtual address is got from dma_alloc_coherent, can't we print
> this address using %pa to get its physical address (the same with DMA
> address),
> or its DMA address using %pad? req->trb is the virtual address got from
I'm not sure. I just looked at the vsprintf code, which simply does:
> static noinline_for_stack
> char *address_val(char *buf, char *end, const void *addr,
> struct printf_spec spec, const char *fmt)
> {
> unsigned long long num;
> int size;
>
> if (check_pointer(&buf, end, addr, spec))
> return buf;
>
> switch (fmt[1]) {
> case 'd':
> num = *(const dma_addr_t *)addr;
> size = sizeof(dma_addr_t);
The above is what is called, which dereferences addr and places it into num.
> break;
> case 'p':
> default:
> num = *(const phys_addr_t *)addr;
> size = sizeof(phys_addr_t);
> break;
> }
>
> return special_hex_number(buf, end, num, size);
This just prints the hex number defined by num. There's no physical address
calculations done via vsprintf that I'm aware of.
> }
> dma_alloc_coherent. And what's the logic for this "unsafe dereference"
> warning?
The actions done in TP_fast_assign() are executed at the time of the trace
event (i.e. when trace_cdns3_ep_queue() is called), but the actions of
TP_printk() are executed when the user reads the trace file (minutes,
hours, days later!). Thus, when you have a TP_printk("... %pa ...", and a
__entry->start_trb_addr referenced, that start_trb_addr may be pointing to
something that is long gone, and when you use a kernel vsnprintf()
dereferencing pointer like %pa (or %pU, %pM, etc), it may read something
that no longer exists, and is obviously unsafe.
S
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On 21-03-02 09:56:05, Steven Rostedt wrote: > On Tue, 2 Mar 2021 16:23:55 +0800 > Peter Chen wrote: > > s it looks like it uses %pa which IIUC from the printk code, it > > > >> dereferences the pointer to find it's virtual address. The event has > > > >> this as the field: > > > >> > > > >> __field(struct cdns3_trb *, start_trb_addr) > > > >> > > > >> Assigns it with: > > > >> > > > >> __entry->start_trb_addr = req->trb; > > > >> > > > >> And prints that with %pa, which will dereference pointer at the time of > > > >> reading, where the address in question may no longer be around. That > > > >> looks to me as a potential bug. > > > > Steven, thanks for reporting. Do you mind sending patch to fix it? > > If you have no time to do it, I will do it later. > > > > I would have already fixed it, but I wasn't exactly sure how this is used. > > In Documentation/core-api/printk-formats.rst we have: > >Physical address types phys_addr_t >-- > >:: > >%pa[p] 0x01234567 or 0x0123456789abcdef > >For printing a phys_addr_t type (and its derivatives, such as >resource_size_t) which can vary based on build options, regardless of the >width of the CPU data path. > > So it only looks like it is used to for the size of the pointer. > > I guess something like this might work: > > diff --git a/drivers/usb/cdns3/cdns3-trace.h b/drivers/usb/cdns3/cdns3-trace.h > index 8648c7a7a9dd..d3b8624fc427 100644 > --- a/drivers/usb/cdns3/cdns3-trace.h > +++ b/drivers/usb/cdns3/cdns3-trace.h > @@ -214,7 +214,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > __field(int, no_interrupt) > __field(int, start_trb) > __field(int, end_trb) > - __field(struct cdns3_trb *, start_trb_addr) > + __field(phys_addr_t, start_trb_addr) > __field(int, flags) > __field(unsigned int, stream_id) > ), > @@ -230,7 +230,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > __entry->no_interrupt = req->request.no_interrupt; > __entry->start_trb = req->start_trb; > __entry->end_trb = req->end_trb; > - __entry->start_trb_addr = req->trb; > + __entry->start_trb_addr = *(const phys_addr_t *)req->trb; > __entry->flags = req->flags; > __entry->stream_id = req->request.stream_id; > ), > @@ -244,7 +244,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, > __entry->status, > __entry->start_trb, > __entry->end_trb, > - __entry->start_trb_addr, > + /* %pa dereferences */ &__entry->start_trb_addr, > __entry->flags, > __entry->stream_id > ) > > > Can you please test it? I don't have the hardware, but I also want to make > sure I don't break anything. > Hi Steve, Regarding this issue, I have one question: - If the virtual address is got from dma_alloc_coherent, can't we print this address using %pa to get its physical address (the same with DMA address), or its DMA address using %pad? req->trb is the virtual address got from dma_alloc_coherent. And what's the logic for this "unsafe dereference" warning? Thanks. -- Thanks, Peter Chen
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Tue, 2 Mar 2021 16:23:55 +0800 Peter Chen wrote: s it looks like it uses %pa which IIUC from the printk code, it > > >> dereferences the pointer to find it's virtual address. The event has > > >> this as the field: > > >> > > >> __field(struct cdns3_trb *, start_trb_addr) > > >> > > >> Assigns it with: > > >> > > >> __entry->start_trb_addr = req->trb; > > >> > > >> And prints that with %pa, which will dereference pointer at the time of > > >> reading, where the address in question may no longer be around. That > > >> looks to me as a potential bug. > > Steven, thanks for reporting. Do you mind sending patch to fix it? > If you have no time to do it, I will do it later. > I would have already fixed it, but I wasn't exactly sure how this is used. In Documentation/core-api/printk-formats.rst we have: Physical address types phys_addr_t -- :: %pa[p] 0x01234567 or 0x0123456789abcdef For printing a phys_addr_t type (and its derivatives, such as resource_size_t) which can vary based on build options, regardless of the width of the CPU data path. So it only looks like it is used to for the size of the pointer. I guess something like this might work: diff --git a/drivers/usb/cdns3/cdns3-trace.h b/drivers/usb/cdns3/cdns3-trace.h index 8648c7a7a9dd..d3b8624fc427 100644 --- a/drivers/usb/cdns3/cdns3-trace.h +++ b/drivers/usb/cdns3/cdns3-trace.h @@ -214,7 +214,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, __field(int, no_interrupt) __field(int, start_trb) __field(int, end_trb) - __field(struct cdns3_trb *, start_trb_addr) + __field(phys_addr_t, start_trb_addr) __field(int, flags) __field(unsigned int, stream_id) ), @@ -230,7 +230,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, __entry->no_interrupt = req->request.no_interrupt; __entry->start_trb = req->start_trb; __entry->end_trb = req->end_trb; - __entry->start_trb_addr = req->trb; + __entry->start_trb_addr = *(const phys_addr_t *)req->trb; __entry->flags = req->flags; __entry->stream_id = req->request.stream_id; ), @@ -244,7 +244,7 @@ DECLARE_EVENT_CLASS(cdns3_log_request, __entry->status, __entry->start_trb, __entry->end_trb, - __entry->start_trb_addr, + /* %pa dereferences */ &__entry->start_trb_addr, __entry->flags, __entry->stream_id ) Can you please test it? I don't have the hardware, but I also want to make sure I don't break anything. Thanks, -- Steve
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On 21-03-01 05:27:04, Pawel Laszczak wrote: > > + Peter Chen - Maintainer of CDNS3 driver > > > > >[ Resending with an address that should work for Felipe ] > > > >On Sat, 27 Feb 2021 14:18:02 -0500 > >Steven Rostedt wrote: > > > >> On Fri, 26 Feb 2021 14:21:00 -0800 > >> Linus Torvalds wrote: > >> > >> > On Fri, Feb 26, 2021 at 11:07 AM Steven Rostedt > >> > wrote: > >> > > > >> > > The first patch scans the print fmts of the trace events looking for > >> > > dereferencing pointers from %p*, and making sure that they refer back > >> > > to the trace event itself. > >> > > > >> > > The second patch handles strings "%s" [..] > >> > > >> > Doing this at runtime really feels like the wrong thing to do. > >> > > >> > It won't even protect us from what happened - people like me and > >> > Andrew won't even run those tracepoints in the first place, so we > >> > won't notice. > >> > > >> > It really would be much better in every respect to have this done by > >> > checkpatch, I think. > >> > >> And after fixing the parsing to not trigger false positives, an > >> allyesconfig boot found this: > >> > >> event cdns3_gadget_giveback has unsafe dereference of argument 11 > >> print_fmt: "%s: req: %p, req buff %p, length: %u/%u %s%s%s, status: %d, > >> trb: [start:%d, end:%d: virt addr %pa], flags:%x SID: %u", > >__get_str(name), REC->req, REC->buf, > >> REC->actual, REC->length, REC->zero ? "Z" : "z", REC->short_not_ok ? "S" > >> : "s", REC->no_interrupt ? "I" : "i", REC->status, REC- > >>start_trb, REC->end_trb, REC->start_trb_addr, REC->flags, RE > >> C->stream_id > >> > >> (as the above is from a trace event class, it triggered for every event > >> in that class). > >> > >> As it looks like it uses %pa which IIUC from the printk code, it > >> dereferences the pointer to find it's virtual address. The event has > >> this as the field: > >> > >> __field(struct cdns3_trb *, start_trb_addr) > >> > >> Assigns it with: > >> > >> __entry->start_trb_addr = req->trb; > >> > >> And prints that with %pa, which will dereference pointer at the time of > >> reading, where the address in question may no longer be around. That > >> looks to me as a potential bug. Steven, thanks for reporting. Do you mind sending patch to fix it? If you have no time to do it, I will do it later. -- Thanks, Peter Chen
RE: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
+ Peter Chen - Maintainer of CDNS3 driver > >[ Resending with an address that should work for Felipe ] > >On Sat, 27 Feb 2021 14:18:02 -0500 >Steven Rostedt wrote: > >> On Fri, 26 Feb 2021 14:21:00 -0800 >> Linus Torvalds wrote: >> >> > On Fri, Feb 26, 2021 at 11:07 AM Steven Rostedt >> > wrote: >> > > >> > > The first patch scans the print fmts of the trace events looking for >> > > dereferencing pointers from %p*, and making sure that they refer back >> > > to the trace event itself. >> > > >> > > The second patch handles strings "%s" [..] >> > >> > Doing this at runtime really feels like the wrong thing to do. >> > >> > It won't even protect us from what happened - people like me and >> > Andrew won't even run those tracepoints in the first place, so we >> > won't notice. >> > >> > It really would be much better in every respect to have this done by >> > checkpatch, I think. >> >> And after fixing the parsing to not trigger false positives, an >> allyesconfig boot found this: >> >> event cdns3_gadget_giveback has unsafe dereference of argument 11 >> print_fmt: "%s: req: %p, req buff %p, length: %u/%u %s%s%s, status: %d, trb: >> [start:%d, end:%d: virt addr %pa], flags:%x SID: %u", >__get_str(name), REC->req, REC->buf, >> REC->actual, REC->length, REC->zero ? "Z" : "z", REC->short_not_ok ? "S" : >> "s", REC->no_interrupt ? "I" : "i", REC->status, REC- >>start_trb, REC->end_trb, REC->start_trb_addr, REC->flags, RE >> C->stream_id >> >> (as the above is from a trace event class, it triggered for every event >> in that class). >> >> As it looks like it uses %pa which IIUC from the printk code, it >> dereferences the pointer to find it's virtual address. The event has >> this as the field: >> >> __field(struct cdns3_trb *, start_trb_addr) >> >> Assigns it with: >> >> __entry->start_trb_addr = req->trb; >> >> And prints that with %pa, which will dereference pointer at the time of >> reading, where the address in question may no longer be around. That >> looks to me as a potential bug. >> >> [ Cc'd the people responsible for that code. ] >> >> -- Steve
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
[ Resending with an address that should work for Felipe ] On Sat, 27 Feb 2021 14:18:02 -0500 Steven Rostedt wrote: > On Fri, 26 Feb 2021 14:21:00 -0800 > Linus Torvalds wrote: > > > On Fri, Feb 26, 2021 at 11:07 AM Steven Rostedt > > wrote: > > > > > > The first patch scans the print fmts of the trace events looking for > > > dereferencing pointers from %p*, and making sure that they refer back > > > to the trace event itself. > > > > > > The second patch handles strings "%s" [..] > > > > Doing this at runtime really feels like the wrong thing to do. > > > > It won't even protect us from what happened - people like me and > > Andrew won't even run those tracepoints in the first place, so we > > won't notice. > > > > It really would be much better in every respect to have this done by > > checkpatch, I think. > > And after fixing the parsing to not trigger false positives, an > allyesconfig boot found this: > > event cdns3_gadget_giveback has unsafe dereference of argument 11 > print_fmt: "%s: req: %p, req buff %p, length: %u/%u %s%s%s, status: %d, trb: > [start:%d, end:%d: virt addr %pa], flags:%x SID: %u", __get_str(name), > REC->req, REC->buf, > REC->actual, REC->length, REC->zero ? "Z" : "z", REC->short_not_ok ? "S" : > "s", REC->no_interrupt ? "I" : "i", REC->status, REC->start_trb, > REC->end_trb, REC->start_trb_addr, REC->flags, RE > C->stream_id > > (as the above is from a trace event class, it triggered for every event > in that class). > > As it looks like it uses %pa which IIUC from the printk code, it > dereferences the pointer to find it's virtual address. The event has > this as the field: > > __field(struct cdns3_trb *, start_trb_addr) > > Assigns it with: > > __entry->start_trb_addr = req->trb; > > And prints that with %pa, which will dereference pointer at the time of > reading, where the address in question may no longer be around. That > looks to me as a potential bug. > > [ Cc'd the people responsible for that code. ] > > -- Steve
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Fri, 26 Feb 2021 14:21:00 -0800 Linus Torvalds wrote: > On Fri, Feb 26, 2021 at 11:07 AM Steven Rostedt wrote: > > > > The first patch scans the print fmts of the trace events looking for > > dereferencing pointers from %p*, and making sure that they refer back > > to the trace event itself. > > > > The second patch handles strings "%s" [..] > > Doing this at runtime really feels like the wrong thing to do. > > It won't even protect us from what happened - people like me and > Andrew won't even run those tracepoints in the first place, so we > won't notice. > > It really would be much better in every respect to have this done by > checkpatch, I think. And after fixing the parsing to not trigger false positives, an allyesconfig boot found this: event cdns3_gadget_giveback has unsafe dereference of argument 11 print_fmt: "%s: req: %p, req buff %p, length: %u/%u %s%s%s, status: %d, trb: [start:%d, end:%d: virt addr %pa], flags:%x SID: %u", __get_str(name), REC->req, REC->buf, REC->actual, REC->length, REC->zero ? "Z" : "z", REC->short_not_ok ? "S" : "s", REC->no_interrupt ? "I" : "i", REC->status, REC->start_trb, REC->end_trb, REC->start_trb_addr, REC->flags, RE C->stream_id (as the above is from a trace event class, it triggered for every event in that class). As it looks like it uses %pa which IIUC from the printk code, it dereferences the pointer to find it's virtual address. The event has this as the field: __field(struct cdns3_trb *, start_trb_addr) Assigns it with: __entry->start_trb_addr = req->trb; And prints that with %pa, which will dereference pointer at the time of reading, where the address in question may no longer be around. That looks to me as a potential bug. [ Cc'd the people responsible for that code. ] -- Steve
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Fri, 2021-02-26 at 18:33 -0500, Steven Rostedt wrote: > On Fri, 26 Feb 2021 14:21:00 -0800 > Linus Torvalds wrote: > > > > The second patch handles strings "%s" [..] > > > > Doing this at runtime really feels like the wrong thing to do. > > > > It won't even protect us from what happened - people like me and > > Andrew won't even run those tracepoints in the first place, so we > > won't notice. > > > > It really would be much better in every respect to have this done by > > checkpatch, I think. > > They are not mutually exclusive. We could have both. One thing that's nice > about this patch is that it removes the possibility of a real bug. That is, > it will catch the dereferencing of a string that is not valid, WARN about > it, but it wont try to dereference it (outside of the > strcpy_from_kernel_nofault()). And hopefully the warning and lack of data > they want, will have this get caught during development. > > Also, there's cases that %s is allowed to reference data that I don't know > if checkpatch would be able to differentiate. It's not obvious to me how to do that.
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Fri, 26 Feb 2021 14:21:00 -0800 Linus Torvalds wrote: > > The second patch handles strings "%s" [..] > > Doing this at runtime really feels like the wrong thing to do. > > It won't even protect us from what happened - people like me and > Andrew won't even run those tracepoints in the first place, so we > won't notice. > > It really would be much better in every respect to have this done by > checkpatch, I think. They are not mutually exclusive. We could have both. One thing that's nice about this patch is that it removes the possibility of a real bug. That is, it will catch the dereferencing of a string that is not valid, WARN about it, but it wont try to dereference it (outside of the strcpy_from_kernel_nofault()). And hopefully the warning and lack of data they want, will have this get caught during development. Also, there's cases that %s is allowed to reference data that I don't know if checkpatch would be able to differentiate. As for the other pointer dereferences (the first patch), those get caught at boot up if they are compiled in. That is, you don't need to have the events enabled. The boot up code will do the verification on all events that are loaded (allyesconfig will catch all of them, which I need to try to boot with this code). -- Steve
Re: [PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
On Fri, Feb 26, 2021 at 11:07 AM Steven Rostedt wrote: > > The first patch scans the print fmts of the trace events looking for > dereferencing pointers from %p*, and making sure that they refer back > to the trace event itself. > > The second patch handles strings "%s" [..] Doing this at runtime really feels like the wrong thing to do. It won't even protect us from what happened - people like me and Andrew won't even run those tracepoints in the first place, so we won't notice. It really would be much better in every respect to have this done by checkpatch, I think. Linus
[PATCH 0/2] tracing: Detect unsafe dereferencing of pointers from trace events
After seeing that an unsafe string dereference in a trace event made it into the kernel, I decided it's time to add some sanity checks to catch these cases without needing me to supervise. The first patch scans the print fmts of the trace events looking for dereferencing pointers from %p*, and making sure that they refer back to the trace event itself. The second patch handles strings "%s", as there are cases that are fine with dereferencing the string outside the trace event. On reading of the trace file, the %s is looked for and when found, the logic checks the pointer that it is about to be dereferenced to see if it is a valid location. This check would have caught the last unsafe dereference committed into the kernel. Steven Rostedt (VMware) (2): tracing: Add check of trace event print fmts for dereferencing pointers tracing: Add a verifier to check string pointers for trace events kernel/trace/trace.c| 148 + kernel/trace/trace.h| 2 + kernel/trace/trace_events.c | 198 kernel/trace/trace_output.c | 2 +- 4 files changed, 349 insertions(+), 1 deletion(-)
