Closed Bug 909282 Opened 11 years ago Closed 10 years ago

Intermittent test_cache_jar.js | test failed (with xpcshell return code: 0) | 0 == 1 | Error in closure function: 2147500036

Categories

(Core :: Networking: JAR, defect)

Product:
Core
Component:
Networking: JAR
Platform:
x86
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED WORKSFORME

People

(Reporter: RyanVM, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Wait to continue testing cached responses until the cache signals that all eviction has finished.
3.31 KB, patch
Details | Diff | Splinter Review 
Josh, I see you wrote this test. Can you please take a look? I'll file another bug for the System JS error as well since I assume it's unrelated to this.

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

Ubuntu VM 12.04 mozilla-central debug test xpcshell on 2013-08-23 15:33:01 PDT for push 6dea0e001df0
slave: tst-linux32-ec2-048

15:52:03     INFO -  TEST-INFO | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | running test ...
15:52:05  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | test failed (with xpcshell return code: 0), see following log:
15:52:05     INFO -  >>>>>>>
15:52:05     INFO -  System JS : WARNING /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js:51
15:52:05     INFO -                       yield without a value is deprecated, and illegal in ES6 (use 'yield undefined' instead)
15:52:05     INFO -  System JS : WARNING /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js:71
15:52:05     INFO -                       yield without a value is deprecated, and illegal in ES6 (use 'yield undefined' instead)
15:52:05     INFO -  System JS : WARNING /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js:85
15:52:05     INFO -                       yield without a value is deprecated, and illegal in ES6 (use 'yield undefined' instead)
15:52:05     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test pending (1)
15:52:05     INFO -  TEST-INFO | (xpcshell/head.js) | test pending (2)
15:52:05     INFO -  TEST-INFO | (xpcshell/head.js) | test MAIN run_test finished (2)
15:52:05     INFO -  TEST-INFO | (xpcshell/head.js) | running event loop
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 1 == 1
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 1 == 1
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 1 == 1
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 1 == 1
15:52:05     INFO -  WARNING: SQLite returned error code 1 , Storage will convert it to NS_ERROR_FAILURE: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 79
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 0 == 0
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 0 == 0
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | [doneSecondLoad : 107] 0 == 0
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05     INFO -  TEST-PASS | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | [ChannelListener.prototype.onStopRequest : 162] 10 == 10
15:52:05  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js | 0 == 1 - See following stack:
15:52:05     INFO -  JS frame :: /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/test_cache_jar.js :: doneSecondLoad :: line 107
15:52:05     INFO -  JS frame :: /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js :: ChannelListener.prototype.onStopRequest :: line 167
15:52:05     INFO -  native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
15:52:05     INFO -  TEST-INFO | (xpcshell/head.js) | exiting test
15:52:05  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js | Error in closure function: 2147500036 - See following stack:
15:52:05     INFO -  JS frame :: /builds/slave/test/build/tests/xpcshell/tests/netwerk/test/unit/head_channels.js :: ChannelListener.prototype.onStopRequest :: line 169
15:52:05     INFO -  native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
15:52:05     INFO -  TEST-INFO | (xpcshell/head.js) | exiting test
15:52:05     INFO -  System JS : ERROR (null):0
15:52:05     INFO -                       uncaught exception: 2147500036
15:52:05     INFO -  WARNING: An event was posted to a thread that will never run it (rejected): file ../../../xpcom/threads/nsThread.cpp, line 353
15:52:05     INFO -  WARNING: unable to post continuation event: file ../../../xpcom/io/nsStreamUtils.cpp, line 438
15:52:05     INFO -  WARNING: NS_ENSURE_TRUE(mDB) failed: file ../../../netwerk/cache/nsDiskCacheDeviceSQL.cpp, line 1401
15:52:05     INFO -  WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file ../../../xpcom/threads/nsThread.cpp, line 435
15:52:05     INFO -  !!! error running onStopped callback: TypeError: callback is not a function
15:52:05     INFO -  WARNING: nsExceptionService ignoring thread destruction after shutdown: file ../../../xpcom/base/nsExceptionService.cpp, line 151
15:52:05     INFO -  WARNING: NS_ENSURE_TRUE(compMgr) failed: file nsComponentManagerUtils.cpp, line 58
15:52:05     INFO -  WARNING: OOPDeinit() without successful OOPInit(): file ../../../toolkit/crashreporter/nsExceptionHandler.cpp, line 2304
15:52:05     INFO -  nsStringStats
15:52:05     INFO -   => mAllocCount:           2937
15:52:05     INFO -   => mReallocCount:          258
15:52:05     INFO -   => mFreeCount:            2936  --  LEAKED 1 !!!
15:52:05     INFO -   => mShareCount:           8636
15:52:05     INFO -   => mAdoptCount:            193
15:52:05     INFO -   => mAdoptFreeCount:        193
15:52:05     INFO -  <<<<<<<
This is my only guess as to why we would find a valid cached response after specifically clearing the cache.
Attachment #797593 - Flags: review?(jduell.mcbugs)
Assignee: nobody → josh
Comment on attachment 797593 [details] [diff] [review]
Wait to continue testing cached responses until the cache signals that all eviction has finished.

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

Michal, do we need to wait like this for cache to be evicted?
Attachment #797593 - Flags: review?(jduell.mcbugs) → review?(michal.novotny)
Comment on attachment 797593 [details] [diff] [review]
Wait to continue testing cached responses until the cache signals that all eviction has finished.

(In reply to Jason Duell (:jduell) from comment #3)
> Michal, do we need to wait like this for cache to be evicted?

I don't think this is necessary unless some of the webapps-clear-data observers causes processing of the pending events.

Anyway, I think that the code in nsCacheService::EvictEntriesForClient() that posts cacheservice:empty-cache notification is wrong. It dispatches the event before the entries are evicted and even before the cache lock is obtained. So if the code is called off the main thread (which isn't of course in case of this unit test) the observer on the main thread could be notified before the entries are really evicted.
Attachment #797593 - Flags: review?(michal.novotny)
This seems to be triggered more often when the new cache is on.  Either the test is broken or we have a bug.

Rather tracking.
Assignee: josh → nobody
Depends on: 977766
Unblocking cache2, fixed with 977766.
No longer blocks: cache2tests
Closing bugs where TBPLbot has previously commented, but have now not been modified for >3 months & do not contain the whiteboard strings for disabled/annotated tests or use the keyword leave-open. Filter on: mass-intermittent-bug-closure-2014-07
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: