Closed Bug 626833 Opened 14 years ago Closed 11 years ago

Intermittent test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 3 or 0) | true == false | exception thrown from do_timeout callback: 2147500036

Categories

(Toolkit :: Application Update, defect)

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

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla25
Tracking Flags:
Tracking Status
firefox23 --- fixed
firefox24 --- fixed
firefox25 --- fixed

People

(Reporter: philor, Assigned: robert.strong.bugs)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

patch rev 1
1.05 KB, patch
bbondy
: review+
Details | Diff | Splinter Review
patch - fix possible race condition
2.87 KB, patch
bbondy
: review+
Details | Diff | Splinter Review 
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1295356493.1295358039.14784.gz&fulltext=1
Rev3 WINNT 5.1 mozilla-central opt test xpcshell on 2011/01/18 05:14:53
s: talos-r3-xp-027

TEST-INFO | C:\talos-slave\test\build\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | running test ...
TEST-UNEXPECTED-FAIL | C:\talos-slave\test\build\xpcshell\tests\toolkit\mozapps\update\test\unit\test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 3), see following log:
>>>>>>>
TEST-INFO | (xpcshell/head.js) | test 1 pending
TEST-INFO | (xpcshell/head.js) | test 2 pending
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [run_test : 160] update test directory path: C:\talos-slave\test\build\firefox\update_test
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [run_test : 195] launching C:\WINDOWS\System32\cmd.exe /D /Q /C C:\talos-slave\test\build\firefox\aus_test_app.exe -no-remote -process-updates 1> C:\talos-slave\test\build\xpcshell\tests\toolkit\mozapps\update\test\unit\app_console_log 2>&1
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [setEnvironment : 315] setting the XRE_NO_WINDOWS_CRASH_DIALOG environment variable to 1... previously it didn't exist
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [setEnvironment : 362] removing the XPCOM_MEM_LEAK_LOG environment variable... previous value c:\docume~1\cltbld\locals~1\temp\tmpqozxqx\runxpcshelltests_leaks.log
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [setEnvironment : 369] setting the XPCOM_DEBUG_BREAK environment variable to warn... previous value stack-and-abort
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [resetEnvironment : 395] setting the XPCOM_MEM_LEAK_LOG environment variable back to c:\docume~1\cltbld\locals~1\temp\tmpqozxqx\runxpcshelltests_leaks.log
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [resetEnvironment : 401] setting the XPCOM_DEBUG_BREAK environment variable back to stack-and-abort
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [resetEnvironment : 435] removing the XRE_NO_WINDOWS_CRASH_DIALOG environment variable
TEST-INFO | (xpcshell/head.js) | test 2 finished
TEST-INFO | (xpcshell/head.js) | running event loop
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [PO_observe : 273] topic process-finished, process exitValue 0
TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 593] contents of C:\talos-slave\test\build\firefox\updates\0\update.log:

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 599] succeeded == succeeded
TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 604] succeeded == succeeded
TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 610] false == false
TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 614] true == true
TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 615] UpdateTestAddFile
 == UpdateTestAddFile

TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 619] true == true
TEST-PASS | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 620] update_test/UpdateTestRemoveFile
 == update_test/UpdateTestRemoveFile

TEST-INFO | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 626] testing C:\talos-slave\test\build\firefox\updates\0\update.log shouldn't exist
TEST-UNEXPECTED-FAIL | C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | true == false - See following stack:
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_throw :: line 439
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_check_eq :: line 491
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_check_false :: line 510
JS frame :: C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js :: checkUpdateFinished :: line 627
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: <TOP_LEVEL> :: line 153
TEST-INFO | (xpcshell/head.js) | exiting test
TEST-UNEXPECTED-FAIL | C:\talos-slave\test\build\xpcshell\head.js | exception thrown from do_timeout callback: 2147500036 - See following stack:
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: do_throw :: line 439
JS frame :: C:\talos-slave\test\build\xpcshell\head.js :: <TOP_LEVEL> :: line 155
TEST-INFO | (xpcshell/head.js) | exiting test
*** AUS:SVC gCanCheckForUpdates - able to check for updates
*** AUS:SVC gCanApplyUpdates - testing write access C:\talos-slave\test\build\firefox\update.test
*** AUS:SVC gCanApplyUpdates - windowsVersion = 5.1
*** AUS:SVC gCanApplyUpdates - testing write access C:\talos-slave\test\build\firefox\update.test
*** AUS:SVC gCanApplyUpdates - able to apply updates
*** AUS:SVC readStatusFile - status: succeeded, path: C:\talos-slave\test\build\firefox\updates\0\update.status
*** AUS:SVC readStatusFile - status: succeeded, path: C:\talos-slave\test\build\firefox\updates\0\update.status
*** AUS:SVC UpdateManager:_loadXMLFileIntoArray: XML file does not exist
*** AUS:SVC cleanUpUpdatesDir - failed to move file C:\talos-slave\test\build\firefox\updates\0\update.log to C:\talos-slave\test\build\firefox\updates and rename it to last-update.log
*** AUS:SVC cleanUpUpdatesDir - failed to remove file C:\talos-slave\test\build\firefox\updates\0\update.log
*** AUS:SVC cleanUpUpdatesDir - failed to remove file C:\talos-slave\test\build\firefox\updates\0\updater.exe
uncaught exception: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIFile.remove]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: C:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js :: end_test :: line 238"  data: no]
<<<<<<<
No cases of this happening for over four months so resolving -> wfm. I suspect code churn caused this and additional code churn fixed this.
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → WORKSFORME
Did you turn the crank again?
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Summary: Intermittent test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 3), true == false, exception thrown from do_timeout callback: 2147500036 → Intermittent test_0200_app_launch_apply_update.js | test failed (with xpcshell return code: 3 or 0) | true == false | exception thrown from do_timeout callback: 2147500036
Whiteboard: [orange]
Status: REOPENED → NEW
Resolving WFM keyword:intermittent-failure bugs last modified >3 months ago, whose whiteboard contains none of:
{random,disabled,marked,fuzzy,todo,fails,failing,annotated,time-bomb,leave open}

There will inevitably be some false positives; for that (and the bugspam) I apologise. Filter on orangewfm.
Status: NEW → RESOLVED
Closed: 13 years ago → 11 years ago
Resolution: --- → WORKSFORME
'e's not dead.
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Attached patch patch rev 1 — — Splinter Review 
This adds a try catch around the call to getAppConsoleLogPath as is done elsewhere in the tests likely for this same reason. Though I am interested in why this is failing for this one test I don't think it is worth the time to investigate further.
Assignee: nobody → robert.bugzilla
Status: REOPENED → ASSIGNED
Attachment #768506 - Flags: review?(netzen)
Attachment #768506 - Flags: review?(netzen) → review+
https://hg.mozilla.org/mozilla-central/rev/1d18d1e35c38
Status: ASSIGNED → RESOLVED
Closed: 11 years ago → 11 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla25
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Remaining failure is at:
18:48:31     INFO -  TEST-INFO | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | [checkUpdateFinished : 292] testing C:\Documents and Settings\cltbld.T-XP32-IX-067\Local Settings\Application Data\Mozilla\Firefox\firefox\updates\0\update.log shouldn't exist
18:48:31  WARNING -  TEST-UNEXPECTED-FAIL | C:/slave/test/build/tests/xpcshell/tests/toolkit/mozapps/update/test/unit/test_0200_app_launch_apply_update.js | true == false

I'll take another stab at this sometime this week.
The relevant code from test_0200_app_launch_apply_update.js is in checkUpdateFinished
  let updatesDir = getUpdatesDir();
  log = updatesDir.clone();
  log.append("0");
  log.append(FILE_UPDATE_LOG);
  logTestInfo("testing " + log.path + " shouldn't exist");
  do_check_false(log.exists());
Looks like there is a race condition with the file rename
Attachment #769937 - Flags: review?(netzen)
Comment on attachment 769937 [details] [diff] [review]
patch - fix possible race condition

Messed up patch... I'll resubmit
Attachment #769937 - Attachment is obsolete: true
Attachment #769937 - Flags: review?(netzen)
Comment on attachment 769937 [details] [diff] [review]
patch - fix possible race condition

The patch was fine... I didn't have my environment 100% setup for the service, etc.
Attachment #769937 - Attachment is obsolete: false
Attachment #769937 - Flags: review?(netzen)
Attachment #769937 - Flags: review?(netzen) → review+
Both an opt and debug build passed so pushed to mozilla-inbound
https://hg.mozilla.org/integration/mozilla-inbound/rev/f2d7f7979664

Since this also affects aurora I'll push it to aurora later.

Let's leave this open until we know things are behaving since this has been a bit of a whack a mole.
Whiteboard: [leave open]
Status: REOPENED → ASSIGNED
Pushed both patches to mozilla-aurora
https://hg.mozilla.org/releases/mozilla-aurora/rev/6be4fd69a8f2

Pushed both patches to mozilla-beta
https://hg.mozilla.org/releases/mozilla-beta/rev/4d7f527a72bb

Please reopen if it occurs again.
Status: ASSIGNED → RESOLVED
Closed: 11 years ago → 11 years ago
status-firefox23: --- → fixed
status-firefox24: --- → fixed
status-firefox25: --- → fixed
Resolution: --- → FIXED
Whiteboard: [leave open]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: