Something went wrong. Try again.
Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
Something went wrong. Try again.
123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721// SPDX-License-Identifier: GPL-2.0/* * KCSAN reporting. * * Copyright (C) 2019, Google LLC. */
#include <linux/debug_locks.h>#include <linux/delay.h>#include <linux/jiffies.h>#include <linux/kallsyms.h>#include <linux/kernel.h>#include <linux/lockdep.h>#include <linux/preempt.h>#include <linux/printk.h>#include <linux/sched.h>#include <linux/spinlock.h>#include <linux/stacktrace.h>
#include "kcsan.h"#include "encoding.h"
/* * Max. number of stack entries to show in the report. */#define NUM_STACK_ENTRIES 64
/* Common access info. */struct access_info { const volatile void *ptr; size_t size; int access_type; int task_pid; int cpu_id; unsigned long ip;};
/* * Other thread info: communicated from other racing thread to thread that set * up the watchpoint, which then prints the complete report atomically. */struct other_info { struct access_info ai; unsigned long stack_entries[NUM_STACK_ENTRIES]; int num_stack_entries;
/* * Optionally pass @current. Typically we do not need to pass @current * via @other_info since just @task_pid is sufficient. Passing @current * has additional overhead. * * To safely pass @current, we must either use get_task_struct/ * put_task_struct, or stall the thread that populated @other_info. * * We cannot rely on get_task_struct/put_task_struct in case * release_report() races with a task being released, and would have to * free it in release_report(). This may result in deadlock if we want * to use KCSAN on the allocators. * * Since we also want to reliably print held locks for * CONFIG_KCSAN_VERBOSE, the current implementation stalls the thread * that populated @other_info until it has been consumed. */ struct task_struct *task;};
/* * To never block any producers of struct other_info, we need as many elements * as we have watchpoints (upper bound on concurrent races to report). */static struct other_info other_infos[CONFIG_KCSAN_NUM_WATCHPOINTS + NUM_SLOTS-1];
/* * Information about reported races; used to rate limit reporting. */struct report_time { /* * The last time the race was reported. */ unsigned long time;
/* * The frames of the 2 threads; if only 1 thread is known, one frame * will be 0. */ unsigned long frame1; unsigned long frame2;};
/* * Since we also want to be able to debug allocators with KCSAN, to avoid * deadlock, report_times cannot be dynamically resized with krealloc in * rate_limit_report. * * Therefore, we use a fixed-size array, which at most will occupy a page. This * still adequately rate limits reports, assuming that a) number of unique data * races is not excessive, and b) occurrence of unique races within the * same time window is limited. */#define REPORT_TIMES_MAX (PAGE_SIZE / sizeof(struct report_time))#define REPORT_TIMES_SIZE \ (CONFIG_KCSAN_REPORT_ONCE_IN_MS > REPORT_TIMES_MAX ? \ REPORT_TIMES_MAX : \ CONFIG_KCSAN_REPORT_ONCE_IN_MS)static struct report_time report_times[REPORT_TIMES_SIZE];
/* * Spinlock serializing report generation, and access to @other_infos. Although * it could make sense to have a finer-grained locking story for @other_infos, * report generation needs to be serialized either way, so not much is gained. */static DEFINE_RAW_SPINLOCK(report_lock);
/* * Checks if the race identified by thread frames frame1 and frame2 has * been reported since (now - KCSAN_REPORT_ONCE_IN_MS). */static bool rate_limit_report(unsigned long frame1, unsigned long frame2) __must_hold(&report_lock){ struct report_time *use_entry = &report_times[0]; unsigned long invalid_before; int i;
BUILD_BUG_ON(CONFIG_KCSAN_REPORT_ONCE_IN_MS != 0 && REPORT_TIMES_SIZE == 0);
if (CONFIG_KCSAN_REPORT_ONCE_IN_MS == 0) return false;
invalid_before = jiffies - msecs_to_jiffies(CONFIG_KCSAN_REPORT_ONCE_IN_MS);
/* Check if a matching race report exists. */ for (i = 0; i < REPORT_TIMES_SIZE; ++i) { struct report_time *rt = &report_times[i];
/* * Must always select an entry for use to store info as we * cannot resize report_times; at the end of the scan, use_entry * will be the oldest entry, which ideally also happened before * KCSAN_REPORT_ONCE_IN_MS ago. */ if (time_before(rt->time, use_entry->time)) use_entry = rt;
/* * Initially, no need to check any further as this entry as well * as following entries have never been used. */ if (rt->time == 0) break;
/* Check if entry expired. */ if (time_before(rt->time, invalid_before)) continue; /* before KCSAN_REPORT_ONCE_IN_MS ago */
/* Reported recently, check if race matches. */ if ((rt->frame1 == frame1 && rt->frame2 == frame2) || (rt->frame1 == frame2 && rt->frame2 == frame1)) return true; }
use_entry->time = jiffies; use_entry->frame1 = frame1; use_entry->frame2 = frame2; return false;}
/* * Special rules to skip reporting. */static boolskip_report(enum kcsan_value_change value_change, unsigned long top_frame){ /* Should never get here if value_change==FALSE. */ WARN_ON_ONCE(value_change == KCSAN_VALUE_CHANGE_FALSE);
/* * The first call to skip_report always has value_change==TRUE, since we * cannot know the value written of an instrumented access. For the 2nd * call there are 6 cases with CONFIG_KCSAN_REPORT_VALUE_CHANGE_ONLY: * * 1. read watchpoint, conflicting write (value_change==TRUE): report; * 2. read watchpoint, conflicting write (value_change==MAYBE): skip; * 3. write watchpoint, conflicting write (value_change==TRUE): report; * 4. write watchpoint, conflicting write (value_change==MAYBE): skip; * 5. write watchpoint, conflicting read (value_change==MAYBE): skip; * 6. write watchpoint, conflicting read (value_change==TRUE): report; * * Cases 1-4 are intuitive and expected; case 5 ensures we do not report * data races where the write may have rewritten the same value; case 6 * is possible either if the size is larger than what we check value * changes for or the access type is KCSAN_ACCESS_ASSERT. */ if (IS_ENABLED(CONFIG_KCSAN_REPORT_VALUE_CHANGE_ONLY) && value_change == KCSAN_VALUE_CHANGE_MAYBE) { /* * The access is a write, but the data value did not change. * * We opt-out of this filter for certain functions at request of * maintainers. */ char buf[64]; int len = scnprintf(buf, sizeof(buf), "%ps", (void *)top_frame);
if (!strnstr(buf, "rcu_", len) && !strnstr(buf, "_rcu", len) && !strnstr(buf, "_srcu", len)) return true; }
return kcsan_skip_report_debugfs(top_frame);}
static const char *get_access_type(int type){ if (type & KCSAN_ACCESS_ASSERT) { if (type & KCSAN_ACCESS_SCOPED) { if (type & KCSAN_ACCESS_WRITE) return "assert no accesses (reordered)"; else return "assert no writes (reordered)"; } else { if (type & KCSAN_ACCESS_WRITE) return "assert no accesses"; else return "assert no writes"; } }
switch (type) { case 0: return "read"; case KCSAN_ACCESS_ATOMIC: return "read (marked)"; case KCSAN_ACCESS_WRITE: return "write"; case KCSAN_ACCESS_WRITE | KCSAN_ACCESS_ATOMIC: return "write (marked)"; case KCSAN_ACCESS_COMPOUND | KCSAN_ACCESS_WRITE: return "read-write"; case KCSAN_ACCESS_COMPOUND | KCSAN_ACCESS_WRITE | KCSAN_ACCESS_ATOMIC: return "read-write (marked)"; case KCSAN_ACCESS_SCOPED: return "read (reordered)"; case KCSAN_ACCESS_SCOPED | KCSAN_ACCESS_ATOMIC: return "read (marked, reordered)"; case KCSAN_ACCESS_SCOPED | KCSAN_ACCESS_WRITE: return "write (reordered)"; case KCSAN_ACCESS_SCOPED | KCSAN_ACCESS_WRITE | KCSAN_ACCESS_ATOMIC: return "write (marked, reordered)"; case KCSAN_ACCESS_SCOPED | KCSAN_ACCESS_COMPOUND | KCSAN_ACCESS_WRITE: return "read-write (reordered)"; case KCSAN_ACCESS_SCOPED | KCSAN_ACCESS_COMPOUND | KCSAN_ACCESS_WRITE | KCSAN_ACCESS_ATOMIC: return "read-write (marked, reordered)"; default: BUG(); }}
static const char *get_bug_type(int type){ return (type & KCSAN_ACCESS_ASSERT) != 0 ? "assert: race" : "data-race";}
/* Return thread description: in task or interrupt. */static const char *get_thread_desc(int task_id){ if (task_id != -1) { static char buf[32]; /* safe: protected by report_lock */
snprintf(buf, sizeof(buf), "task %i", task_id); return buf; } return "interrupt";}
/* Helper to skip KCSAN-related functions in stack-trace. */static int get_stack_skipnr(const unsigned long stack_entries[], int num_entries){ char buf[64]; char *cur; int len, skip;
for (skip = 0; skip < num_entries; ++skip) { len = scnprintf(buf, sizeof(buf), "%ps", (void *)stack_entries[skip]);
/* Never show tsan_* or {read,write}_once_size. */ if (strnstr(buf, "tsan_", len) || strnstr(buf, "_once_size", len)) continue;
cur = strnstr(buf, "kcsan_", len); if (cur) { cur += strlen("kcsan_"); if (!str_has_prefix(cur, "test")) continue; /* KCSAN runtime function. */ /* KCSAN related test. */ }
/* * No match for runtime functions -- @skip entries to skip to * get to first frame of interest. */ break; }
return skip;}
/* * Skips to the first entry that matches the function of @ip, and then replaces * that entry with @ip, returning the entries to skip with @replaced containing * the replaced entry. */static intreplace_stack_entry(unsigned long stack_entries[], int num_entries, unsigned long ip, unsigned long *replaced){ unsigned long symbolsize, offset; unsigned long target_func; int skip;
if (kallsyms_lookup_size_offset(ip, &symbolsize, &offset)) target_func = ip - offset; else goto fallback;
for (skip = 0; skip < num_entries; ++skip) { unsigned long func = stack_entries[skip];
if (!kallsyms_lookup_size_offset(func, &symbolsize, &offset)) goto fallback; func -= offset;
if (func == target_func) { *replaced = stack_entries[skip]; stack_entries[skip] = ip; return skip; } }
fallback: /* Should not happen; the resulting stack trace is likely misleading. */ WARN_ONCE(1, "Cannot find frame for %pS in stack trace", (void *)ip); return get_stack_skipnr(stack_entries, num_entries);}
static intsanitize_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, replaced) : get_stack_skipnr(stack_entries, num_entries);}
/* Compares symbolized strings of addr1 and addr2. */static int sym_strcmp(void *addr1, void *addr2){ char buf1[64]; char buf2[64];
snprintf(buf1, sizeof(buf1), "%pS", addr1); snprintf(buf2, sizeof(buf2), "%pS", addr2);
return strncmp(buf1, buf2, sizeof(buf1));}
static voidprint_stack_trace(unsigned long stack_entries[], int num_entries, unsigned long reordered_to) __must_hold(&report_lock){ 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) __must_hold(&report_lock){ if (!task) return;
/* Restore IRQ state trace for printing. */ kcsan_restore_irqtrace(task);
pr_err("\n"); debug_show_held_locks(task); print_irqtrace_events(task);}
static void print_report(enum kcsan_value_change value_change, const struct access_info *ai, struct other_info *other_info, u64 old, u64 new, u64 mask) __must_hold(&report_lock){ 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, &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 */
/* * Must check report filter rules before starting to print. */ if (skip_report(KCSAN_VALUE_CHANGE_TRUE, stack_entries[skipnr])) return;
if (other_info) { other_skipnr = sanitize_stack_entries(other_info->stack_entries, other_info->num_stack_entries, other_info->ai.ip, &other_reordered_to); other_frame = other_info->stack_entries[other_skipnr];
/* @value_change is only known for the other thread */ if (skip_report(value_change, other_frame)) return; }
if (rate_limit_report(this_frame, other_frame)) return;
/* Print report header. */ pr_err("==================================================================\n"); if (other_info) { int cmp;
/* * Order functions lexographically for consistent bug titles. * Do not print offset of functions to keep title short. */ cmp = sym_strcmp((void *)other_frame, (void *)this_frame); pr_err("BUG: KCSAN: %s in %ps / %ps\n", get_bug_type(ai->access_type | other_info->ai.access_type), (void *)(cmp < 0 ? other_frame : this_frame), (void *)(cmp < 0 ? this_frame : other_frame)); } else { pr_err("BUG: KCSAN: %s in %pS\n", get_bug_type(ai->access_type), (void *)this_frame); }
pr_err("\n");
/* Print information about the racing accesses. */ if (other_info) { pr_err("%s to 0x%px of %zu bytes by %s on cpu %i:\n", get_access_type(other_info->ai.access_type), other_info->ai.ptr, other_info->ai.size, get_thread_desc(other_info->ai.task_pid), other_info->ai.cpu_id);
/* Print the other thread's stack trace. */ print_stack_trace(other_info->stack_entries + other_skipnr, other_info->num_stack_entries - other_skipnr, other_reordered_to); if (IS_ENABLED(CONFIG_KCSAN_VERBOSE)) print_verbose_info(other_info->task);
pr_err("\n"); pr_err("%s to 0x%px of %zu bytes by %s on cpu %i:\n", get_access_type(ai->access_type), ai->ptr, ai->size, get_thread_desc(ai->task_pid), ai->cpu_id); } else { pr_err("race at unknown origin, with %s to 0x%px of %zu bytes by %s on cpu %i:\n", get_access_type(ai->access_type), ai->ptr, ai->size, get_thread_desc(ai->task_pid), ai->cpu_id); } /* Print stack trace of this thread. */ print_stack_trace(stack_entries + skipnr, num_stack_entries - skipnr, reordered_to); if (IS_ENABLED(CONFIG_KCSAN_VERBOSE)) print_verbose_info(current);
/* Print observed value change. */ if (ai->size <= 8) { int hex_len = ai->size * 2; u64 diff = old ^ new;
if (mask) diff &= mask; if (diff) { pr_err("\n"); pr_err("value changed: 0x%0*llx -> 0x%0*llx\n", hex_len, old, hex_len, new); if (mask) { pr_err(" bits changed: 0x%0*llx with mask 0x%0*llx\n", hex_len, diff, hex_len, mask); } } }
/* Print report footer. */ pr_err("\n"); pr_err("Reported by Kernel Concurrency Sanitizer on:\n"); dump_stack_print_info(KERN_DEFAULT); pr_err("==================================================================\n");
check_panic_on_warn("KCSAN");}
static void release_report(unsigned long *flags, struct other_info *other_info) __releases(&report_lock){ /* * Use size to denote valid/invalid, since KCSAN entirely ignores * 0-sized accesses. */ other_info->ai.size = 0; raw_spin_unlock_irqrestore(&report_lock, *flags);}
/* * Sets @other_info->task and awaits consumption of @other_info. */static void set_other_info_task_blocking(unsigned long *flags, const struct access_info *ai, struct other_info *other_info) __must_hold(&report_lock){ /* * We may be instrumenting a code-path where current->state is already * something other than TASK_RUNNING. */ const bool is_running = task_is_running(current); /* * To avoid deadlock in case we are in an interrupt here and this is a * race with a task on the same CPU (KCSAN_INTERRUPT_WATCHER), provide a * timeout to ensure this works in all contexts. * * Await approximately the worst case delay of the reporting thread (if * we are not interrupted). */ int timeout = max(kcsan_udelay_task, kcsan_udelay_interrupt);
other_info->task = current; do { if (is_running) { /* * Let lockdep know the real task is sleeping, to print * the held locks (recall we turned lockdep off, so * locking/unlocking @report_lock won't be recorded). */ set_current_state(TASK_UNINTERRUPTIBLE); } raw_spin_unlock_irqrestore(&report_lock, *flags); /* * We cannot call schedule() since we also cannot reliably * determine if sleeping here is permitted -- see in_atomic(). */
udelay(1); raw_spin_lock_irqsave(&report_lock, *flags); if (timeout-- < 0) { /* * Abort. Reset @other_info->task to NULL, since it * appears the other thread is still going to consume * it. It will result in no verbose info printed for * this task. */ other_info->task = NULL; break; } /* * If invalid, or @ptr nor @current matches, then @other_info * has been consumed and we may continue. If not, retry. */ } while (other_info->ai.size && other_info->ai.ptr == ai->ptr && other_info->task == current); if (is_running) set_current_state(TASK_RUNNING);}
/* Populate @other_info; requires that the provided @other_info not in use. */static void prepare_report_producer(unsigned long *flags, const struct access_info *ai, struct other_info *other_info) __must_not_hold(&report_lock){ raw_spin_lock_irqsave(&report_lock, *flags);
/* * The same @other_infos entry cannot be used concurrently, because * there is a one-to-one mapping to watchpoint slots (@watchpoints in * core.c), and a watchpoint is only released for reuse after reporting * is done by the consumer of @other_info. Therefore, it is impossible * for another concurrent prepare_report_producer() to set the same * @other_info, and are guaranteed exclusivity for the @other_infos * entry pointed to by @other_info. * * To check this property holds, size should never be non-zero here, * because every consumer of struct other_info resets size to 0 in * release_report(). */ WARN_ON(other_info->ai.size);
other_info->ai = *ai; other_info->num_stack_entries = stack_trace_save(other_info->stack_entries, NUM_STACK_ENTRIES, 2);
if (IS_ENABLED(CONFIG_KCSAN_VERBOSE)) set_other_info_task_blocking(flags, ai, other_info);
raw_spin_unlock_irqrestore(&report_lock, *flags);}
/* Awaits producer to fill @other_info and then returns. */static bool prepare_report_consumer(unsigned long *flags, const struct access_info *ai, struct other_info *other_info) __cond_acquires(true, &report_lock){
raw_spin_lock_irqsave(&report_lock, *flags); while (!other_info->ai.size) { /* Await valid @other_info. */ raw_spin_unlock_irqrestore(&report_lock, *flags); cpu_relax(); raw_spin_lock_irqsave(&report_lock, *flags); }
/* Should always have a matching access based on watchpoint encoding. */ if (WARN_ON(!matching_access((unsigned long)other_info->ai.ptr & WATCHPOINT_ADDR_MASK, other_info->ai.size, (unsigned long)ai->ptr & WATCHPOINT_ADDR_MASK, ai->size))) goto discard;
if (!matching_access((unsigned long)other_info->ai.ptr, other_info->ai.size, (unsigned long)ai->ptr, ai->size)) { /* * If the actual accesses to not match, this was a false * positive due to watchpoint encoding. */ atomic_long_inc(&kcsan_counters[KCSAN_COUNTER_ENCODING_FALSE_POSITIVES]); goto discard; }
return true;
discard: release_report(flags, other_info); return false;}
static struct access_info prepare_access_info(const volatile void *ptr, size_t size, int access_type, unsigned long ip){ return (struct access_info) { .ptr = ptr, .size = size, .access_type = access_type, .task_pid = in_task() ? task_pid_nr(current) : -1, .cpu_id = raw_smp_processor_id(), /* Only replace stack entry with @ip if scoped access. */ .ip = (access_type & KCSAN_ACCESS_SCOPED) ? ip : 0, };}
void kcsan_report_set_info(const volatile void *ptr, size_t size, int access_type, unsigned long ip, int watchpoint_idx){ const struct access_info ai = prepare_access_info(ptr, size, access_type, ip); unsigned long flags;
kcsan_disable_current(); lockdep_off(); /* See kcsan_report_known_origin(). */
prepare_report_producer(&flags, &ai, &other_infos[watchpoint_idx]);
lockdep_on(); kcsan_enable_current();}
void kcsan_report_known_origin(const volatile void *ptr, size_t size, int access_type, unsigned long ip, enum kcsan_value_change value_change, int watchpoint_idx, u64 old, u64 new, u64 mask){ const struct access_info ai = prepare_access_info(ptr, size, access_type, ip); struct other_info *other_info = &other_infos[watchpoint_idx]; unsigned long flags = 0;
kcsan_disable_current(); /* * Because we may generate reports when we're in scheduler code, the use * of printk() could deadlock. Until such time that all printing code * called in print_report() is scheduler-safe, accept the risk, and just * get our message out. As such, also disable lockdep to hide the * warning, and avoid disabling lockdep for the rest of the kernel. */ lockdep_off();
if (!prepare_report_consumer(&flags, &ai, other_info)) goto out; /* * Never report if value_change is FALSE, only when it is * either TRUE or MAYBE. In case of MAYBE, further filtering may * be done once we know the full stack trace in print_report(). */ if (value_change != KCSAN_VALUE_CHANGE_FALSE) print_report(value_change, &ai, other_info, old, new, mask);
release_report(&flags, other_info);out: lockdep_on(); kcsan_enable_current();}
void kcsan_report_unknown_origin(const volatile void *ptr, size_t size, int access_type, unsigned long ip, u64 old, u64 new, u64 mask){ const struct access_info ai = prepare_access_info(ptr, size, access_type, ip); unsigned long flags;
kcsan_disable_current(); lockdep_off(); /* See kcsan_report_known_origin(). */
raw_spin_lock_irqsave(&report_lock, flags); print_report(KCSAN_VALUE_CHANGE_TRUE, &ai, NULL, old, new, mask); raw_spin_unlock_irqrestore(&report_lock, flags);
lockdep_on(); kcsan_enable_current();}