Intermittent test_0000_bootstrap_svc.js | test failed (with xpcshell return code: 0) | "failed: 26" == "succeeded" and a bunch more

RESOLVED FIXED in Firefox 24

Status

()

Toolkit
Application Update
RESOLVED FIXED
4 years ago
4 years ago

People

(Reporter: RyanVM, Assigned: bhearsum)

Tracking

({intermittent-failure})

unspecified
mozilla27
x86
Windows 8
intermittent-failure
Points:
---

Firefox Tracking Flags

(firefox24 fixed, firefox25 fixed, firefox26 fixed, firefox27 fixed, firefox-esr24 fixed)

Details

(Reporter)

Description

4 years ago
+++ This bug was initially created as a clone of Bug #715746 +++

Ahhhh, memories.

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

WINNT 6.2 mozilla-central pgo test xpcshell on 2013-09-26 18:30:58 PDT for push 0005c66e4de4
slave: t-w864-ix-123

18:57:56     INFO -  TEST-INFO | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\test_0000_bootstrap_svc.js | running test ...
18:57:58  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\test_0000_bootstrap_svc.js | test failed (with xpcshell return code: 0), see following log:
18:57:58     INFO -  >>>>>>>
18:57:58     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test pending (1)
18:57:58     INFO -  18:57:56:418 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [shouldRunServiceTest : 1663] Checking if the service exists on this machine.
18:57:58     INFO -  18:57:56:440 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [shouldRunServiceTest : 1669] Service exists, return value: 0
18:57:58     INFO -  TEST-INFO | (xpcshell/head.js) | test pending (2)
18:57:58     INFO -  18:57:57:199 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setupUpdaterTest : 2090] testing successful removal of the directory used to apply the mar file
18:57:58     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setupUpdaterTest : 2092] false == false
18:57:58     INFO -  18:57:57:225 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_installer.exe to stop if necessary...
18:57:58     INFO -  18:57:57:231 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_tmp.exe to stop if necessary...
18:57:58     INFO -  18:57:57:238 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice.exe to stop if necessary...
18:57:58     INFO -  18:57:57:244 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForServiceStop : 1782] Waiting for service to stop if necessary...
18:57:58     INFO -  18:57:57:244 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForServiceStop : 1792] Stopping service...
18:57:58     INFO -  18:57:57:250 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForServiceStop : 1806] Service stopped.
18:57:58     INFO -  18:57:57:250 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_installer.exe to stop if necessary...
18:57:58     INFO -  18:57:57:256 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_tmp.exe to stop if necessary...
18:57:58     INFO -  18:57:57:262 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice.exe to stop if necessary...
18:57:58     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [runUpdateUsingService : 1875] "pending-service" == "pending-service"
18:57:58     INFO -  18:57:57:271 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [runUpdateUsingService : 1890] launching C:\windows\System32\cmd.exe /D /Q /C C:\slave\test\build\application\firefox\0000_svc_aus_test_app.exe -no-remote -process-updates -dump-args C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\app_args_log 1> C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\0000_svc_app_console_log 2>&1
18:57:58     INFO -  18:57:57:271 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 3317] setting the XRE_NO_WINDOWS_CRASH_DIALOG environment variable to 1... previously it didn't exist
18:57:58     INFO -  18:57:57:271 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 3371] setting the XPCOM_DEBUG_BREAK environment variable to warn... previous value stack-and-abort
18:57:58     INFO -  18:57:57:271 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 3386] setting the MOZ_UPDATE_ROOT_OVERRIDE environment variable to C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\0000_svc_mar
18:57:58     INFO -  18:57:57:272 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 3392] setting the MOZ_UPDATE_APPDIR_OVERRIDE environment variable to C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\0000_svc_applyToDir\appdir
18:57:58     INFO -  18:57:57:272 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 3401] setting MOZ_NO_SERVICE_FALLBACK environment variable to 1
18:57:58     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | "copying C:\slave\test\build\application\firefox\updater.exe to: C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\0000_svc_applyToDir\appdir"
18:57:58     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | "copying C:\slave\test\build\application\firefox\maintenanceservice.exe to: C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\0000_svc_applyToDir\appdir"
18:57:58     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | "copying C:\slave\test\build\application\firefox\maintenanceservice_installer.exe to: C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\0000_svc_applyToDir\appdir"
18:57:58     INFO -  18:57:57:421 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 3427] setting the XPCOM_DEBUG_BREAK environment variable back to stack-and-abort
18:57:58     INFO -  18:57:57:422 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 3461] removing the XRE_NO_WINDOWS_CRASH_DIALOG environment variable
18:57:58     INFO -  18:57:57:422 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 3467] removing the MOZ_UPDATE_ROOT_OVERRIDE environment variable
18:57:58     INFO -  18:57:57:422 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 3473] removing the MOZ_UPDATE_APPDIR_OVERRIDE environment variable
18:57:58     INFO -  18:57:57:422 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 3483] removing MOZ_NO_SERVICE_FALLBACK environment variable
18:57:58     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test finished (2)
18:57:58     INFO -  TEST-INFO | (xpcshell/head.js) | running event loop
18:57:58     INFO -  18:57:58:422 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_installer.exe to stop if necessary...
18:57:58     INFO -  18:57:58:429 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_tmp.exe to stop if necessary...
18:57:58     INFO -  18:57:58:435 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice.exe to stop if necessary...
18:57:58     INFO -  18:57:58:441 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForServiceStop : 1782] Waiting for service to stop if necessary...
18:57:58     INFO -  18:57:58:442 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForServiceStop : 1792] Stopping service...
18:57:58     INFO -  18:57:58:448 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForServiceStop : 1806] Service stopped.
18:57:58     INFO -  18:57:58:448 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_installer.exe to stop if necessary...
18:57:58     INFO -  18:57:58:454 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice_tmp.exe to stop if necessary...
18:57:58     INFO -  18:57:58:460 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [waitForApplicationStop : 1812] Waiting for maintenanceservice.exe to stop if necessary...
18:57:58  WARNING -  TEST-UNEXPECTED-FAIL | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | "failed: 26" == "succeeded" - See following stack:
18:57:58     INFO -  JS frame :: C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js :: timerCallback :: line 1966
18:57:58     INFO -  native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
18:57:58     INFO -  TEST-INFO | (xpcshell/head.js) | exiting test
18:57:58     INFO -  18:57:58:747 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [cleanUp : 1292] start - general test cleanup
18:57:58     INFO -  18:57:58:764 | TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [cleanUp : 1323] finish - general test cleanup
18:57:58     INFO -  <<<<<<<

