Closed Bug 891840 Opened 12 years ago Closed 10 years ago

Intermittent test_meta_viewport6.html,test_pixel_lengths.html | application timed out after 330 seconds with no output and/or application crashed [@ nsPresContext::PreferenceChanged(char const*)][@ nsPresContext::AppUnitsPerDevPixel()]

Categories

(Core :: DOM: Core & HTML, defect)

Product:
Core
Component:
DOM: Core & HTML
Platform:
x86
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla36
Tracking Flags:
Tracking Status
firefox31 --- disabled
firefox32 --- disabled
firefox33 --- disabled
firefox34 --- disabled
firefox35 --- fixed
firefox36 --- fixed
firefox-esr24 --- unaffected
firefox-esr31 --- disabled
b2g-v1.3 --- disabled
b2g-v1.3T --- disabled
b2g-v1.4 --- disabled
b2g-v2.0 --- disabled
b2g-v2.0M --- disabled
b2g-v2.1 --- disabled
b2g-v2.2 --- fixed

People

(Reporter: cbook, Assigned: johns)

References

(
URL
)

Details

(Keywords: crash, intermittent-failure)

https://tbpl.mozilla.org/php/getParsedLog.php?id=25120138&tree=Mozilla-Inbound b2g_ics_armv7a_gecko_emulator_vm mozilla-inbound opt test mochitest-1 on 2013-07-10 04:47:47 PDT for push 0d65b1c05b2f slave: tst-linux64-ec2-135 05:33:35 WARNING - TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_meta_viewport6.html | application timed out after 330 seconds with no output 05:33:35 INFO - INFO | automation.py | Application ran for: 0:39:33.740034 05:33:35 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpILxctSpidlog 05:33:37 INFO - mozcrash INFO | Downloading symbols from: http://ftp.mozilla.org/pub/mozilla.org/b2g/tinderbox-builds/mozilla-inbound-ics_armv7a_gecko/1373451898/b2g-25.0a1.en-US.android-arm.crashreporter-symbols.zip 05:33:37 INFO - checking for crashes in '/data/local/tests/profile/minidumps' 05:33:37 INFO - Downloading symbols from: http://ftp.mozilla.org/pub/mozilla.org/b2g/tinderbox-builds/mozilla-inbound-ics_armv7a_gecko/1373451898/b2g-25.0a1.en-US.android-arm.crashreporter-symbols.zip 05:34:02 WARNING - PROCESS-CRASH | /tests/content/base/test/test_meta_viewport6.html | application crashed [@ nsPresContext::PreferenceChanged(char const*)] 05:34:02 INFO - Crash dump filename: /tmp/tmpa2tVRD/5e579ef0-cd7a-b841-6f368fc0-71fa0a22.dmp 05:34:02 INFO - Operating system: Android 05:34:02 INFO - 0.0.0 Linux 2.6.29-00294-g701690d #1 Mon May 20 22:43:07 CST 2013 armv7l Android/full/generic:4.0.4.0.4.0.4/OPENMASTER/1893:eng/test-keys 05:34:02 INFO - CPU: arm 05:34:02 INFO - 0 CPUs 05:34:02 INFO - Crash reason: SIGSEGV 05:34:02 INFO - Crash address: 0x10 05:34:02 INFO - Thread 0 (crashed) 05:34:02 INFO - 0 libxul.so!nsPresContext::PreferenceChanged(char const*) [nsDeviceContext.h:0d65b1c05b2f : 61 + 0x0] 05:34:02 INFO - r4 = 0x418bbcdc r5 = 0x4490d800 r6 = 0xbe8d9880 r7 = 0x00000001 05:34:02 INFO - r8 = 0x0000003f r9 = 0x00010011 r10 = 0x43934740 fp = 0x41f7fa10 05:34:02 INFO - sp = 0xbe8d9840 lr = 0x40652c05 pc = 0x407c2f62 05:34:02 INFO - Found by: given as instruction pointer in context 05:34:02 INFO - 1 libxul.so!nsPresContext::PrefChangedCallback(char const*, void*) [nsPresContext.cpp:0d65b1c05b2f : 161 + 0x7] 05:34:02 INFO - r4 = 0x43934740 r5 = 0x00000003 r6 = 0x4074e331 r7 = 0x00000000 05:34:02 INFO - r8 = 0x0000003f r9 = 0x00010011 r10 = 0x43934740 fp = 0x41f7fa10 05:34:02 INFO - sp = 0xbe8d98c8 pc = 0x407c3123 05:34:02 INFO - Found by: call frame info 05:34:02 INFO - 2 libxul.so!mozilla::ValueObserver::Observe(nsISupports*, char const*, unsigned short const*) [Preferences.cpp:0d65b1c05b2f : 143 + 0x3] 05:34:02 INFO - r4 = 0x43934740 r5 = 0x00000003 r6 = 0x4074e331 r7 = 0x00000000 05:34:02 INFO - r8 = 0x0000003f r9 = 0x00010011 r10 = 0x43934740 fp = 0x41f7fa10 05:34:02 INFO - sp = 0xbe8d98d0 pc = 0x4074e367 05:34:02 INFO - Found by: call frame info 05:34:02 INFO - 3 libxul.so!nsPrefBranch::NotifyObserver(char const*, void*) [nsPrefBranch.cpp:0d65b1c05b2f : 724 + 0xb] 05:34:02 INFO - r4 = 0xbe8d9938 r5 = 0xbe8d99cc r6 = 0x4074e331 r7 = 0x00000000 05:34:02 INFO - r8 = 0x0000003f r9 = 0x00010011 r10 = 0x43934740 fp = 0x41f7fa10 05:34:02 INFO - sp = 0xbe8d9938 pc = 0x40750bdb 05:34:02 INFO - Found by: call frame info 05:34:02 INFO - 4 libxul.so!pref_DoCallback [prefapi.cpp:0d65b1c05b2f : 956 + 0x7] 05:34:02 INFO - r4 = 0x43499a50 r5 = 0x00000000 r6 = 0x00000000 r7 = 0x41f585b8 05:34:02 INFO - r8 = 0x439348a0 r9 = 0x00000000 r10 = 0x00000000 fp = 0x00000000 05:34:02 INFO - sp = 0xbe8d9a60 pc = 0x40752435 05:34:02 INFO - Found by: call frame info 05:34:02 INFO - 5 libxul.so!pref_HashPref [prefapi.cpp:0d65b1c05b2f : 802 + 0x3] 05:34:02 INFO - r4 = 0x00000020 r5 = 0x43499938 r6 = 0x41f585b8 r7 = 0x43115794 05:34:02 INFO - r8 = 0xbe8d9ddc r9 = 0x00000000 r10 = 0x00000000 fp = 0x00000000 05:34:02 INFO - sp = 0xbe8d9a78 pc = 0x407525cb 05:34:02 INFO - Found by: call frame info 05:34:02 INFO - 6 libxul.so!PREF_SetCharPref [prefapi.cpp:0d65b1c05b2f : 258 + 0x3]
Summary: Intermittent TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_meta_viewport6.html | application timed out after 330 seconds with no output and crashed application crashed [@ nsPresContext::PreferenceChanged(char const*)] → Intermittent TEST-UNEXPECTED-FAIL | test_meta_viewport6.html,test_pixel_lengths.html | application timed out after 330 seconds with no output and/or application crashed [@ nsPresContext::PreferenceChanged(char const*)]
Johnny, this is a long-running crash we've been hitting in automation. Any chance you could help find an owner? :)
Flags: needinfo?(jst)
Summary: Intermittent TEST-UNEXPECTED-FAIL | test_meta_viewport6.html,test_pixel_lengths.html | application timed out after 330 seconds with no output and/or application crashed [@ nsPresContext::PreferenceChanged(char const*)] → Intermittent test_meta_viewport6.html,test_pixel_lengths.html | application timed out after 330 seconds with no output and/or application crashed [@ nsPresContext::PreferenceChanged(char const*)]
Summary: Intermittent test_meta_viewport6.html,test_pixel_lengths.html | application timed out after 330 seconds with no output and/or application crashed [@ nsPresContext::PreferenceChanged(char const*)] → Intermittent test_meta_viewport6.html,test_pixel_lengths.html | application timed out after 330 seconds with no output and/or application crashed [@ nsPresContext::PreferenceChanged(char const*)][@ nsPresContext::AppUnitsPerDevPixel()]
Sorry for the silence here, I did spend some time digging in here trying to figure out what we're actually crashing on here, but failed to make much headway. It seems pretty clear that this is in layout code though, so bumping this to the layout folks. Jet, can you please have one of your guys dig in here?
Flags: needinfo?(jst) → needinfo?(bugs)
To Jonathan for a look. It seems like our usage of SpecialPowers.pushPrefEnv() is running into a very bad race condition (smells similar to bug 701060.) Can you help resolve this one?
Assignee: nobody → jwatt
Flags: needinfo?(bugs)
One thing that is clear here is that the symbols are busted: 15:48:56 INFO - 0 libxul.so!nsPresContext::PreferenceChanged(char const*) [task.h:31abf5bacc6c : 27 + 0x0] 15:48:56 INFO - eip = 0xb54bfe2c esp = 0xbff73b70 ebp = 0xbff73d2c ebx = 0xb6dd98c8 15:48:56 INFO - esi = 0x9c581c00 edi = 0xbff73bc4 eax = 0x00000000 ecx = 0x00006970 15:48:56 INFO - edx = 0xb619aeb4 efl = 0x00210202 15:48:56 INFO - Found by: given as instruction pointer in context nsPresContext::PreferenceChanged doesn't call CancelableTask's ctor or dtor anywhere (checked under a debugger), so the task.h:27 part is bogus, which is unfortunate as that doesn't reveal much about the crash... Ted, any idea why?
Flags: needinfo?(ted)
I really don't know what's going on with the symbols here, but I don't think this is a Breakpad issue, it seems like it's just the compiler being weird. The crash in comment 233 is at libxul.so + 0x15b1323, and the relevant bits of the symbol file look like (with filenames+line numbers expanded into hg links): 15b130f http://hg.mozilla.org/releases/mozilla-beta/annotate/10904f84c309/layout/base/nsPresContext.cpp#l935 15b1320 http://hg.mozilla.org/releases/mozilla-beta/annotate/10904f84c309/xpcom/base/nsAutoPtr.h#l1029 15b1323 http://hg.mozilla.org/releases/mozilla-beta/annotate/10904f84c309/ipc/chromium/src/base/task.h#l27 15b1326 http://hg.mozilla.org/releases/mozilla-beta/annotate/10904f84c309/layout/base/nsPresContext.cpp#l914 It would be interesting to grab a full build with symbols from tinderbox and disassemble this function to see WTF the codegen actually looks like here.
Flags: needinfo?(ted)
The symbols on the stack looks valid though - it's a preference change that is being notified to a pres context. Maybe we crash b/c the pres context is in the process of being destroyed? I wonder if we can stress test this to crash it more reliably. The prefs we listen for are here: http://mxr.mozilla.org/mozilla-central/source/layout/base/nsPresContext.cpp?rev=5333221d0d23#1079 Changing one of those, while creating/destroying/reloading a lot of <iframe>s might trigger it.
(In reply to Mats Palmgren (:mats) from comment #238) > The symbols on the stack looks valid though - it's a preference change that > is being notified to a pres context. Maybe we crash b/c the pres context is > in > the process of being destroyed? I wonder if we can stress test this to crash > it more reliably. The prefs we listen for are here: > http://mxr.mozilla.org/mozilla-central/source/layout/base/nsPresContext. > cpp?rev=5333221d0d23#1079 > Changing one of those, while creating/destroying/reloading a lot of <iframe>s > might trigger it. Any luck with this, Mats? :). We're still hitting this crash pretty reliably in automation as you can see.
Flags: needinfo?(matspal)
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #270) > Any luck with this, Mats? :). We're still hitting this crash pretty reliably > in automation as you can see. I'm busy with other work for the foreseeable future so it's not likely I'll get to this anytime soon, sorry. If someone else can make a standalone testcase that reproduces the crash reliably, then I'll take a look.
Flags: needinfo?(matspal)
Per comment 235, I guess that last needinfo really should have gone to jwatt anyway.
Flags: needinfo?(jwatt)
I think it's time to considering disabling these tests if we can't fix this crash.
Flags: needinfo?(jst)
test_pixel_lengths.html disabled on all platforms. https://hg.mozilla.org/integration/mozilla-inbound/rev/0b924bbee94d
Flags: needinfo?(jwatt)
Flags: needinfo?(jst)
Whiteboard: [test disabled][leave open]
I think I fixed this in bug 1090530, if that sticks these can be re-enabled.
Depends on: 1090530
Green! Test re-enabled on trunk. We can also re-enable it on any other branches that bug 1090530 gets approval to land on. https://hg.mozilla.org/integration/mozilla-inbound/rev/b327975e972b
Assignee: jwatt → jschoenick
status-b2g-v2.0M: --- → disabled
status-b2g-v2.1: --- → disabled
status-b2g-v2.2: --- → fixed
status-firefox33: --- → disabled
status-firefox34: --- → disabled
status-firefox35: --- → disabled
status-firefox36: --- → fixed
status-firefox-esr31: --- → disabled
Component: General → DOM
Product: Firefox OS → Core
Whiteboard: [test disabled][leave open]
Backed out in https://hg.mozilla.org/integration/mozilla-inbound/rev/6c3fa2249f3e for moving test_bluetooth.html from being the first test in mochitest-13 on debug b2g emulator to being the test in mochitest-12 which times out with no output 50% of the time. And yes, I did consider the alternative of hiding all b2g mochitests on all trunk trees for being unacceptably chunked, but that would require more paperwork than a backout did.
I would have voted for disabling the flaky timebomb test instead of backing this out, but that's OK, I'll just do it myself instead. Here's an example log for perpetuity. https://treeherder.mozilla.org/ui/logviewer.html#?job_id=3507717&repo=mozilla-inbound
https://hg.mozilla.org/mozilla-central/rev/a8f1024325bf
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla36
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.