Closed Bug 759639 Opened 12 years ago Closed 12 years ago

Intermittent test_0202_app_launch_apply_update_dirlocked_svc.js | test failed (with xpcshell return code: 0), | pending-service == pending, | exception thrown from do_timeout callback: 2147500036

Categories

(Toolkit :: Application Update, defect)

x86
Windows XP
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla20
Tracking Status
firefox14 --- wontfix
firefox15 - wontfix
firefox16 - wontfix
firefox17 - fixed
firefox18 --- fixed
firefox19 --- fixed
firefox20 --- unaffected
firefox-esr17 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 3 obsolete files)

https://tbpl.mozilla.org/php/getParsedLog.php?id=12178113&tree=Mozilla-Inbound
Rev3 WINNT 5.1 mozilla-inbound opt test xpcshell on 2012-05-29 18:31:00 PDT for push 2b16fea69517
slave: talos-r3-xp-039

TEST-UNEXPECTED-FAIL | c:\talos-slave\test\build\xpcshell\tests\toolkit\mozapps\update\test_svc\unit\test_0202_app_launch_apply_update_dirlocked_svc.js | test failed (with xpcshell return code: 0), see following log:
>>>>>>>

TEST-INFO | (xpcshell/head.js) | test 1 pending
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [attemptServiceInstall : 1502] Starting installer process...
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [shouldRunServiceTest : 1425] Checking if the service exists on this machine.
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [shouldRunServiceTest : 1431] Service exists, return value: 0

TEST-INFO | (xpcshell/head.js) | test 2 pending
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/test_0202_app_launch_apply_update_dirlocked_svc.js | [adjustPathsOnWindows : 252] Using this new bin directory: c:\docume~1\cltbld\locals~1\temp\tmpp7xl19\ExecutableDir.tmp\bin

TEST-PASS | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [lockDirectory : 1279] true == true

TEST-PASS | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [lockDirectory : 1280] false == false

TEST-PASS | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/test_0202_app_launch_apply_update_dirlocked_svc.js | [run_test : 189] true == true
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 2776] 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_svc/unit/head_update.js | [setEnvironment : 2823] removing the XPCOM_MEM_LEAK_LOG environment variable... previous value c:\docume~1\cltbld\locals~1\temp\tmpp7xl19\runxpcshelltests_leaks.log
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [setEnvironment : 2830] 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_svc/unit/head_update.js | [setEnvironment : 2856] setting MOZ_NO_SERVICE_FALLBACK environment variable to 1
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 2876] setting the XPCOM_MEM_LEAK_LOG environment variable back to c:\docume~1\cltbld\locals~1\temp\tmpp7xl19\runxpcshelltests_leaks.log
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 2882] 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_svc/unit/head_update.js | [resetEnvironment : 2916] removing the XRE_NO_WINDOWS_CRASH_DIALOG environment variable
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js | [resetEnvironment : 2938] removing MOZ_NO_SERVICE_FALLBACK environment variable

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

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

TEST-UNEXPECTED-FAIL | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/test_0202_app_launch_apply_update_dirlocked_svc.js | pending-service == pending - See following stack:
JS frame :: c:\talos-slave\test\build\xpcshell\head.js :: do_throw :: line 440
JS frame :: c:\talos-slave\test\build\xpcshell\head.js :: _do_check_eq :: line 534
JS frame :: c:\talos-slave\test\build\xpcshell\head.js :: do_check_eq :: line 555
JS frame :: c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/test_0202_app_launch_apply_update_dirlocked_svc.js :: finishTest :: line 313
JS frame :: c:\talos-slave\test\build\xpcshell\head.js :: <TOP_LEVEL> :: line 121

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 440
JS frame :: c:\talos-slave\test\build\xpcshell\head.js :: <TOP_LEVEL> :: line 123

