889860 - Intermittent test_0200_app_launch_apply_update.js | Test timed out | test failed (with xpcshell return code: 1)

Status: RESOLVED FIXED

(Toolkit :: Application Update, defect)

Description

[Ryan VanderMeulen [:RyanVM]]

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

Windows XP 32-bit mozilla-inbound opt test xpcshell on 2013-07-03 02:52:01 PDT for push 9939c3648650
slave: t-xp32-ix-017

03:13:40     INFO -  TEST-INFO | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | running test ...
03:18:40  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | Test timed out
03:18:40     INFO -  Can't trigger Breakpad, just killing process
03:18:40  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 1), see following log:
03:18:40     INFO -  >>>>>>>
03:18:40     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test pending (1)
03:18:40     INFO -  TEST-INFO | (xpcshell/head.js) | test pending (2)
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [run_test : 84] update test directory path: C:\slave\test\build\application\firefox\update_test
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [run_test : 123] launching C:\WINDOWS\System32\cmd.exe /D /Q /C C:\slave\test\build\application\firefox\0200_aus_test_app.exe -no-remote -process-updates 1> C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\0200_app_console_log 2>&1
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [setEnvironment : 3210] setting the XRE_NO_WINDOWS_CRASH_DIALOG environment variable to 1... previously it didn't exist
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [setEnvironment : 3257] removing the XPCOM_MEM_LEAK_LOG environment variable... previous value c:\docume~1\cltbld~1.t-x\locals~1\temp\tmpcli0co\runxpcshelltests_leaks.log
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [setEnvironment : 3264] setting the XPCOM_DEBUG_BREAK environment variable to warn... previous value stack-and-abort
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [setEnvironment : 3294] setting MOZ_NO_SERVICE_FALLBACK environment variable to 1
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [resetEnvironment : 3314] setting the XPCOM_MEM_LEAK_LOG environment variable back to c:\docume~1\cltbld~1.t-x\locals~1\temp\tmpcli0co\runxpcshelltests_leaks.log
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [resetEnvironment : 3320] setting the XPCOM_DEBUG_BREAK environment variable back to stack-and-abort
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [resetEnvironment : 3354] removing the XRE_NO_WINDOWS_CRASH_DIALOG environment variable
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [resetEnvironment : 3376] removing MOZ_NO_SERVICE_FALLBACK environment variable
03:18:40     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test finished (2)
03:18:40     INFO -  TEST-INFO | (xpcshell/head.js) | running event loop
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/head_update.js | [PO_observe : 3133] topic process-finished, process exitValue 0
03:18:40     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 261] contents of C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\update.log:
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 267] "succeeded" == "succeeded"
03:18:40     INFO -  *** AUS:SVC Creating UpdateService
03:18:40     INFO -  *** AUS:SVC gCanCheckForUpdates - able to check for updates
03:18:40     INFO -  *** AUS:SVC gCanApplyUpdates - testing write access C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\update.test
03:18:40     INFO -  *** AUS:SVC gCanApplyUpdates - windowsVersion = 5.1
03:18:40     INFO -  *** AUS:SVC gCanApplyUpdates - testing write access C:\slave\test\build\application\firefox\update.test
03:18:40     INFO -  *** AUS:SVC gCanApplyUpdates - able to apply updates
03:18:40     INFO -  *** AUS:SVC readStatusFile - status: succeeded, path: C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\update.status
03:18:40     INFO -  *** AUS:SVC readStatusFile - status: succeeded, path: C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\update.status
03:18:40     INFO -  *** AUS:SVC UpdateManager:_loadXMLFileIntoArray: XML file does not exist
03:18:40     INFO -  *** AUS:SVC cleanUpUpdatesDir - failed to move file C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\update.log to C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates and rename it to last-update.log
03:18:40     INFO -  *** AUS:SVC cleanUpUpdatesDir - failed to remove file C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\update.log
03:18:40     INFO -  *** AUS:SVC cleanUpUpdatesDir - failed to remove file C:\Documents and Settings\cltbld.T-XP32-IX-017\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\updater.exe
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 272] "succeeded" == "succeeded"
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 278] false == false
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 282] true == true
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 283] "UpdateTestAddFile
03:18:40     INFO -  " == "UpdateTestAddFile
03:18:40     INFO -  "
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 287] true == true
03:18:40     INFO -  TEST-PASS | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 288] "update_test/UpdateTestRemoveFile
03:18:40     INFO -  " == "update_test/UpdateTestRemoveFile
03:18:40     INFO -  "
03:18:40     INFO -  <<<<<<<

Comment 1

[Legacy TBPL/Treeherder Robot]

Gijs
https://tbpl.mozilla.org/php/getParsedLog.php?id=24897448&tree=UX
Windows XP 32-bit ux debug test xpcshell on 2013-07-03 11:11:06
revision: b6f8dc3e635b
slave: t-xp32-ix-013

11:46:51  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | Test timed out
11:46:51  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 1), see following log:
11:53:04    ERROR - Return code: 1

Comment 2

[Legacy TBPL/Treeherder Robot]

philor
https://tbpl.mozilla.org/php/getParsedLog.php?id=24922548&tree=Mozilla-Inbound
Windows XP 32-bit mozilla-inbound debug test xpcshell on 2013-07-03 20:38:03
revision: 4afa33be1fce
slave: t-xp32-ix-053

21:12:42  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | Test timed out
21:12:42  WARNING -  TEST-UNEXPECTED-FAIL | C:\slave\test\build\tests\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 1), see following log:
21:18:50    ERROR - Return code: 1

Comment 3

[Robert Strong (they/them - no direct email)]

Attachment: patch rev1

I suspect this won't fix this though it shouldn't hurt and I tried to reproduce with this patch numerous times without success so it might.
https://tbpl.mozilla.org/?tree=Try&rev=51b5f8398388

Comment 4

[Brian R. Bondy [:bbondy]]

Comment on attachment 771506 [details] [diff] [review]
patch rev1

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

::: toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js
@@ +256,5 @@
>  
> +  try {
> +    // Check that the last-update.log is not locked before proceeding.
> +    log.moveTo(updatesDir, FILE_LAST_LOG);
> +    log.moveTo(updatesDir, FILE_UPDATE_LOG);

You may want to catch these separately for more specific logging.  I suspect the first one would always be the one to fail though so I'm fine with leaving it as is.

Comment 5

[Robert Strong (they/them - no direct email)]

Attachment: patch rev2 - comments addressed

Comment 6

[Robert Strong (they/them - no direct email)]

Pushed to mozilla-inbound
https://hg.mozilla.org/integration/mozilla-inbound/rev/cf80d2e4411c

Comment 7

[Robert Strong (they/them - no direct email)]

Attachment: patch rev3 with comment addressed and additional comments

Comment 8

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/cf80d2e4411c

Comment 9

[Robert Strong (they/them - no direct email)]

Pushed to mozilla-aurora
https://hg.mozilla.org/releases/mozilla-aurora/rev/85b2a5b62f6b

Pushed to mozilla-beta
https://hg.mozilla.org/releases/mozilla-beta/rev/583dc042a287