crash-reporter: Generate kernel crash signatures for server-side grouping of similar crashes

crash-reporter: Generate kernel crash signatures for server-side grouping of similar crashes

BUG=5868
TEST=KernelCrash, UserCrash, CrashSender, unittests, and manual inspection of sent report.

Change-Id: I31991895c9ac719ac1832d588ae3360500ef0c26

Committed: http://chrome-svn/viewvc/chromeos?view=rev&revision=f326db8

[kmixter1, 2010-10-22 03:26:41]

hughd, please take a look at ComputeKernelStackSignature in kernel_collector.cc.

[petkov, 2010-10-22 18:44:21]

A few comments, nothing critical. So LGTM.

http://codereview.chromium.org/4018008/diff/3001/4003
File crash_collector.h (right):

http://codereview.chromium.org/4018008/diff/3001/4003#newcode92
crash_collector.h:92: // calling WriteCrashMetaData.
Mention that key may not contain = or \n, and value may not contain \n.

http://codereview.chromium.org/4018008/diff/3001/4007
File kernel_collector.cc (right):

http://codereview.chromium.org/4018008/diff/3001/4007#newcode84
kernel_collector.cc:84: hash = hash * 16127 + input[i];
maybe add a comment why this particular way of hashing...

http://codereview.chromium.org/4018008/diff/3001/4007#newcode88
kernel_collector.cc:88: bool KernelCollector::ComputeKernelStackSignature(
This routine may become a bit more readable if you split it.

http://codereview.chromium.org/4018008/diff/3001/4007#newcode118
kernel_collector.cc:118: input.set(kernel_dump.c_str(), kernel_dump.length());
kernel_dump.data()

http://codereview.chromium.org/4018008/diff/3001/4007#newcode135
kernel_collector.cc:135: input.set(kernel_dump.c_str(), kernel_dump.length());
kernel_dump.data()

http://codereview.chromium.org/4018008/diff/3001/4007#newcode165
kernel_collector.cc:165: continue;
this isn't a break for debugging purposes?

[hughd, 2010-10-23 03:13:44]

[I just wrote my comments in the review box, and it kindly ended up
crashing with "Invalid XSRF token" when I went to publish, losing
them.  Let's try gmail...]

It looks pretty good, and you may fairly argue that any classification
of kcrashes is progress, never mind refinements which can be added
later; but I cannot quite say LGTM yet myself, for this reason or two.

The "EIP:" matching is going to miss those cases where panic("Some
string") is called directly from somewhere in the kernel which did not
already show a stacktrace: those would show "Kernel panic - not
syncing: %s\n", where the %s is a good distinguisher passed in from
the callsite; but no "EIP:".

In other cases (when panic_on_oops is set, as we have), notably
"kernel BUG" and "BUG: unable to handle" (oops), there is an original
stacktrace with "EIP:" (and also "EIP is at") first, then the
panic("Fatal exception") stacktrace as an afterthought.

I think your kcrash parsing would be better to assume those two cases,
panic stacktrace alone, and panic stacktrace appended to original
stracktrace, rather than the "5 second window" technique which you use
to try and make sense of them all - I may be wrong, but as it stands,
you seemed to be in danger of mixing lines of a stacktrace from an
unrelated WARNING a few seconds earlier with the stacktrace of the
real dump with the stacktrace of the panic.  Not the end of the world
when you're just trying to make up a signature, but not very
satisfactory.

It would be nice to say that if you have a good "kernel BUG" or "BUG:
unable to handle" immediately before the "Kernel panic", then ignore
"Kernel panic" onwards.  However, at least in the (not very
interesting!) /proc/breakme case, the original stacktrace often
consists _solely_ of "? " lines, with the panic stacktrace doing a
much better job.  Until I fix 6073 (no prediction when), it's a
messier task for you.

[kmixter1, 2010-10-26 18:28:24]

PTAL. Responded to all comments.

Hugh: I did a substantial rework of the parsing code including adding panic
support, only taking the last stack, and only considering EIP lines within a
small time window of the last stack.  I also removed the stack trace truncation
to 10 frames.  Below are two example stack traces that now have different
signatures because I don't truncate.


<0>[  342.841135] EIP: [<b8985c15>] ieee80211_stop_tx_ba_session+0xa3/0xb5
[mac80211] SS:ESP 0068:9a1c1f24
<0>[  342.841135] CR2: 00000000ff8592e6
<4>[  342.841135] ---[ end trace b1cb563de7c7229c ]---
<0>[  342.841135] Kernel panic - not syncing: Fatal exception in interrupt
<4>[  342.841135] Pid: 10377, comm: sed Tainted: G      D    2.6.32.23+drm33.10
#1
<4>[  342.841135] Call Trace:
<4>[  342.841135]  [<7937a5df>] ? printk+0x14/0x1d
<4>[  342.841135]  [<7937a525>] panic+0x3e/0xe4
<4>[  342.841135]  [<7937cb2d>] oops_end+0x73/0x81
<4>[  342.841135]  [<7901b260>] no_context+0x10d/0x117
<4>[  342.841135]  [<7901b354>] __bad_area_nosemaphore+0xea/0xf2
<4>[  342.841135]  [<7901b36e>] bad_area_nosemaphore+0x12/0x15
<4>[  342.841135]  [<7937db87>] do_page_fault+0x12b/0x28c
<4>[  342.841135]  [<79020056>] ? sched_slice+0x73/0x9a
<4>[  342.841135]  [<7937da5c>] ? do_page_fault+0x0/0x28c
<4>[  342.841135]  [<7937c256>] error_code+0x66/0x6c
<4>[  342.841135]  [<b8985bf6>] ? ieee80211_stop_tx_ba_session+0x84/0xb5
[mac80211]
<4>[  342.841135]  [<7901007b>] ? mtrr_type_lookup+0x1ff/0x215
<4>[  342.841135]  [<790400d8>] ? ftrace_raw_event_workqueue_creation+0x52/0x98
<4>[  342.841135]  [<7937da5c>] ? do_page_fault+0x0/0x28c
<4>[  342.841135]  [<b8985c15>] ? ieee80211_stop_tx_ba_session+0xa3/0xb5
[mac80211]
<4>[  342.841135]  [<79039d16>] run_timer_softirq+0x165/0x1e6
<4>[  342.841135]  [<790340af>] __do_softirq+0xa6/0x143
<4>[  342.841135]  [<79034177>] do_softirq+0x2b/0x30
<4>[  342.841135]  [<79034253>] irq_exit+0x2e/0x61
<4>[  342.841135]  [<79014453>] smp_apic_timer_interrupt+0x6d/0x7b
<4>[  342.841135]  [<790034f6>] apic_timer_interrupt+0x2a/0x30
<4>[  342.841135]  [<7937007b>] ? quirk_via_cx700_pci_parking_caching+0x84/0xbb
<4>[  342.841135]  [<79370000>] ? quirk_via_cx700_pci_parking_caching+0x9/0xbb


vs



<0>[ 5294.972702] EIP: [<c0961cea>] ieee80211_stop_tx_ba_session+0xa4/0xb6
[mac80211] SS:ESP 0068:8146be90
<0>[ 5294.972729] CR2: 000000003536347c
<4>[ 5294.972739] ---[ end trace e05320d81a808477 ]---
<0>[ 5294.972746] Kernel panic - not syncing: Fatal exception in interrupt
<4>[ 5294.972758] Pid: 0, comm: swapper Tainted: G      D W  2.6.32.23+drm33.10
#1
<4>[ 5294.972766] Call Trace:
<4>[ 5294.972778]  [<8133f71d>] ? printk+0x14/0x17
<4>[ 5294.972791]  [<8133f663>] panic+0x3e/0xe4
<4>[ 5294.972803]  [<81005dcc>] oops_end+0x73/0x81
<4>[ 5294.972816]  [<81019dd4>] no_context+0x13c/0x146
<4>[ 5294.972830]  [<81014a01>] ? lapic_next_event+0x14/0x18
<4>[ 5294.972843]  [<81019ec3>] __bad_area_nosemaphore+0xe5/0xed
<4>[ 5294.972857]  [<81019edd>] bad_area_nosemaphore+0x12/0x15
<4>[ 5294.972869]  [<8101a0f7>] do_page_fault+0xff/0x23c
<4>[ 5294.972882]  [<81019ff8>] ? do_page_fault+0x0/0x23c
<4>[ 5294.972894]  [<81341453>] error_code+0x73/0x78
<4>[ 5294.972916]  [<c0961ccb>] ? ieee80211_stop_tx_ba_session+0x85/0xb6
[mac80211]
<4>[ 5294.972939]  [<c0961cea>] ? ieee80211_stop_tx_ba_session+0xa4/0xb6
[mac80211]
<4>[ 5294.972953]  [<81037693>] run_timer_softirq+0x166/0x1e7
<4>[ 5294.972967]  [<810319e8>] __do_softirq+0xa7/0x144
<4>[ 5294.972979]  [<81031ab0>] do_softirq+0x2b/0x30
<4>[ 5294.972991]  [<81031b8c>] irq_exit+0x2e/0x61
<4>[ 5294.973003]  [<810048f4>] do_IRQ+0x87/0x9b
<4>[ 5294.973041]  [<81003270>] common_interrupt+0x30/0x38
<4>[ 5294.973054]  [<8104007b>] ? sys_clock_getres+0x3b/0x8a
<4>[ 5294.973067]  [<811a3184>] ? acpi_idle_enter_bm+0x245/0x270
<4>[ 5294.973082]  [<81281373>] cpuidle_idle_call+0x6a/0xbb
<4>[ 5294.973093]  [<81001e03>] cpu_idle+0x93/0xac
<4>[ 5294.973106]  [<81333cc4>] rest_init+0x58/0x5a
<4>[ 5294.973118]  [<814b9827>] start_kernel+0x308/0x30d
<4>[ 5294.973131]  [<814b9097>] i386_start_kernel+0x97/0x9e

http://codereview.chromium.org/4018008/diff/3001/4003
File crash_collector.h (right):

http://codereview.chromium.org/4018008/diff/3001/4003#newcode92
crash_collector.h:92: // calling WriteCrashMetaData.
On 2010/10/22 18:44:21, petkov wrote:
> Mention that key may not contain = or \n, and value may not contain \n.
> 

Done.

http://codereview.chromium.org/4018008/diff/3001/4007
File kernel_collector.cc (right):

http://codereview.chromium.org/4018008/diff/3001/4007#newcode84
kernel_collector.cc:84: hash = hash * 16127 + input[i];
On 2010/10/22 18:44:21, petkov wrote:
> maybe add a comment why this particular way of hashing...
> 

Done.

http://codereview.chromium.org/4018008/diff/3001/4007#newcode88
kernel_collector.cc:88: bool KernelCollector::ComputeKernelStackSignature(
On 2010/10/22 18:44:21, petkov wrote:
> This routine may become a bit more readable if you split it.
> 

Done.

http://codereview.chromium.org/4018008/diff/3001/4007#newcode118
kernel_collector.cc:118: input.set(kernel_dump.c_str(), kernel_dump.length());
On 2010/10/22 18:44:21, petkov wrote:
> kernel_dump.data()
> 

Code removed in refactor.

http://codereview.chromium.org/4018008/diff/3001/4007#newcode135
kernel_collector.cc:135: input.set(kernel_dump.c_str(), kernel_dump.length());
On 2010/10/22 18:44:21, petkov wrote:
> kernel_dump.data()
> 
Code removed in refactor.

http://codereview.chromium.org/4018008/diff/3001/4007#newcode165
kernel_collector.cc:165: continue;
On 2010/10/22 18:44:21, petkov wrote:
> this isn't a break for debugging purposes?
> 
maximum stack depth removed at hugh's request.

[hughd, 2010-10-26 21:30:28]

LGTM (lengthier review comments gobbled up by "Invalid XSRF token", so delivered
orally to kmixter, and we agree LGTM).