TEST-INFO | (xpcshell/head.js) | exiting test
TEST-INFO | c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/test_0202_app_launch_apply_update_dirlocked_svc.js | [end_test : 209] removing update test directory c:\docume~1\cltbld\locals~1\temp\tmpp7xl19\ExecutableDir.tmp\bin\update_test
Unable to remove files / directories from directory
path: C:\Documents and Settings\cltbld\Local Settings\Application Data\Mozilla\Firefox\firefox\updates
Exception: [Exception... "Component returned failure code: 0x80520015 (NS_ERROR_FILE_ACCESS_DENIED) [nsIFile.remove]"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: c:/talos-slave/test/build/xpcshell/tests/toolkit/mozapps/update/test_svc/unit/head_update.js :: cleanUpdatesDir :: line 1050"  data: no]
<<<<<<<
Traceback (most recent call last):
  File "xpcshell/runxpcshelltests.py", line 915, in <module>
    main()
  File "xpcshell/runxpcshelltests.py", line 911, in main
    if not xpcsh.runTests(args[0], testdirs=args[1:], **options.__dict__):
  File "xpcshell/runxpcshelltests.py", line 795, in runTests
    self.removeDir(self.profileDir)
  File "xpcshell/runxpcshelltests.py", line 321, in removeDir
    shutil.rmtree(dirname)
  File "c:\mozilla-build\python25\Lib\shutil.py", line 169, in rmtree
    rmtree(fullname, ignore_errors, onerror)
  File "c:\mozilla-build\python25\Lib\shutil.py", line 169, in rmtree
    rmtree(fullname, ignore_errors, onerror)
  File "c:\mozilla-build\python25\Lib\shutil.py", line 174, in rmtree
    onerror(os.remove, fullname, sys.exc_info())
  File "c:\mozilla-build\python25\Lib\shutil.py", line 172, in rmtree
    os.remove(fullname)
WindowsError: [Error 13] Access is denied: 'c:\\docume~1\\cltbld\\locals~1\\temp\\tmpp7xl19\\ExecutableDir.tmp\\bin\\updated.update_in_progress.lock'
program finished with exit code 1
Rev3 WINNT 5.1 build-system debug test xpcshell on 2012-05-28 13:03:39 PDT for push e8a1cd107e75

slave: talos-r3-xp-046

https://tbpl.mozilla.org/php/getParsedLog.php?id=12140363&tree=Build-System
Ehsan, do you have any ideas on this one? It's a regular attendee of the orangefactor top oranges list :-)
There's nothing for us to track here since there's nothing that would block a release. When there's a fix for the orange, please nominate for approval to branches.
lsblakk: These test failures are frequent and are a result of bug 307181. Does this really not need to track mozilla15 and higher release?
Blocks: bgupdates
(In reply to comment #113)
> Ehsan, do you have any ideas on this one? It's a regular attendee of the
> orangefactor top oranges list :-)

No, sorry, I won't have enough time to work on this for the foreseeable future.  Could you please ping Brian about this?
(In reply to Ehsan Akhgari [:ehsan] from comment #123)
> (In reply to comment #113)
> > Ehsan, do you have any ideas on this one? It's a regular attendee of the
> > orangefactor top oranges list :-)
> 
> No, sorry, I won't have enough time to work on this for the foreseeable
> future.  Could you please ping Brian about this?

Brian, don't suppose you can take a look? :-)
Brian, ping for comment 124.
Thanks for pinging, sorry I missed comment 124. 

I'll take a look in the near-ish future, I'll be on PTO soon for a new baby, but after that I'll take a look.
Ah, congrats!

Thank you :-)
Whiteboard: [orange]
(In reply to Brian R. Bondy [:bbondy] from comment #151)
> Thanks for pinging, sorry I missed comment 124. 
> 
> I'll take a look in the near-ish future, I'll be on PTO soon for a new baby,
> but after that I'll take a look.

Don't suppose you can take a look now?
Is now quite high up the top-oranges list...

Cheers :-)
Flags: needinfo?(netzen)
I did look by the way during the week that I was off but I didn't make progress unfortunately. I'll talk to rstrong to see if I can prioritize it above some metro stuff I've been doing.
Flags: needinfo?(netzen)
I'll take a look.
Assignee: nobody → robert.bugzilla
(In reply to Robert Strong [:rstrong] (do not email) from comment #386)
> I'll take a look.

Thank you, I really appreciate this :-)
Attached patch patch rev1 (obsolete) — Splinter Review
Not sure what is causing this as of yet but I'm cleaning up a couple of things and added logging to the file / dir cleanup since the log with this failure also had a failure there.
Attached patch patch rev2 (obsolete) — Splinter Review
Little cleaner
Attachment #689370 - Attachment is obsolete: true
Note: in comment #389 the updated.update_in_progress.lock is still present
What I think is happening is the update's state is initially set to pending instead of pending-svc, the update is processed in the background, the update's state is checked in checkUpdateApplied before it has changed, it calls finishTest on a timeout, and though I haven't verified the code for this part it is changed to pending-service at this point which causes the test failure.
Attached patch patch rev3 (obsolete) — Splinter Review
Pushed to try
https://tbpl.mozilla.org/?tree=Try&rev=e29539775868
Attachment #689377 - Attachment is obsolete: true
Attachment #689516 - Flags: review?(netzen)
Comment on attachment 689516 [details] [diff] [review]
patch rev3

This doesn't appear to solve this so clearing review.
Attachment #689516 - Flags: review?(netzen)
Comment on attachment 689516 [details] [diff] [review]
patch rev3

This actually might solve this bug but one of my other changes to fix the lock file exposed what appears to be a bug with it.
Comment on attachment 689570 [details] [diff] [review]
patch rev4

Brian, if this try push looks ok could you review this? Thanks
https://tbpl.mozilla.org/?tree=Try&rev=c749f78755b1&noignore=1
Attachment #689570 - Flags: review?(netzen)
Comment on attachment 689570 [details] [diff] [review]
patch rev4

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

Looks good, thanks for taking this bug. Hope this puts an end to it :)
Attachment #689570 - Flags: review?(netzen) → review+
https://hg.mozilla.org/mozilla-central/rev/43ca2f335378
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla20
Comment on attachment 689570 [details] [diff] [review]
patch rev4

Test fix for aurora and beta. I'm fine with it not being approved but it should lessen oranges on these branches and it has no impact on users.
Attachment #689570 - Flags: approval-mozilla-beta?
Attachment #689570 - Flags: approval-mozilla-aurora?
Comment on attachment 689570 [details] [diff] [review]
patch rev4

Just found out that the approval exemption still applies to tests so clearing
Attachment #689570 - Flags: approval-mozilla-beta?
Attachment #689570 - Flags: approval-mozilla-aurora?
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: