mochitest-browser-chrome causes millions of ASSERTIONS "XPConnect is being called on a scope without a 'Components' property!"

RESOLVED WORKSFORME

Status

defect
RESOLVED WORKSFORME
10 years ago
6 years ago

People

(Reporter: murali, Unassigned)

Tracking

Trunk
x86
All
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(6 attachments, 1 obsolete attachment)

Reporter

Description

10 years ago
Dave Townsend was investigating XPINSTALL code coverage issues and tried to 'bunzip2' the mochitest-browser-chrome.log.bz2 file.

He got the following error

I'm trying to look at one of the logs from this run however it appears
to be corrupt. I get the following:

lambda:logs dave$ bunzip2 -v mochitest-browser-chrome.log.bz2
   mochitest-browser-chrome.log.bz2:
bunzip2: Compressed file ends unexpectedly;
        perhaps it is corrupted?  *Possible* reason follows.
bunzip2: No such file or directory
        Input file = mochitest-browser-chrome.log.bz2, output file =
mochitest-browser-chrome.log

It is possible that the compressed file(s) have become corrupted.
You can use the -tvv option to test integrity of such files.

You can use the `bzip2recover' program to attempt to recover
data from undamaged sections of corrupted files.

bunzip2: Deleting output file mochitest-browser-chrome.log, if it exists. 


When I tried it on winXP 32 bit with WinRAR, I got the following error after 100% unrar activity.

!   C:\Documents and Settings\mnandigama\Local Settings\Temp\Rar$DI00.531\mochitest-browser-chrome.log.bz2: Unexpected end of archive


This is by far the biggest log file in the full packet. 

Please help.
Reporter

Updated

10 years ago
Depends on: 505765
Buildbot terminated the mochitest-browser-chrome part of the run when it got no output after 43200 seconds. IIRC the process list had fix-linux-stack.pl running, so this looks like fallout from bug 385248.
Depends on: 385248
Summary: Codecoverage build logs archives seems to be corrupt. → Codecoverage mochitest-browser-chrome log archive seems to be corrupt
fix-linux-stack.pl should be running the entire time the test is running.  I don't think the fact that it's running says that it's the source of the problem.

Comment 3

10 years ago
This happened in the run of:
- Tue Aug 11 21:56:42 2009
- Sat Aug 15 03:02:01 2009

I assume this can be tried to be fixed/tracked down by doing local runs, right?

Who could take ownership of it?
Reporter

Comment 4

10 years ago
Armen, I presume the question is directed to team members of RE team. Some one who runs it on the RE setup only can reproduce it to validate the scenario.
The sequence of problems is
* mochitest-browser-chrome log is corrupted, because
* buildbot aborted the mochitest-browser-chrome after it failed to complete within 12 hours, because
* there are more than 2 million instances of
!!! ASSERTION: XPConnect is being called on a scope without a 'Components' property!: 'Error', file /builds/moz2_slave/mozilla-central-linux-codecoverage/build/js/src/xpconnect/src/xpcwrappednativescope.cpp, line 786
in the bzip2recover'd log, which is several GB in size when uncompressed.

The way to solve the problem is to prevent the ASSERTIONS, and so avoid many many calls to fix-linux-stack.pl. No idea if this is a problem in the Firefox code, or code-coverage, or both, but I note that we hit approximately 175 of these ASSERTIONS if you run mochitest-browser-chrome on a regular linux debug build.
Component: Release Engineering → Code Coverage
OS: Windows XP → All
Product: mozilla.org → Testing
QA Contact: release → codecoverage
Version: other → Trunk
Summary: Codecoverage mochitest-browser-chrome log archive seems to be corrupt → Codecoverage mochitest-browser-chrome causes millions of ASSERTIONS "XPConnect is being called on a scope without a 'Components' property!"
The first 5 log fragments from bzip2recover. There are 1023 XPConnect assertions in here, plus 13 other miscellaneous ones.
According to bug 372581 comment 84 this is not specific to codecoverage, and probably blocks enabling unit tests on debug builds.
Blocks: 372581
Summary: Codecoverage mochitest-browser-chrome causes millions of ASSERTIONS "XPConnect is being called on a scope without a 'Components' property!" → mochitest-browser-chrome causes millions of ASSERTIONS "XPConnect is being called on a scope without a 'Components' property!"
http://hg.mozilla.org/users/dbaron_mozilla.com/patches/raw-file/56363c473a65/no-components-dump-stack is a patch that will add more information (the JS stack, which is critical for diagnosing what's going on with this assertion) to the logs.

Could somebody who's seeing millions of assertions here do a run with that patch and attach a reasonable subset of the log so we can see what their cause is?  (I'm seeing 117 of these assertions on a full mochitest-browser-chrome run, and from various causes.  So a "reasonable subset" should include at least a few hundred just so we can see which is causing the large number; probably around 1000 is best.)
Reporter

Comment 10

10 years ago
I'm on it
Reporter

Comment 11

10 years ago
dbaron, your patch failed to apply on the trunk

mnandigama@murali-desktop:~/src$ hg import ../no-components-dump-stack 
applying ../no-components-dump-stack
patching file js/src/xpconnect/src/xpcwrappednativescope.cpp
Hunk #1 FAILED at 774
1 out of 1 hunk FAILED -- saving rejects to file js/src/xpconnect/src/xpcwrappednativescope.cpp.rej
abort: patch failed to apply
Just hand-edit in the one line right below that NS_ERROR, then.
Here's the output of:

grep "\(XPConnect is being\|^<function \|^file \)" browserchromelog.log | tr '\n\a' ' \n' | sort | uniq -c


unfortunately, the vast majority of the assertions (197118 of 197255) have no stack printed.  I'm not sure why that would happen.

However, all of the assertions with no stack printed are during shutdown of the tests, and the only useful information printed (other than the stack to the assertions) is a JavaScript error.  I'll attach the bit that repeats in the next attachment.
Posted file the part that repeats β€”
Here's the part that repeats 98553 times (although I think the stacks change for the last few repetitions):  two assertions and then a JS error.


Near the end of these repetitions, there are two other messages I noticed that *could* be related:

************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'[JavaScript Error: "this.outputStream is null" {file: "file:///home/mnandigama/mozcentral-dbg/dist/bin/components/GPSDGeolocationProvider.js" line: 226}]' when calling method: [nsIGeolocationProvider::shutdown]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "<unknown>"  data: yes]
************************************************************

************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: file:///home/mnandigama/mozcentral-dbg/dist/bin/components/NetworkGeolocationProvider.js :: anonymous :: line 375"  data: no]
************************************************************
(In reply to comment #14)
> stack printed.  I'm not sure why that would happen.

Actually, I do know:  there's no JS on the stack at the time, so there's nothing to print.
The console service uses XPCOM proxies, though, so the assertions seem likely to be related to that error message, and perhaps to some unbalanced calls here:
http://mxr.mozilla.org/mozilla-central/search?string=registerlistener
What command line did you use to run the tests?
Reporter

Comment 19

10 years ago
make mochitest-browser-chrome from the OBJDIR
No longer blocks: 372581
Posted patch debugging patch (obsolete) β€” β€” Splinter Review
This adds sufficient debugging information to debug these assertions based on the output.  (The dumping-the-object part is the most useful, but I think the JS stack has turned out to be useful in one warning.)
Attachment #492731 - Flags: review?(mrbkap)
As the reviewer of http://hg.mozilla.org/mozilla-central/rev/fb3a90e23a98 , I claim you're a good reviewer for this as well.  This should eliminate most of the guesswork from the analysis I've been doing with the above patch, though I still need to get a new set of mochitest logs with it.
Attachment #492782 - Flags: review?(mrbkap)
Attachment #492782 - Flags: review?(mrbkap) → review+
Comment on attachment 492731 [details] [diff] [review]
debugging patch

I wonder if xpc_DumpJSStack might work as well or better.
Attachment #492731 - Flags: review?(mrbkap) → review+
Posted patch debugging patch β€” β€” Splinter Review
Revised per your suggestion, and also to loop over proxies since there are a bunch of assertions in some of the mochitest-plain tests that require such a loop.
Attachment #492731 - Attachment is obsolete: true
Attachment #492902 - Flags: review?(mrbkap)
Comment on attachment 492902 [details] [diff] [review]
debugging patch

>diff --git a/js/src/xpconnect/src/xpcwrappednativescope.cpp b/js/src/xpconnect/src/xpcwrappednativescope.cpp
>+    while (p->isProxy()) {

Nit: while( instead of while ( and brace on the next line.

>+        p = p->getProxyPrivate().toObjectOrNull();
>+        if(!p)
>+            break;
>+        printf("which is a proxy for:\n");
>+        js_DumpObject(p);

Non-nit: you probalby |while (p->isWrapper()) { ... same body ... }| instead of isProxy.

r=me with those addressed.
Attachment #492902 - Flags: review?(mrbkap) → review+
And I relanded the part of the debugging patch that I previously had to revert:
http://hg.mozilla.org/mozilla-central/rev/bc2fda9a8b32
Depends on: 631447
I believe bug 631447 says it wasn't very safe: a suite-aborting infinite loop of assertions and stacks ending in a 50MB log that was too much for anyone to bother looking at for two weeks, with the extra bonus on OS X of failing to kill httpd.js so that it not only aborts mochitest-browser-chrome, but also kills mochitest-ipcplugins.
No longer depends on: 614320
This assertion is long gone.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.