diff options
| author | Dmitry Vyukov <dvyukov@google.com> | 2018-02-07 13:46:35 +0100 |
|---|---|---|
| committer | Dmitry Vyukov <dvyukov@google.com> | 2018-02-07 13:46:35 +0100 |
| commit | d2473bc545f3c562e5876a07e7bf7785bd48e472 (patch) | |
| tree | 4d27d10bbfc182d21456c29bd987bceab5b7dd5b | |
| parent | f34079dbcf82bb019d7bd1845be743d6dbc4748d (diff) | |
pkg/report: improve guilty frame extraction
1. Make extractStackFrame more picky about stray frames.
This fixes some TODO's in tests where we matched completley
unrelated frames printed by another task.
2. Extract KASAN guilty frame from report header
if the frame should not be skipped (e.g. not __lock_acquire).
This makes parsing more tolerant to corrupted reports.
| -rw-r--r-- | pkg/report/linux.go | 172 | ||||
| -rw-r--r-- | pkg/report/report.go | 100 | ||||
| -rw-r--r-- | pkg/report/testdata/linux/report/196 | 1 | ||||
| -rw-r--r-- | pkg/report/testdata/linux/report/197 | 1 | ||||
| -rw-r--r-- | pkg/report/testdata/linux/report/198 | 3 | ||||
| -rw-r--r-- | pkg/report/testdata/linux/report/199 | 3 | ||||
| -rw-r--r-- | pkg/report/testdata/linux/report/200 | 3 |
7 files changed, 181 insertions, 102 deletions
diff --git a/pkg/report/linux.go b/pkg/report/linux.go index 833828ee8..fcc390907 100644 --- a/pkg/report/linux.go +++ b/pkg/report/linux.go @@ -416,7 +416,8 @@ func (ctx *linux) isCorrupted(title string, report []byte, format oopsFormat) bo return true } // Check if the report contains stack trace. - if !format.noStackTrace && !bytes.Contains(report, []byte("Call Trace")) && !bytes.Contains(report, []byte("backtrace")) { + if !format.noStackTrace && !bytes.Contains(report, []byte("Call Trace")) && + !bytes.Contains(report, []byte("backtrace")) { return true } // Check for common title corruptions. @@ -486,12 +487,12 @@ var linuxStackKeywords = []*regexp.Regexp{ regexp.MustCompile(`[^k] backtrace:`), } +var linuxRipFrame = compile("IP: (?:(?:[0-9]+:)?(?:{{PC}} +){0,2}{{FUNC}}|[0-9]+:0x[0-9a-f]+)") + var linuxStackParams = &stackParams{ stackStartRes: linuxStackKeywords, frameRes: []*regexp.Regexp{ compile("^ +(?:{{PC}} )?{{FUNC}}"), - compile("IP: (?:{{PC}} +)?{{FUNC}}"), - compile("IP: [0-9]+:(?:{{PC}} +{{PC}} +)?{{FUNC}}"), }, skipPatterns: []string{ "__sanitizer", @@ -532,11 +533,20 @@ var linuxStackParams = &stackParams{ }, } -var linuxWarningStackStart = []string{ - // In newer kernels WARNING traps and actual stack starts after invalid_op frame, - // older kernels does not have that and just print stack. - " invalid_op", - "Call Trace:", +func warningStackFmt(skip ...string) *stackFmt { + return &stackFmt{ + // In newer kernels WARNING traps and actual stack starts after invalid_op frame, + // older kernels just print stack. + parts: []*regexp.Regexp{ + linuxRipFrame, + parseStackTrace, + }, + parts2: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + skip: skip, + } } var linuxOopses = []*oops{ @@ -547,7 +557,11 @@ var linuxOopses = []*oops{ title: compile("BUG: KASAN: ([a-z\\-]+) in {{FUNC}}(?:.*\\n)+?.*(Read|Write) of size (?:[0-9]+)"), fmt: "KASAN: %[1]v %[3]v in %[4]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, + parts: []*regexp.Regexp{ + compile("BUG: KASAN: (?:[a-z\\-]+) in {{FUNC}}"), + compile("Call Trace:"), + parseStackTrace, + }, }, }, { @@ -566,12 +580,24 @@ var linuxOopses = []*oops{ { title: compile("BUG: unable to handle kernel paging request"), fmt: "BUG: unable to handle kernel paging request in %[1]v", - stack: &stackFmt{}, + stack: &stackFmt{ + parts: []*regexp.Regexp{ + linuxRipFrame, + compile("Call Trace:"), + parseStackTrace, + }, + }, }, { title: compile("BUG: unable to handle kernel NULL pointer dereference"), fmt: "BUG: unable to handle kernel NULL pointer dereference in %[1]v", - stack: &stackFmt{}, + stack: &stackFmt{ + parts: []*regexp.Regexp{ + linuxRipFrame, + compile("Call Trace:"), + parseStackTrace, + }, + }, }, { // Sometimes with such BUG failures, the second part of the header doesn't get printed @@ -584,15 +610,21 @@ var linuxOopses = []*oops{ title: compile("BUG: spinlock (lockup suspected|already unlocked|recursion|bad magic|wrong owner|wrong CPU)"), fmt: "BUG: spinlock %[1]v in %[2]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, - skip: []string{"spin_"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + skip: []string{"spin_"}, }, }, { title: compile("BUG: soft lockup"), fmt: "BUG: soft lockup in %[1]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, }, }, { @@ -650,8 +682,11 @@ var linuxOopses = []*oops{ title: compile("BUG: using __this_cpu_([a-z_]+)\\(\\) in preemptible"), fmt: "BUG: using __this_cpu_%[1]v() in preemptible code in %[2]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, - skip: []string{"dump_stack", "preemption", "preempt"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + skip: []string{"dump_stack", "preemption", "preempt"}, }, }, { @@ -663,7 +698,10 @@ var linuxOopses = []*oops{ title: compile("BUG: memory leak"), fmt: "memory leak in %[1]v", stack: &stackFmt{ - start: []string{"backtrace:"}, + parts: []*regexp.Regexp{ + compile("backtrace:"), + parseStackTrace, + }, skip: []string{"kmemleak", "kmalloc", "kmem", "slab", "alloc", "create_object"}, }, @@ -682,59 +720,39 @@ var linuxOopses = []*oops{ { title: compile("WARNING: .*lib/debugobjects\\.c.* debug_print_object"), fmt: "WARNING: ODEBUG bug in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - // Skip all users of ODEBUG as well. - skip: []string{"debug_", "rcu", "hrtimer_", "timer_", - "work_", "percpu_", "kmem_", "slab_", "kfree"}, - }, + // Skip all users of ODEBUG as well. + stack: warningStackFmt("debug_", "rcu", "hrtimer_", "timer_", + "work_", "percpu_", "kmem_", "slab_", "kfree"), }, { title: compile("WARNING: .*mm/usercopy\\.c.* usercopy_warn"), fmt: "WARNING: bad usercopy in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - skip: []string{"usercopy", "__check"}, - }, + stack: warningStackFmt("usercopy", "__check"), }, { title: compile("WARNING: .*lib/kobject\\.c.* kobject_"), fmt: "WARNING: kobject bug in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - skip: []string{"kobject_"}, - }, + stack: warningStackFmt("kobject_"), }, { title: compile("WARNING: .*fs/proc/generic\\.c.* proc_register"), fmt: "WARNING: proc registration bug in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - skip: []string{"proc_"}, - }, + stack: warningStackFmt("proc_"), }, { title: compile("WARNING: .*lib/refcount\\.c.* refcount_"), fmt: "WARNING: refcount bug in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - skip: []string{"refcount"}, - }, + stack: warningStackFmt("refcount"), }, { title: compile("WARNING: .*kernel/locking/lockdep\\.c.*lock_"), fmt: "WARNING: locking bug in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - }, + stack: warningStackFmt(), }, { title: compile("WARNING: .*mm/slab_common\\.c.* kmalloc_slab"), fmt: "WARNING: kmalloc bug in %[1]v", - stack: &stackFmt{ - start: linuxWarningStackStart, - skip: []string{"kmalloc", "slab"}, - }, + stack: warningStackFmt("kmalloc", "slab"), }, { title: compile("WARNING: .* at {{SRC}} {{FUNC}}"), @@ -770,8 +788,11 @@ var linuxOopses = []*oops{ report: compile("WARNING: suspicious RCU usage(?:.*\n)+?.*?{{SRC}}"), fmt: "WARNING: suspicious RCU usage in %[2]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, - skip: []string{"rcu"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + skip: []string{"rcu"}, }, }, { @@ -831,24 +852,33 @@ var linuxOopses = []*oops{ title: compile("INFO: rcu_(?:preempt|sched|bh) detected(?: expedited)? stall"), fmt: "INFO: rcu detected stall in %[1]v", stack: &stackFmt{ - start: []string{" apic_timer_interrupt"}, - skip: []string{"apic_timer_interrupt", "rcu"}, + parts: []*regexp.Regexp{ + linuxRipFrame, + parseStackTrace, + }, + skip: []string{"apic_timer_interrupt", "rcu"}, }, }, { title: compile("INFO: rcu_(?:preempt|sched|bh) self-detected stall"), fmt: "INFO: rcu detected stall in %[1]v", stack: &stackFmt{ - start: []string{" apic_timer_interrupt"}, - skip: []string{"apic_timer_interrupt", "rcu"}, + parts: []*regexp.Regexp{ + linuxRipFrame, + parseStackTrace, + }, + skip: []string{"apic_timer_interrupt", "rcu"}, }, }, { title: compile("INFO: trying to register non-static key"), fmt: "INFO: trying to register non-static key in %[1]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, - skip: []string{"stack", "lock", "IRQ"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + skip: []string{"stack", "lock", "IRQ"}, }, }, { @@ -856,15 +886,21 @@ var linuxOopses = []*oops{ report: compile("INFO: suspicious RCU usage(?:.*\n)+?.*?:{{SRC}}"), fmt: "INFO: suspicious RCU usage in %[2]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, - skip: []string{"rcu"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + skip: []string{"rcu"}, }, }, { title: compile("INFO: task .* blocked for more than [0-9]+ seconds"), fmt: "INFO: task hung in %[1]v", stack: &stackFmt{ - start: []string{"Call Trace:"}, + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, skip: []string{"sched", "_lock", "completion", "kthread", "wait", "synchronize"}, }, @@ -900,7 +936,13 @@ var linuxOopses = []*oops{ { title: compile("general protection fault:"), fmt: "general protection fault in %[1]v", - stack: &stackFmt{}, + stack: &stackFmt{ + parts: []*regexp.Regexp{ + linuxRipFrame, + compile("Call Trace:"), + parseStackTrace, + }, + }, }, }, []*regexp.Regexp{}, @@ -943,12 +985,22 @@ var linuxOopses = []*oops{ { title: compile("kernel BUG at mm/usercopy.c"), fmt: "BUG: bad usercopy in %[1]v", - stack: &stackFmt{start: []string{"Call Trace:"}}, + stack: &stackFmt{ + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + }, }, { title: compile("kernel BUG at lib/list_debug.c"), fmt: "BUG: corrupted list in %[1]v", - stack: &stackFmt{start: []string{"Call Trace:"}}, + stack: &stackFmt{ + parts: []*regexp.Regexp{ + compile("Call Trace:"), + parseStackTrace, + }, + }, }, }, []*regexp.Regexp{}, diff --git a/pkg/report/report.go b/pkg/report/report.go index 399b497bc..89d780b4b 100644 --- a/pkg/report/report.go +++ b/pkg/report/report.go @@ -93,13 +93,22 @@ type oopsFormat struct { } type stackFmt struct { - // If start is empty, starting matching stack trace from the beginning of the report. - // Otherwise start matching trace after first start match. - start []string + // parts describe how guilty stack frame must be extracted from the report. + // parts are matched consecutively potentially capturing frames. + // parts can be of 3 types: + // - non-capturing regexp, matched against report and advances current position + // - capturing regexp, same as above, but also yields a frame + // - special value parseStackTrace means that a stack trace must be parsed + // starting from current position + parts []*regexp.Regexp + // If parts2 is present it is tried when parts matching fails. + parts2 []*regexp.Regexp // Skip these functions in stack traces (matched as substring). skip []string } +var parseStackTrace *regexp.Regexp + func compile(re string) *regexp.Regexp { re = strings.Replace(re, "{{ADDR}}", "0x[0-9a-f]+", -1) re = strings.Replace(re, "{{PC}}", "\\[\\<[0-9a-f]+\\>\\]", -1) @@ -175,8 +184,8 @@ func extractDescription(output []byte, oops *oops, params *stackParams) ( args = append(args, string(output[match[i]:match[i+1]])) } if f.stack != nil { - frame, ok := extractStackFrame(params, f.stack, output[match[0]:]) - if !ok { + frame := extractStackFrame(params, f.stack, output[match[0]:]) + if frame == "" { continue } args = append(args, frame) @@ -234,43 +243,66 @@ func startReportPrefix(output []byte, prefixes []string) []byte { return nil } -func extractStackFrame(params *stackParams, stack *stackFmt, output []byte) (frame string, ok bool) { - output = startReportPrefix(output, stack.start) - if len(output) == 0 { - return - } - stackTraces := 0 +func extractStackFrame(params *stackParams, stack *stackFmt, output []byte) string { skip := append([]string{}, params.skipPatterns...) skip = append(skip, stack.skip...) - skipRe := regexp.MustCompile(strings.Join(skip, "|")) - for s := bufio.NewScanner(bytes.NewReader(output)); s.Scan(); { - ln := s.Bytes() - for _, re := range params.stackStartRes { - if re.Match(ln) { - stackTraces++ - if stackTraces > 1 { - return "", false + var skipRe *regexp.Regexp + if len(skip) != 0 { + skipRe = regexp.MustCompile(strings.Join(skip, "|")) + } + frame := extractStackFrameImpl(params, output, skipRe, stack.parts) + if frame != "" || len(stack.parts2) == 0 { + return frame + } + return extractStackFrameImpl(params, output, skipRe, stack.parts2) +} + +func extractStackFrameImpl(params *stackParams, output []byte, skipRe *regexp.Regexp, + parts []*regexp.Regexp) string { + s := bufio.NewScanner(bytes.NewReader(output)) +nextPart: + for _, part := range parts { + if part == parseStackTrace { + for s.Scan() { + ln := s.Bytes() + for _, re := range params.stackStartRes { + if re.Match(ln) { + continue nextPart + } + } + var match []int + for _, re := range params.frameRes { + match = re.FindSubmatchIndex(ln) + if match != nil { + break + } + } + if match == nil { + continue + } + frame := ln[match[2]:match[3]] + if skipRe == nil || !skipRe.Match(frame) { + return string(frame) } - break } - } - var match []int - for _, re := range params.frameRes { - match = re.FindSubmatchIndex(ln) - if match != nil { + } else { + for s.Scan() { + ln := s.Bytes() + match := part.FindSubmatchIndex(ln) + if match == nil { + continue + } + if len(match) == 4 && match[2] != -1 { + frame := ln[match[2]:match[3]] + if skipRe == nil || !skipRe.Match(frame) { + return string(frame) + } + } break } } - if match == nil { - continue - } - frame = string(ln[match[2]:match[3]]) - if len(skip) != 0 && skipRe.MatchString(frame) { - continue - } - return frame, true } - return "", false + return "" } // replace replaces [start:end] in where with what, inplace. diff --git a/pkg/report/testdata/linux/report/196 b/pkg/report/testdata/linux/report/196 index dd3ae765d..042889bc3 100644 --- a/pkg/report/testdata/linux/report/196 +++ b/pkg/report/testdata/linux/report/196 @@ -1,5 +1,4 @@ TITLE: KASAN: wild-memory-access Read in sg_read -CORRUPTED: Y [ 67.633749] ================================================================== [ 67.633767] BUG: KASAN: wild-memory-access in sg_read+0xe5c/0x1440 diff --git a/pkg/report/testdata/linux/report/197 b/pkg/report/testdata/linux/report/197 index 150ef6edb..78ae656db 100644 --- a/pkg/report/testdata/linux/report/197 +++ b/pkg/report/testdata/linux/report/197 @@ -1,5 +1,4 @@ TITLE: KASAN: global-out-of-bounds Read in show_timer -CORRUPTED: Y [ 66.768767] ================================================================== [ 66.776196] BUG: KASAN: global-out-of-bounds in show_timer+0x27a/0x2b0 at addr ffffffff82cda558 diff --git a/pkg/report/testdata/linux/report/198 b/pkg/report/testdata/linux/report/198 index 7c3f1e568..6373ecbcd 100644 --- a/pkg/report/testdata/linux/report/198 +++ b/pkg/report/testdata/linux/report/198 @@ -1,5 +1,4 @@ -# TODO: must be "in ip6t_do_table" -TITLE: general protection fault in __vmalloc_node_range +TITLE: general protection fault in ip6t_do_table [ 159.247590] syz-executor6: vmalloc: allocation failure: 8589934588 bytes, mode:0x14080c0(GFP_KERNEL|__GFP_ZERO), nodemask=(null) [ 159.259380] syz-executor6 cpuset=/ mems_allowed=0 diff --git a/pkg/report/testdata/linux/report/199 b/pkg/report/testdata/linux/report/199 index ea2aa11a8..1c606e5f1 100644 --- a/pkg/report/testdata/linux/report/199 +++ b/pkg/report/testdata/linux/report/199 @@ -1,5 +1,4 @@ -# TODO: must be "in iov_iter_advance". -TITLE: KASAN: stack-out-of-bounds Read in warn_alloc_failed +TITLE: KASAN: stack-out-of-bounds Read in iov_iter_advance [ 81.174109] ================================================================== [ 81.174125] BUG: KASAN: stack-out-of-bounds in iov_iter_advance+0x4c0/0x4f0 at addr ffff8801ca657d38 diff --git a/pkg/report/testdata/linux/report/200 b/pkg/report/testdata/linux/report/200 index 2187f2f03..c30a296e8 100644 --- a/pkg/report/testdata/linux/report/200 +++ b/pkg/report/testdata/linux/report/200 @@ -1,5 +1,4 @@ -# TODO: must be "in ip6t_do_table" -TITLE: general protection fault in should_fail +TITLE: general protection fault in ip6t_do_table [ 73.452724] FAULT_INJECTION: forcing a failure. [ 73.452724] name failslab, interval 1, probability 0, space 0, times 0 |
