Closed Bug 1045421 Opened 6 years ago Closed 6 years ago

XPCShell failures started up across multiple trees with test_crash_manager.js | test failed (with xpcshell return code: 0), see following log:

Categories

(Toolkit :: Crash Reporting, defect)

defect
Not set
normal
Points:
1

Tracking

()

RESOLVED FIXED
mozilla34
Iteration:
34.2
Tracking Status
firefox31 - wontfix
firefox32 + fixed
firefox33 + fixed
firefox34 + fixed
firefox-esr24 --- unaffected
firefox-esr31 32+ fixed
b2g-v1.3 --- unaffected
b2g-v1.3T --- unaffected
b2g-v1.4 --- fixed
b2g-v2.0 --- fixed
b2g-v2.1 --- fixed

People

(Reporter: KWierso, Assigned: gps)

Details

Attachments

(1 file, 1 obsolete file)

This started up this evening. There was a service outage in PHX tonight around the same time this showed up, so it might be related to that.

https://tbpl.mozilla.org/php/getParsedLog.php?id=44760175&tree=Mozilla-Central

18:41:44     INFO -  TEST-PASS | C:\slave\test\build\tests\xpcshell\tests\dom\plugins\test\unit\test_persist_in_prefs.js | test passed (time: 263.000ms)
18:41:44     INFO -  TEST-INFO | C:\slave\test\build\tests\xpcshell\tests\dom\plugins\test\unit\test_plugin_default_state_xpi.js | running test ...
18:41:44     INFO -  TEST-PASS | C:\slave\test\build\tests\xpcshell\tests\dom\plugins\test\unit\test_plugin_default_state_xpi.js | test passed (time: 433.000ms)
18:41:44     INFO -  TEST-INFO | C:\slave\test\build\tests\xpcshell\tests\services\common\tests\unit\test_storageservice_client.js | running test ...
18:41:47     INFO -  TEST-PASS | C:\slave\test\build\tests\xpcshell\tests\services\common\tests\unit\test_storageservice_client.js | test passed (time: 2674.000ms)
18:41:47     INFO -  TEST-INFO | C:\slave\test\build\tests\xpcshell\tests\toolkit\components\crashes\tests\xpcshell\test_crash_manager.js | running test ...
18:41:48  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\components\crashes\tests\xpcshell\test_crash_manager.js | test failed (with xpcshell return code: 0), see following log:
18:41:48     INFO -  >>>>>>>
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test pending (1)
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test run_next_test 0 pending (2)
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test finished (2)
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | running event loop



LATER



18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-41
18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-42
18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-43
18:41:48     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js | [test_prune_old : 174] 2 == 2
18:41:48     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js | [test_prune_old : 179] Old crash has been pruned. - 1 == 1
18:41:48     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js | [test_prune_old : 182] Proper crash was pruned. - "id2" == "id2"
18:41:48     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js | [test_prune_old : 188] 0 == 0
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test run_next_test 11 pending (2)
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test test_prune_old finished (2)
18:41:48     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js | Starting test_schedule_maintenance
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test test_schedule_maintenance pending (2)
18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-45
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | test run_next_test 11 finished (2)
18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-46
18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-47
18:41:48     INFO -  Creating directory: c:\\docume~1\\cltbld~1.t-x\\locals~1\\temp\\tmpqo1tx7\\dummy-dir-48
18:41:48  WARNING -  TEST-UNEXPECTED-FAIL | C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js | 0 == 1 - See following stack:
18:41:48     INFO -      C:/slave/test/build/tests/xpcshell/tests/toolkit/components/crashes/tests/xpcshell/test_crash_manager.js:test_schedule_maintenance:200
18:41:48     INFO -      _run_next_test@C:\\slave\\test\\build\\tests\\xpcshell\\head.js:1308:9
18:41:48     INFO -      do_execute_soon/<.run@C:\\slave\\test\\build\\tests\\xpcshell\\head.js:570:9
18:41:48     INFO -      _do_main@C:\\slave\\test\\build\\tests\\xpcshell\\head.js:191:5
18:41:48     INFO -      _execute_test@C:\\slave\\test\\build\\tests\\xpcshell\\head.js:405:5
18:41:48     INFO -      @-e:1:1
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | exiting test
18:41:48  WARNING -  TEST-UNEXPECTED-FAIL | C:\\slave\\test\\build\\tests\\xpcshell\\head.js | Unexpected exception 2147500036
18:41:48     INFO -  TEST-INFO | (xpcshell/head.js) | exiting test
18:41:48     INFO -  <<<<<<<