etc etc etc...
Comment hidden (Treeherder Robot)
Sounds like fallout of some sort from bug 803531.
Strange that its intermittent though.
Could there be a signing server not updated?
Flags: needinfo?(bhearsum)
(Assignee)

Comment 4

4 years ago
Sorry, can someone decode these errors for me? I'm not seeing where the potential connection to the signing servers is.

This is certainly the first test from a nightly with the new certificates, though.
Flags: needinfo?(ryanvm)
Flags: needinfo?(netzen)
error 26 is a verification error on the signature of updater.exe from the maintenane service.

See:
http://dxr.mozilla.org/mozilla-central/search?tree=mozilla-central&q=SERVICE_UPDATER_SIGN_ERROR&redirect=true
Flags: needinfo?(netzen)
(Assignee)

Comment 6

4 years ago
Hrm. So I just verified that all of the signing servers are using the same certificate - so there's no mismatch there. I was also able to install the latest build through the stub installer this morning, which I think validates the cert pinning? This error certainly seems to point at something with the new certificates though...
Flags: needinfo?(bhearsum)
(Assignee)

Updated

4 years ago
Depends on: 921483
Comment hidden (Treeherder Robot)
Talked to bhearsum on #releng and we found that the problem has to do with the bootstrap script that runs on each machine reboot. 
It runs a custom built maintenanceservice_installer.exe which has the old cert values inside of it.

This failures only affects nightly/release builds, and only for tests.

The suggested fix is to manually write out with a REG command or python script, so it can be easily updated (instead of building another updated binary).

Inside HKLM 
Write to key:
SOFTWARE\Mozilla\MaintenanceService\3932ecacee736d366d6436db0f55bce4\0
With string name: issuer and string value: DigiCert Assured ID Code Signing CA-1
(Assignee)

Comment 9

4 years ago
With bug 921483 this shouldn't happen anymore. There might be one or two more instances of it on slaves that haven't rebooted recently, but they'll pick up the changes at next boot.

Ryan, I'll leave it up to you or another sheriff to close this when you're comfortable.
Ryan, given the above are you ok with closing this bug?
(Reporter)

Comment 11

4 years ago
Sure thing, thanks for the reminder.
Assignee: nobody → bhearsum
Status: NEW → RESOLVED
Last Resolved: 4 years ago
status-firefox24: --- → fixed
status-firefox25: --- → fixed
status-firefox26: --- → fixed
status-firefox27: --- → fixed
status-firefox-esr24: --- → fixed
Flags: needinfo?(ryanvm)
Resolution: --- → FIXED
Target Milestone: --- → mozilla27
You need to log in before you can comment on or make changes to this bug.