Intermittent test_TelemetryPing.js | test failed (with xpcshell return code: 3), see following log: | test-ping == saved-session

RESOLVED FIXED in mozilla16

Status

()

defect
RESOLVED FIXED
7 years ago
7 years ago

People

(Reporter: emorley, Unassigned)

Tracking

({intermittent-failure})

15 Branch
mozilla16
x86
Windows 7
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

Rev3 WINNT 6.1 mozilla-central debug test xpcshell on 2012-05-09 12:58:34 PDT for push b5765cc9da6c

slave: talos-r3-w7-073

https://tbpl.mozilla.org/php/getParsedLog.php?id=11617163&tree=Firefox

{
TEST-INFO | C:\talos-slave\test\build\xpcshell\tests\toolkit\components\telemetry\tests\unit\test_TelemetryPing.js | running test ...
TEST-UNEXPECTED-FAIL | C:\talos-slave\test\build\xpcshell\tests\toolkit\components\telemetry\tests\unit\test_TelemetryPing.js | test failed (with xpcshell return code: 3), see following log:
>>>>>>>
### XPCOM_MEM_LEAK_LOG defined -- logging leaks to c:\users\cltbld\appdata\local\temp\tmpbdvmy3\runxpcshelltests_leaks.log

TEST-INFO | (xpcshell/head.js) | test 1 pending
WARNING: This method is lossy. Use GetCanonicalPath !: file e:/builds/moz2_slave/m-cen-w32-dbg/build/xpcom/io/nsLocalFileWin.cpp, line 3292

TEST-INFO | (xpcshell/head.js) | test 2 pending

TEST-INFO | (xpcshell/head.js) | test 2 finished

TEST-INFO | (xpcshell/head.js) | running event loop

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] XPCShell == XPCShell

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] xpcshell@tests.mozilla.org == xpcshell@tests.mozilla.org

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] 1 == 1

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] XPCShell == XPCShell

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] 2007010101 == 2007010101

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] 2007010101 == 2007010101

TEST-UNEXPECTED-FAIL | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | test-ping == saved-session - See following stack:
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_throw :: line 462
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: _do_check_eq :: line 556
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_check_eq :: line 577
JS frame :: C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js :: checkPayloadInfo :: line 124
JS frame :: C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js :: checkPersistedHistograms :: line 147
JS frame :: C:/talos-slave/test/build/firefox/components/httpd.js :: <TOP_LEVEL> :: line 2272
JS frame :: C:/talos-slave/test/build/firefox/components/httpd.js :: <TOP_LEVEL> :: line 1169
JS frame :: C:/talos-slave/test/build/firefox/components/httpd.js :: <TOP_LEVEL> :: line 1617
JS frame :: C:/talos-slave/test/build/firefox/components/httpd.js :: <TOP_LEVEL> :: line 1465
JS frame :: C:/talos-slave/test/build/firefox/components/httpd.js :: <TOP_LEVEL> :: line 1334

TEST-INFO | (xpcshell/head.js) | exiting test

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] XPCShell == XPCShell

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] xpcshell@tests.mozilla.org == xpcshell@tests.mozilla.org

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] 1 == 1

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] XPCShell == XPCShell

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] 2007010101 == 2007010101

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 121] 2007010101 == 2007010101

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 124] saved-session == saved-session

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 125] true == true

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 126] true == true

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 136] true == true

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | [checkPayloadInfo : 137] true == true

TEST-UNEXPECTED-FAIL | C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js | false == true - See following stack:
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_throw :: line 462
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: _do_check_eq :: line 556
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_check_eq :: line 577
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_check_true :: line 591
JS frame :: C:/talos-slave/test/build/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryPing.js :: <TOP_LEVEL> :: line 305
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: _execute_test :: line 363
JS frame :: -e :: <TOP_LEVEL> :: line 1

TEST-INFO | (xpcshell/head.js) | exiting test
uncaught exception: 2147500036
resource:///components/fuelApplication.js:1322: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
WARNING: nsExceptionService ignoring thread destruction after shutdown: file e:/builds/moz2_slave/m-cen-w32-dbg/build/xpcom/base/nsExceptionService.cpp, line 199
JS Component Loader: ERROR C:/talos-slave/test/build/firefox/components/httpd.js:481
                     TypeError: dumpn is not a function
WARNING: NS_ENSURE_TRUE(mMainThread) failed: file e:/builds/moz2_slave/m-cen-w32-dbg/build/xpcom/threads/nsThreadManager.cpp, line 292
WARNING: NS_ENSURE_TRUE(mMainThread) failed: file e:/builds/moz2_slave/m-cen-w32-dbg/build/xpcom/threads/nsThreadManager.cpp, line 283
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file e:/builds/moz2_slave/m-cen-w32-dbg/build/obj-firefox/xpcom/build/nsThreadUtils.cpp, line 168
WARNING: NS_ENSURE_TRUE(mInitialized) failed: file e:/builds/moz2_slave/m-cen-w32-dbg/build/xpcom/threads/nsThreadManager.cpp, line 241
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file e:/builds/moz2_slave/m-cen-w32-dbg/build/obj-firefox/xpcom/build/nsThreadUtils.cpp, line 83
WARNING: Failed to create async thread.: file e:/builds/moz2_slave/m-cen-w32-dbg/build/storage/src/mozStorageConnection.cpp, line 598
WARNING: NS_ENSURE_TRUE(asyncThread) failed: file e:/builds/moz2_slave/m-cen-w32-dbg/build/storage/src/mozStorageConnection.cpp, line 1052
WARNING: OOPDeinit() without successful OOPInit(): file e:/builds/moz2_slave/m-cen-w32-dbg/build/toolkit/crashreporter/nsExceptionHandler.cpp, line 2041
}
Posted patch bandaid patchSplinter Review
I've seen this problem in different contexts; I'm not sure what's causing it in this instance, but here's a patch while might help a bit.  I don't have solid, debugged evidence for this since xpcshell JS debugging is painful, but here's the outline for what goes wrong when I have seen situations like this locally:

1. TelemetryPing sends an HTTP request for a persistent telemetry ping.
2. Something goes wrong during the checking of the payload for said ping.
3. xpcshell/head.js throws an error, causing the HTTP handler to abort.
4. The error propagates into the ether somewhere (not sure what happens to it, really).
5. TelemetryPing sends an HTTP request for a "normal" telemetry ping.
6. The HTTP server hands it off to the *persistent* telemetry ping handler, because we didn't get a chance to swap in the normal ping handler in checkPersistedHistograms.
7. Spurious errors and whatnot ensue.

The patch fixes this case by installing the new handler before we check (and therefore possibly throw).  It *looks* like in some of these cases that the checking for the persistent telemetry ping never happens, which is very strange.  Anyway, for the third (fourth?) time, this isn't advertised as a total fix, but one which might help remove some of the noise here.
Attachment #630984 - Flags: review?(taras.mozilla)
Comment on attachment 630984 [details] [diff] [review]
bandaid patch

good idea
Attachment #630984 - Flags: review?(taras.mozilla) → review+
https://hg.mozilla.org/integration/mozilla-inbound/rev/9afafcdf9be5

Will try to pay attention to any reports on this bug after the above gets merged; ideally those reports will have more useful information in them.
Whiteboard: [orange] → [orange][leave open]
Seems to have done the trick :-)
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Whiteboard: [orange][leave open] → [orange]
Target Milestone: --- → mozilla16
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.