lkml.org 
[lkml]   [2021]   [Dec]   [6]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    Patch in this message
    /
    Date
    From
    SubjectRe: [PATCH v3 08/25] kcsan: Show location access was reordered to
    Hi,

    On Tue, Nov 30, 2021 at 12:44:16PM +0100, Marco Elver wrote:
    > Also show the location the access was reordered to. An example report:
    >
    > | ==================================================================
    > | BUG: KCSAN: data-race in test_kernel_wrong_memorder / test_kernel_wrong_memorder
    > |
    > | read-write to 0xffffffffc01e61a8 of 8 bytes by task 2311 on cpu 5:
    > | test_kernel_wrong_memorder+0x57/0x90
    > | access_thread+0x99/0xe0
    > | kthread+0x2ba/0x2f0
    > | ret_from_fork+0x22/0x30
    > |
    > | read-write (reordered) to 0xffffffffc01e61a8 of 8 bytes by task 2310 on cpu 7:
    > | test_kernel_wrong_memorder+0x57/0x90
    > | access_thread+0x99/0xe0
    > | kthread+0x2ba/0x2f0
    > | ret_from_fork+0x22/0x30
    > | |
    > | +-> reordered to: test_kernel_wrong_memorder+0x80/0x90
    > |

    Should this be "reordered from" instead of "reordered to"? For example,
    if the following case needs a smp_mb() between write to A and write to
    B, I think currently it will report as follow:

    foo() {
    WRITE_ONCE(A, 1); // let's say A's address is 0xaaaa
    bar() {
    WRITE_ONCE(B, 1); // Assume B's address is 0xbbbb
    // KCSAN find the problem here
    }
    }

    <report>
    | write (reordered) to 0xaaaa of ...:
    | bar+0x... // address of the write to B
    | foo+0x... // address of the callsite to bar()
    | ...
    | |
    | +-> reordered to: foo+0x... // address of the write to A

    But since the access reported here is the write to A, so it's a
    "reordered from" instead of "reordered to"?

    Regards,
    Boqun

    > | Reported by Kernel Concurrency Sanitizer on:
    > | CPU: 7 PID: 2310 Comm: access_thread Not tainted 5.14.0-rc1+ #18
    > | Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.14.0-2 04/01/2014
    > | ==================================================================
    >
    > Signed-off-by: Marco Elver <elver@google.com>
    > ---
    > kernel/kcsan/report.c | 35 +++++++++++++++++++++++------------
    > 1 file changed, 23 insertions(+), 12 deletions(-)
    >
    > diff --git a/kernel/kcsan/report.c b/kernel/kcsan/report.c
    > index 1b0e050bdf6a..67794404042a 100644
    > --- a/kernel/kcsan/report.c
    > +++ b/kernel/kcsan/report.c
    > @@ -308,10 +308,12 @@ static int get_stack_skipnr(const unsigned long stack_entries[], int num_entries
    >
    > /*
    > * Skips to the first entry that matches the function of @ip, and then replaces
    > - * that entry with @ip, returning the entries to skip.
    > + * that entry with @ip, returning the entries to skip with @replaced containing
    > + * the replaced entry.
    > */
    > static int
    > -replace_stack_entry(unsigned long stack_entries[], int num_entries, unsigned long ip)
    > +replace_stack_entry(unsigned long stack_entries[], int num_entries, unsigned long ip,
    > + unsigned long *replaced)
    > {
    > unsigned long symbolsize, offset;
    > unsigned long target_func;
    > @@ -330,6 +332,7 @@ replace_stack_entry(unsigned long stack_entries[], int num_entries, unsigned lon
    > func -= offset;
    >
    > if (func == target_func) {
    > + *replaced = stack_entries[skip];
    > stack_entries[skip] = ip;
    > return skip;
    > }
    > @@ -342,9 +345,10 @@ replace_stack_entry(unsigned long stack_entries[], int num_entries, unsigned lon
    > }
    >
    > static int
    > -sanitize_stack_entries(unsigned long stack_entries[], int num_entries, unsigned long ip)
    > +sanitize_stack_entries(unsigned long stack_entries[], int num_entries, unsigned long ip,
    > + unsigned long *replaced)
    > {
    > - return ip ? replace_stack_entry(stack_entries, num_entries, ip) :
    > + return ip ? replace_stack_entry(stack_entries, num_entries, ip, replaced) :
    > get_stack_skipnr(stack_entries, num_entries);
    > }
    >
    > @@ -360,6 +364,14 @@ static int sym_strcmp(void *addr1, void *addr2)
    > return strncmp(buf1, buf2, sizeof(buf1));
    > }
    >
    > +static void
    > +print_stack_trace(unsigned long stack_entries[], int num_entries, unsigned long reordered_to)
    > +{
    > + stack_trace_print(stack_entries, num_entries, 0);
    > + if (reordered_to)
    > + pr_err(" |\n +-> reordered to: %pS\n", (void *)reordered_to);
    > +}
    > +
    > static void print_verbose_info(struct task_struct *task)
    > {
    > if (!task)
    > @@ -378,10 +390,12 @@ static void print_report(enum kcsan_value_change value_change,
    > struct other_info *other_info,
    > u64 old, u64 new, u64 mask)
    > {
    > + unsigned long reordered_to = 0;
    > unsigned long stack_entries[NUM_STACK_ENTRIES] = { 0 };
    > int num_stack_entries = stack_trace_save(stack_entries, NUM_STACK_ENTRIES, 1);
    > - int skipnr = sanitize_stack_entries(stack_entries, num_stack_entries, ai->ip);
    > + int skipnr = sanitize_stack_entries(stack_entries, num_stack_entries, ai->ip, &reordered_to);
    > unsigned long this_frame = stack_entries[skipnr];
    > + unsigned long other_reordered_to = 0;
    > unsigned long other_frame = 0;
    > int other_skipnr = 0; /* silence uninit warnings */
    >
    > @@ -394,7 +408,7 @@ static void print_report(enum kcsan_value_change value_change,
    > if (other_info) {
    > other_skipnr = sanitize_stack_entries(other_info->stack_entries,
    > other_info->num_stack_entries,
    > - other_info->ai.ip);
    > + other_info->ai.ip, &other_reordered_to);
    > other_frame = other_info->stack_entries[other_skipnr];
    >
    > /* @value_change is only known for the other thread */
    > @@ -434,10 +448,9 @@ static void print_report(enum kcsan_value_change value_change,
    > other_info->ai.cpu_id);
    >
    > /* Print the other thread's stack trace. */
    > - stack_trace_print(other_info->stack_entries + other_skipnr,
    > + print_stack_trace(other_info->stack_entries + other_skipnr,
    > other_info->num_stack_entries - other_skipnr,
    > - 0);
    > -
    > + other_reordered_to);
    > if (IS_ENABLED(CONFIG_KCSAN_VERBOSE))
    > print_verbose_info(other_info->task);
    >
    > @@ -451,9 +464,7 @@ static void print_report(enum kcsan_value_change value_change,
    > get_thread_desc(ai->task_pid), ai->cpu_id);
    > }
    > /* Print stack trace of this thread. */
    > - stack_trace_print(stack_entries + skipnr, num_stack_entries - skipnr,
    > - 0);
    > -
    > + print_stack_trace(stack_entries + skipnr, num_stack_entries - skipnr, reordered_to);
    > if (IS_ENABLED(CONFIG_KCSAN_VERBOSE))
    > print_verbose_info(current);
    >
    > --
    > 2.34.0.rc2.393.gf8c9666880-goog
    >

    \
     
     \ /
      Last update: 2021-12-06 06:05    [W:4.297 / U:0.020 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site