Not sure at this point if it'll just go away on its own with new builds.
test_schedule_maintenance was added by gps in bug 875562. We've already been able to reproduce these on Aurora33 and Beta32, and I have no reason to believe we couldn't hit this on esr31 and b2g30 as well. Some sort of timebomb in the test?
Pushed to aurora and beta with a corrected bug number in the commit message (trunk trees had it as bug 1045419):

https://hg.mozilla.org/mozilla-central/raw-rev/56efa7ae8500
https://hg.mozilla.org/releases/mozilla-beta/rev/6782bc9ae760

I don't have the esr or b2g trees cloned at the moment, but Ryan wants this to go to ESR31 and b2g30, so I'll needinfo him so he can do it in the morning.
Attached patch crash-manager.patch (obsolete) — Splinter Review
There was a hard-coded date in test_crash_manager.js of around August 3,
2013. This meant that about a year later we would start to run into
boundary issues since we weren't wrapping Date.now() inside
CrashManager.jsm.

It turns out the actual value of DUMMY_DATE doesn't really matter. So,
the test has been changed to produce a value that is reasonably modern.

While I was debugging this, I noticed we're not getting logging in the
tests. So I added that.
Assignee: nobody → gps
Status: NEW → ASSIGNED
Attachment #8464111 - Flags: review?(georg.fritzsche)
Iteration: --- → 34.1
Hi Greg, can you assign a point value and mark this bug as either [qa+] or [qa-] for verification.
QA Whiteboard: [qa?]
Flags: needinfo?(gps)
Flags: firefox-backlog+
It took me about 15 minutes to fix it, so I guess that's a 1?
Points: --- → 1
QA Whiteboard: [qa?] → [qa-]
Flags: needinfo?(gps)
Comment on attachment 8464111 [details] [diff] [review]
crash-manager.patch

Review of attachment 8464111 [details] [diff] [review]:
-----------------------------------------------------------------

The date fix looks fine, but see the point on the logging below.

::: toolkit/components/crashes/CrashManagerTest.jsm
@@ +29,5 @@
> +  let log = Log.repository.getLogger("Crashes.CrashManager");
> +  log.level = Log.Level.All;
> +  let appender = new Log.DumpAppender();
> +  appender.level = Log.Level.All;
> +  log.addAppender(appender);

This is fine for xpcshell tests which run each in their own environment, but for e.g. mochitest-browser you'll end up adding an additional DumpAppender per test.
Can we do this better or just have a dump pref for the logging in CrashManager.jsm?
Attachment #8464111 - Flags: review?(georg.fritzsche)
Iteration: 34.1 → 34.2
Comment on attachment 8464111 [details] [diff] [review]
crash-manager.patch

Gah, I think my comment got swallowed.

I think we should land this as-is and worry about the mochitest implications later. We have patches actively landing against CrashManager.jsm and I don't want disabled tests while development is ongoing.
Attachment #8464111 - Flags: review?(georg.fritzsche)
This seems like it isn't too much effort to fix or am i missing something?
Flags: needinfo?(gps)
I'll fix it.
Flags: needinfo?(gps)
Attachment #8464111 - Attachment is obsolete: true
Attachment #8464111 - Flags: review?(georg.fritzsche)
Attached patch pSplinter Review
Prevent double appender.
Attachment #8468582 - Flags: review?(georg.fritzsche)
Attachment #8468582 - Attachment is patch: true
Comment on attachment 8468582 [details] [diff] [review]
p

Review of attachment 8468582 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good to me.
Attachment #8468582 - Flags: review?(georg.fritzsche) → review+
https://hg.mozilla.org/mozilla-central/rev/d5387e9486f1
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla34
[Tracking Requested - why for this release]:

I'm requesting uplift of this test-only change so we can reinstate test coverage of released builds. I don't anticipate anything touching this code to be uplifted to Aurora or earlier. But you never know. This uplift should be harmless.
test-only changes don't need approval for uplift, just land them a=test-only or set checkin-needed and I'll get it. Note that it'll need to land on b2g30, esr31, beta, and aurora.
Flags: needinfo?(ryanvm)
Thanks for the landing assist, Ryan!
You need to log in before you can comment on or make changes to this bug.