Closed Bug 921321 Opened 12 years ago Closed 12 years ago

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

Categories

(Toolkit :: Application Update, defect)

Product:
Toolkit
Component:
Application Update
Platform:
x86
Windows 8
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla27
Tracking Flags:
Tracking Status
firefox24 --- fixed
firefox25 --- fixed
firefox26 --- fixed
firefox27 --- fixed
firefox-esr24 --- fixed

People

(Reporter: RyanVM, Assigned: bhearsum)

References

Details

(Keywords: intermittent-failure)

+++ 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...
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)
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)
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)
Depends on: 921483
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
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?
Sure thing, thanks for the reminder.
Assignee: nobody → bhearsum
Status: NEW → RESOLVED
Closed: 12 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.