Closed Bug 828324 Opened 12 years ago Closed 12 years ago

mozcrash output is not TBPL-starrable & the PROCESS-CRASH/stackwalk lines can end up interleaved

Categories

(Testing :: Mozbase, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: emorley, Assigned: emorley)

References

(Blocks 1 open bug)

Details

(Keywords: sheriffing-P1)

Attachments

(1 file)

With bug 813132 in production, I've just seen: { FIRE PROC: ' "MOZ_CRASHREPORTER_SHUTDOWN=1,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1" org.mozilla.fennec -profile /mnt/sdcard/tests/profile -tp file:/mnt/sdcard/tests/svg.manifest -tpnoisy -tpcycles 3 -tppagecycles 1 -tpdelay 1000' getting files in '/mnt/sdcard/tests/profile/minidumps/' Crash dump filename: /tmp/tmpfd1iC9/4d377dbf-7a54-d335-3649b455-23409abd.dmp Operating system: Android 0.0.0 Linux 3.2.0+ #2 SMP PREEMPT Thu Nov 29 08:06:57 EST 2012 armv7l pandaboard/pandaboard/pandaboard:4.0.4/IMM76I/5:eng/test-keys CPU: arm 0 CPUs Crash reason: SIGSEGV Crash address: 0xbec937a0 Thread 11 (crashed) 0 libnss3.so!nssCertificate_Destroy [certificate.c : 102 + 0x0] r4 = 0xbec9374c r5 = 0x629fb680 r6 = 0x00000000 r7 = 0x5d6ff90c r8 = 0x604aa6d9 r9 = 0x64860400 r10 = 0x00000008 fp = 0x00000010 ... ... ... 32 dalvik-heap (deleted) + 0x7d665e sp = 0x5d6ffcbc pc = 0x4135f660 Found by: stack scanning 33 libdvm.so + 0x8fb77 sp = 0x5d6ffcc8 pc = 0x409a6b79 Found by: stack scanning 34 dalvik-heap (deleted) + 0x7e2efe sp = 0x5d6ffccc pc = 0x4136bf00 Found by: stack scanning 35 data@app@orgmozcrash ERROR | PROCESS-CRASH | ttest.py | application crashed [@ nssCertificate_Destroy] .mozilla.fennec-1.apk@classes.dex + 0x178244 sp = 0x5d6ffcd0 pc = 0x5ba77246 Found by: stack scanning } This is presumably due to mixing print and log.error, and logging being bufferd. 148 log.error("PROCESS-CRASH | %s | application crashed [%s]", test_name, top_frame) 149 print '\n'.join(stackwalk_output) at https://github.com/mozilla/mozbase/blob/492a08a51e2c2f6b9911cca45094e4291ee162c4/mozcrash/mozcrash/mozcrash.py#L148 We should just make this both print, and then we'd also avoid the "ERROR | " breaking TBPL parsing (yeah I can adjust the TBPL regexes for these, but it still bloats the annotated summary output to the point where it is more likely to wrap onto another line).
Blocks: 778688, 827446
Keywords: sheriffing-P1
Attached patch Patch v1 (deleted) — Splinter Review
Assignee: nobody → emorley
Status: NEW → ASSIGNED
Attachment #699982 - Flags: review?(jmaher)
Comment on attachment 699982 [details] [diff] [review] Patch v1 Review of attachment 699982 [details] [diff] [review]: ----------------------------------------------------------------- should we remove the rest of the log.*() calls in mozcrash.py?
Attachment #699982 - Flags: review?(jmaher) → review+
(In reply to Joel Maher (:jmaher) from comment #3) > should we remove the rest of the log.*() calls in mozcrash.py? Maybe... Ted?
Is this only an issue with log.error? (Is log.error going to stderr and the rest to stdout?) This is the first time I've seen something like that on non-Windows. I thought everything else was line-buffered?
It might be, yeah. Either way, I think print is the correct decision here for now. I've landed bug 829092 in the meantime so TBPL matches against these lines, even with the "mozcrash ERROR |" prefix - but that still doesn't fully fix things, since TBPL expects (since every other suite uses this format): "failure-type | test-name | message" ...so the extra pipe breaks it. If we decide in the future that (a) we've happy to remove the prefix from mozlog, and (b) we're going to debug the interleaving here - then we can always switch this back to log.error
Depends on: 829332
No longer depends on: 829332
Depends on: 829334
philor/Ryan, once the dependencies are fixed, will mean the talos crashes (hopefully) get a starable crash signature :-)
Summary: mozcrash stackwalk output can end up interleaved with the PROCESS-CRASH line → mozcrash output is not TBPL-starrable & the PROCESS-CRASH/stackwalk lines can end up interleaved
Working fine on inbound :-)
Status: ASSIGNED → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
This can (and should) be fixed from logging. I'm not entirely sure how, but see http://docs.python.org/2/library/logging.handlers.html .
Blocks: 926407
(In reply to Jeff Hammel [:jhammel] from comment #11) > This can (and should) be fixed from logging. I'm not entirely sure how, but > see http://docs.python.org/2/library/logging.handlers.html . Broken out to bug 926407.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: