Call to xpconnect wrapped JSObject produced this error: * [Exception... "'[JavaScript Error: "nBox.getNotificationWithValue is not a function" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 1822}]' when calling method:

RESOLVED FIXED in Thunderbird 28.0

Status

Thunderbird
Message Compose Window
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: ISHIKAWA, Chiaki, Assigned: aceman)

Tracking

(Blocks: 1 bug)

Trunk
Thunderbird 28.0
All
Linux
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(3 attachments, 1 obsolete attachment)

(Reporter)

Description

5 years ago
Created attachment 799017 [details] [diff] [review]
Print additional information about URL path in chrome handler for debugging purposes.

(I captured the error under Debian GNU/Linux. But presumably it may be common to all architecture since the problem is in JS component.)


When I run DEBUG BUILD of TB, I get an exception thrown all the way to
the top of javascript interpreter. (It was recorded 28 times at last count
durin the run of |make mozmill| test suite. With this frequency and diminishing serious errors, at least noticed by |make mozmill|, this issue is now located near the top of error list.)

************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'[JavaScript Error: "nBox.getNotificationWithValue is not a function" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 1822}]' when calling method: [nsITimerCallback::notify]"	nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]

The code in question is as follows.
The line marked with "-->" is where the error occurs.

  /**
   * Check for attachment keywords, and display a notification if it's
   * appropriate.
   */
  function CheckForAttachmentNotification(event)
  {
    if (!CheckForAttachmentNotification.shouldFire || gRemindLater)
      return;
    if (!event)
      attachmentWorker.lastMessage = null;
    CheckForAttachmentNotification.shouldFire = false;
    let nBox = document.getElementById("attachmentNotificationBox");
--> let notification = nBox.getNotificationWithValue("1");
    let removeNotification = false;

    if (!ShouldShowAttachmentNotification(true)) {
      removeNotification = true;
      CheckForAttachmentNotification.shouldFire = true;
    }

  if (notification && removeNotification)
    nBox.removeNotification(notification);
};


Looking at it, I have a suspicion that nBox has a value that
is not quite expected. 
(Maybe document.getElementById("attachmentNotificationBox") failed?)
I am not even sure if |document| contains a valid value by looking at the
session log. But if so, how the test passed successfully (!?)

Here is a log from one test that produces the error.
There are so many suspicious WARNING lines, and I am not sure which to
blame.

TEST-START | /COMM-CENTRAL/comm-central/mail/test/mozmill/cloudfile/test-cloudfile-attachment-urls.js | test_inserts_linebreak_on_empty_compose
Step Pass: {"function": "Controller.keypress()"}
++DOCSHELL 0x5dcc830 == 15 [id = 21]
++DOMWINDOW == 29 (0x4dec328) [serial = 48] [outer = (nil)]
++DOCSHELL 0x1e05660 == 16 [id = 22]
++DOMWINDOW == 30 (0x3e509d8) [serial = 49] [outer = (nil)]
++DOCSHELL 0x4f62f50 == 17 [id = 23]
++DOMWINDOW == 31 (0x52715c8) [serial = 50] [outer = (nil)]
WARNING: NS_ENSURE_TRUE(NS_SUCCEEDED(rv) && subjPrincipal) failed: file /COMM-CENTRAL/comm-central/mozilla/docshell/base/nsDocShell.cpp, line 8393
WARNING: NS_ENSURE_TRUE(NS_SUCCEEDED(rv) && subjPrincipal) failed: file /COMM-CENTRAL/comm-central/mozilla/docshell/base/nsDocShell.cpp, line 8393
WARNING: Subdocument container has no frame: file /COMM-CENTRAL/comm-central/mozilla/layout/base/nsDocumentViewer.cpp, line 2339
++DOMWINDOW == 32 (0x5e33528) [serial = 51] [outer = 0x4dec328]
++DOMWINDOW == 33 (0x16cfeb8) [serial = 52] [outer = 0x3e509d8]
WARNING: Subdocument container has no frame: file /COMM-CENTRAL/comm-central/mozilla/layout/base/nsDocumentViewer.cpp, line 2339
++DOMWINDOW == 34 (0x5e33138) [serial = 53] [outer = 0x52715c8]
++DOMWINDOW == 35 (0x49429a8) [serial = 54] [outer = 0x3e509d8]
WARNING: NS_ENSURE_TRUE(aSelection->GetRangeCount()) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/base/nsEditor.cpp, line 3806
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/base/nsEditor.cpp, line 3785
WARNING: NS_ENSURE_SUCCESS(res, res) failed with result 0x80004005: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditRules.cpp, line 316
WARNING: NS_ENSURE_TRUE(sheet) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2955
WARNING: NS_ENSURE_TRUE(aNode) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/base/nsEditor.cpp, line 3480

    The following output, "Resolved URL was ..." is printed by my
    change to investigate strange ".../null" path name for resolved
    URL printed in "Chrome file doesn't exist".  See the attached
    more-debug-output-from-chrome-handler.patch. I printed this
    additional message since originally the strange message such as
    "Chrome file doesn't exist:
    /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null"
    might be the cause of "nBox.getNotificationWithValue is not a
    function" error. But I am not sure.
    Again, this is a local build and tested locally. I wonder
    if I need to set up special network proxy or something.
    (But if so, I think the test harness invoked by |make mozmil|
    ought to have set it up already.
    

Resolved URL was file:///TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null, aURI was chrome://messenger/content/messengercompose/null
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
WARNING: We should have hit the document element...: file /COMM-CENTRAL/comm-central/mozilla/layout/xul/base/src/nsBoxObject.cpp, line 177
Resolved URL was file:///TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null, aURI was chrome://messenger/content/messengercompose/null
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/classic/skin/classic/messenger/icons/dropbox.png
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/classic/skin/classic/messenger/icons/dropbox.png
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
Step Pass: {"function": "controller.waitFor()"}
Step Pass: {"function": "controller.waitFor()"}
Step Pass: {"function": "controller.waitFor()"}
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(editor) failed: file /COMM-CENTRAL/comm-central/mozilla/extensions/spellcheck/src/mozInlineSpellChecker.cpp, line 1808
WARNING: NS_ENSURE_TRUE(editor) failed: file /COMM-CENTRAL/comm-central/mozilla/extensions/spellcheck/src/mozInlineSpellChecker.cpp, line 707
++DOCSHELL 0x47b1c30 == 18 [id = 24]
++DOMWINDOW == 36 (0x42a9058) [serial = 55] [outer = (nil)]
++DOMWINDOW == 37 (0x4aba9a8) [serial = 56] [outer = 0x42a9058]
Step Pass: {"function": "Controller.keypress()"}
++DOCSHELL 0x46d1be0 == 19 [id = 25]
++DOMWINDOW == 38 (0x4eb5578) [serial = 57] [outer = (nil)]
++DOCSHELL 0x5bab940 == 20 [id = 26]
++DOMWINDOW == 39 (0x381cb48) [serial = 58] [outer = (nil)]
++DOCSHELL 0x4eb3ee0 == 21 [id = 27]
++DOMWINDOW == 40 (0x4e90398) [serial = 59] [outer = (nil)]
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'[JavaScript Error: "nBox.getNotificationWithValue is not a function" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 1822}]' when calling method: [nsITimerCallback::notify]"	nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]
************************************************************
WARNING: NS_ENSURE_TRUE(NS_SUCCEEDED(rv) && subjPrincipal) failed: file /COMM-CENTRAL/comm-central/mozilla/docshell/base/nsDocShell.cpp, line 8393
WARNING: NS_ENSURE_TRUE(NS_SUCCEEDED(rv) && subjPrincipal) failed: file /COMM-CENTRAL/comm-central/mozilla/docshell/base/nsDocShell.cpp, line 8393
WARNING: Subdocument container has no frame: file /COMM-CENTRAL/comm-central/mozilla/layout/base/nsDocumentViewer.cpp, line 2339
++DOMWINDOW == 41 (0x245cc08) [serial = 60] [outer = 0x4eb5578]
++DOMWINDOW == 42 (0x5ca1ca8) [serial = 61] [outer = 0x381cb48]
WARNING: Subdocument container has no frame: file /COMM-CENTRAL/comm-central/mozilla/layout/base/nsDocumentViewer.cpp, line 2339
++DOMWINDOW == 43 (0x5d07ee8) [serial = 62] [outer = 0x4e90398]
++DOMWINDOW == 44 (0x3d15b48) [serial = 63] [outer = 0x381cb48]
WARNING: NS_ENSURE_TRUE(aSelection->GetRangeCount()) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/base/nsEditor.cpp, line 3806
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/base/nsEditor.cpp, line 3785
WARNING: NS_ENSURE_SUCCESS(res, res) failed with result 0x80004005: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditRules.cpp, line 316
WARNING: NS_ENSURE_TRUE(sheet) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2955
Resolved URL was file:///TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null, aURI was chrome://messenger/content/messengercompose/null
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
WARNING: We should have hit the document element...: file /COMM-CENTRAL/comm-central/mozilla/layout/xul/base/src/nsBoxObject.cpp, line 177
Resolved URL was file:///TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null, aURI was chrome://messenger/content/messengercompose/null
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/messenger/content/messenger/messengercompose/null
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
Chrome file doesn't exist: /TEST-MAIL-DIR/objdir-tb3/mozilla/dist/bin/chrome/classic/skin/classic/messenger/icons/dropbox.png
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 215
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /COMM-CENTRAL/comm-central/mozilla/netwerk/base/src/nsFileStreams.cpp, line 487
WARNING: NS_ENSURE_TRUE(nextNode) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 940
WARNING: NS_ENSURE_TRUE(nextNode) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 940
Step Pass: {"function": "controller.waitFor()"}
Step Pass: {"function": "controller.waitFor()"}
Step Pass: {"function": "controller.waitFor()"}
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(ps) failed: file /COMM-CENTRAL/comm-central/mozilla/editor/libeditor/html/nsHTMLEditor.cpp, line 2959
WARNING: NS_ENSURE_TRUE(editor) failed: file /COMM-CENTRAL/comm-central/mozilla/extensions/spellcheck/src/mozInlineSpellChecker.cpp, line 1808
WARNING: NS_ENSURE_TRUE(editor) failed: file /COMM-CENTRAL/comm-central/mozilla/extensions/spellcheck/src/mozInlineSpellChecker.cpp, line 707
++DOCSHELL 0x52a5dd0 == 22 [id = 28]
++DOMWINDOW == 45 (0x1b4be98) [serial = 64] [outer = (nil)]
++DOMWINDOW == 46 (0x1686cb8) [serial = 65] [outer = 0x1b4be98]
TEST-PASS | /COMM-CENTRAL/comm-central/mail/test/mozmill/cloudfile/test-cloudfile-attachment-urls.js | test-cloudfile-attachment-urls.js::test_inserts_linebreak_on_empty_compose

TIA
(Reporter)

Comment 1

5 years ago
Created attachment 803539 [details]
A log to show the problem in more detail with dump statements to print nBox.getNoficationWithValue.

I am attaching an excerpt from a log after I added
a few dump statements to see what is going on.:
Here is the modified CheckForAttachmentNotification() (line 1825 in
MsgComposeCommands.jsis part of this function. The error occurs at the line with "--->".
(Since I have modified MsgComoseCommands.js for debugging, the line
number may vary slightly from the pristine comm-central source. YMMV.)

    function CheckForAttachmentNotification(event)
    {
      if (!CheckForAttachmentNotification.shouldFire || gRemindLater)
	return;
      if (!event)
	attachmentWorker.lastMessage = null;
      CheckForAttachmentNotification.shouldFire = false;
      let nBox = document.getElementById("attachmentNotificationBox");
=>    dump ( "nBox = " + nBox + " (in CheckForAttachmentNotification)\n");
=>    dump ( "nBox.getNotificationWithValue = " + nBox.getNotificationWithValue + "\n");
=>    dump ( "nBox.removeNotification       = " + nBox.removeNotification + "\n");
--->  let notification = nBox.getNotificationWithValue("1");
      let removeNotification = false;

      if (!ShouldShowAttachmentNotification(true)) {
	removeNotification = true;
	CheckForAttachmentNotification.shouldFire = true;
      }

      if (notification && removeNotification)
	nBox.removeNotification(notification);
    };


I am attaching a log from a run of the following command:
make SOLO_TEST=cloudfile/test-cloudfile-attachment-urls.js mozmill-one
(This is only one of the targets that produced the errors during |make
mozmill| run.)

In it, you can see that nBox.getNotificatonWithValue gets initialized
and then reset to undefined for no apparent reason (well, it is not
clear why to me.) In one instance, I am not sure if it ever gets
initialized since the first dump shows the values are undefined.
(the case of test_inserts_linebreak_on_empty_compose_with_signature ).

I wonder if people in the know can figure out what went wrong.
The code above does not seem to have been changed recently and so
I suspect some interactions of recent changes in the underlying event
handling codes, etc. may have caused this issue.

Superficially, I can think of a temporary bandage such as
checking |if (!nBox.getNotificationWithValue) | and
sets |notification| to |false| without calling |getNotificaitonWithVAlue()|
if so.
But given the code seems to have been running without producing such 
errors before, I think someone needs to look into the issue.
I wonder where getNotificationWithValue becomes undefined where nBox
itself seems to exist after all.

What puzzles me is that the test passes even though these
strange errors are thrown (!?)

TIA
(Reporter)

Updated

5 years ago
Attachment #803539 - Attachment mime type: text/x-log → text/plain
(Reporter)

Updated

5 years ago
Assignee: nobody → ishikawa
(Reporter)

Comment 2

5 years ago
I should mention that this is the most frequent Errors thrown (28 times) during |make mozmill| run.
after other errors have been fixed 

Help will be appreciated.

TIA
(Assignee)

Comment 3

5 years ago
Suyash, while you worked on the bug with on changes in the notification bar for attachments, did you get any idea what this nBox.getNotificationWithValue("1") may want?
(Reporter)

Comment 4

5 years ago
Interesting data point.

This warning first appeared in my local testing on March 23
for test target, "TEST-START | /COMM-CENTRAL/comm-central/mail/test/mozmill/composition/test-image-insertion-dialog.js | test_image_insertion_dialog_persist".

At the time
the hg identify shows for local comm-central,
/COMM-CENTRAL/comm-central
hg identify
d6fe1500ab71+ qtip/tip/trychooser.patch

(But do note that the error message is NOT printed in every |make mozmill| session.
It can be timing-dependent :-( 
There are session logs after this date that don't print this message occasionally.
Even on the same day the first message line appeared on March 23, I had another log that
did not have this message.
 
Starting around the end of July, this message appears more or less  every time |make mozmill| session is recorded. [It may be that the problem became severer early July.] So this message is very distracting now.

Logs on my local PC that has this message lines.
Output of the following command on my PC's directory that stores logs.
ls -tr | xargs egrep -l getNotificationWithValue  

log57.txt  <--- March 23th. There is log58.txt on the same day that did not have this line.
log59.txt
log65.txt
log70.txt
log70-summary.txt
log70-fixed.txt
log72.txt
log72-summary.txt
log75-summary.txt
log75.txt
log91.txt
log99-mozmill-original.txt
log99-mozmill-original-smmmary.txt
log114-mozmill-original.txt                
   <--- since around this log (recorded on July 29th), the message appears almost
   always. (Note that some logs are for compilation recording, etc. 
   and do not contain full |make mozmill| session log. Thus may not be printed here.)
log115-mozmil-original.txt
log115-mozmil-original-fixed-stack.txt
log116-mozmill-original.txt
log116-mozmill-original-summary.txt
log115-mozmill-original-summary.txt
log117-mozmill-original.txt
log118-mozmill-original.txt
log119-mozmill-original.txt
log119-mozmill-original-summary.txt
log120-mozmill-original.txt
log120-mozmill-original-summary.txt
log114-mozmill-original-summary.txt
log121-summary.txt
log121-mozmill-original-ref-comm-central.txt
log122-momill-original-ref-comm-central.txt
log123-mozmill-comm-central.txt
log124-mozmill-comm-central.txt
log125-mozmill-comm-central.txt
log125-mozmill-comm-central-summary.txt
log126-mozmill-comm-central.txt
log126-mozmill-comm-central-summary.txt
log127-mozmill-comm-central.txt
log127-mozmill-comm-central-summary.txt
log128-mozmill-comm-central.txt
log129-mozmill-comm-central-memcheck.txt
log130-mozmill-comm-central.txt
log131-mozmill-original.txt
          I switched from 32bits linux to 64bits linux and bumped the
          log file number (so log204 immediately follows log131.)
log204-mozmill-comm-central.txt
log205-mozmill-original.txt
log206-mozmill-original.txt
log207-mozmill-original.txt
log209-mozmill-memcheck.txt
log210-mozmill-original.txt
log211-mozmill-original-comm-central.txt
log212-mozmill-original.txt
log215-mozmill-original.txt
log216-mozmill-original.txt
log217-mozmill-original.txt
log218-mozmill-original.txt
log219-mozmill-original-comm-central.txt
log220-mozmill-original-comm-central.txt
log221-mozmill-original.txt
log226-mozmill.txt
log231-mozmill.txt~
log231-mozmill.txt
log233-mozmill.txt~
log234-mozmill.txt~
log234-mozmill.txt
log233-mozmill.txt
log235-mozmill.txt
log236-mozmill.txt
log238-mozmill.txt
log239-mozmill.txt
log240-mozmill.txt
log241-mozmill-ref.txt
log242-mozmill-ref.txt
log243-mozmill-ref.txt
log244-mozmill.txt
log245-mozmill.txt
log246-mozmill.txt
log247-mozmill.txt  <- Sept 12th ( a few hours ago)

Hope this helps.
(Assignee)

Comment 5

5 years ago
I can confirm I also see this error in my local mozmill runs (e.g. cloudfile/test-cloudfile-attachment-urls.js).
(Assignee)

Comment 6

5 years ago
Created attachment 804050 [details] [diff] [review]
patch

I have instrumented the cloudfile/test-cloudfile-attachment-urls.js test and it shows that there are case where nBox is a notificationbox XUL element, but it still somehow does not have the properties and methods of it.

I ran the test in the foreground watching what it is doing. It was opening tons of compose windows but they often were blank (no body).

The attached patch fixes the problem in my local runs. Watching the test, the compose windows are now properly filled with the message and notifications that attachments were added.
Can you try it?
Assignee: ishikawa → acelists
Status: NEW → ASSIGNED
Attachment #804050 - Flags: feedback?(ishikawa)
(Reporter)

Comment 7

5 years ago
(In reply to :aceman from comment #6)
> Created attachment 804050 [details] [diff] [review]
> patch
> 
> I have instrumented the cloudfile/test-cloudfile-attachment-urls.js test and
> it shows that there are case where nBox is a notificationbox XUL element,
> but it still somehow does not have the properties and methods of it.
> 
> I ran the test in the foreground watching what it is doing. It was opening
> tons of compose windows but they often were blank (no body).
> 
> The attached patch fixes the problem in my local runs. Watching the test,
> the compose windows are now properly filled with the message and
> notifications that attachments were added.
> Can you try it?

Thank you, aceman. The patch did seem to fix the issue for that particular file.
(Oh wait, I still see one error, I am not sure why.)
But, there are other similar files that cause the issues. So I probably
need to patch other test files by placing a wait in strategic positions.

But thank you for find this out the hard way.

Incidentally, during the investigation of this and other bugs which throw NS_ERROR_* to the
top-level, I also noticed that inserting a delay or two in the test programs
seem to solve the observed problems, at least, for now.

Maybe I am one of the few people in the world who look at the screen during
|make mozmill| run to learn what type of tests are being performed.
What I noticed is over the last several months is that
as we move to a newer CPU hardware (more core and higher CPU clock),
and faster memory (higher bandwidth), we seem to be running test programs
at so fast a speed that the painting on the screen is no longer visible to the naked eye!
Or before the graphics system catches up writing something on the screen, main thread already decides to call it a quit (or, say, destroy a dialog) and so drawing is not finished completely.

Like you explained, sometimes I only see a rectangular blob where a dialog would have appeared, but the test proceeds without showing any characters or buttons in it. 
Sometimes the rectangular blob is so large as to hide the major portion of the original window, and I assume it must be a compose window or something, but again nothing is drawn inside and the blob disappears eventually. I can only guess something would have been drawn, but that thread is either
blocked, or that X drawing operation is not proceeding fast enough. (We can call Xflush() but
not guarantee the the graphics operation is finished by the time Xflush() returns, correct?) 

During debugging of other bug, I spotted an error message. After a dozen minutes 
of code-analysis and I could not figure out why a problem could occur, and on a hunch, I inserted mc.sleep(1000) in the javascript statements of the test program to see what is being drawn exactly on the screen for my visual inspection (since I saw only a rectangular blob until then).  Voila. I could see what was being drawn in the dialog, AND the error message is NO LONGER there!

So yes, I agree that we need to build or find out certain type of drawing barrier/event barrier to assure the test programmers to be convinced that all the drawing operations on the screen have been completed, and all event-related setup has been completed (including the placement of buttons and such that would have trigger an event for testing.)
Unless we can produce and show some reliable ways of creating such check points from the viewpoint of 
temporal order, these tests would remain inherently buggy.

Actually during the investigation for the cause of Bug 912172,
at one point, I wrote down a memo: It reads
we must have a folder being shown in the first place.
Aren't we running too fast to invoke the code here?
Has the display been prepared at the time when the test routine hits
the code here?
What is the proper way of saying "we wait until the objects to be
displayed are shown on the screen, and dust settles down."?

And indeed, the inserted delay in the test-side code eradicated
some of the error messages [without the code change in the main TB code at all.]
However, the error messages caused by the software interrupt was for real, and
so I had to change the TB code in the end. (Yes, this is what happened, and so the
flow of thoughts explained in Bug 912172 is a little bit skewed.)

To recap today's situation for testers:

There are more parallelism thanks to more powerful CPU and efficient libraries.
 -> This leads to more thread-race issues [which may have been hidden and dormant due to the
slow CPU and more or less serialized execution of code on the older systems.].

We now see relatively more faster processing of non-drawing operations in contrast to graphical operations. [X is not a speed daemon, and note PCs traditionally did not have
high-performance graphics power until recently.].
 -> So the test program's main logic may proceed ahead of the visual elements being laid down
    properly (and the graphics subsystem can respond properly about the
    layout of the elements and such.)

    (BTW, this, of course, is another manifestation of the greater parallelism on toady's PC.)

Anyway, so there seem to be cases when
- one can place a proper synchronization primitive to
  wait for these graphical operations (event handler placement as well) performed by
  other threads (like notification bar placement as you mention, etc.)

- or simply wait for a long enough time if such primitives are
  not obvious like we did here 
 (I think this is a bug of mozilla core toolkits if it is the case.)

But, at the same time,  I think we also need to tweak TB/FF main source code so that
such improper probing of internal transient states by such external programs are discouranged
and better and consistent instrumentation API functions are provided for
testing programs to check the operation and internal status 
(for testing, and  for application synchronization purposes, too.).
Yes, "Design for Testing" comes to my mind.

I myself found a few places where an insertion of wait seem to cure certain
warnings. In those case, I  don't know what are the proper primitives, too, like you.
These need to be investigated seriously for proper testing and long-term health of
mozilla codebase, especially for TB.

TIA

PS: I will investigate other files to shutdown these error messages.
(So it could be that my move to 64 bits from 32 bits and use -O2 for compilation
rather than -O in the old days may have increased the error frequencies for this bug.)
(Reporter)

Updated

5 years ago
Blocks: 826967
(Reporter)

Updated

5 years ago
See Also: → bug 916505
(Reporter)

Updated

5 years ago
Attachment #804050 - Flags: feedback?(ishikawa) → feedback+
(Assignee)

Comment 8

5 years ago
I can reproduce this error also manually when replying to a message, quickly typing in some letters into the body and clicking Send later. And there were no attachments in the message. The error gets into the console after clicking Send later.

Also, I do not see where we create a notification with value "1". There is only a call to appendNotification that sets a value of "attachmentReminder". Also, if I inlude the word "attach" into the body, the attachment notification bar pops up, but it never disappears even if I attach an attachment. Even when clicking Send, I still get the warning that attachment is missing. So either this is fallout of bug 521158 or this was broken for a while. I'll try to change the "1" to "attachmentReminder" and see what happens.
(Assignee)

Comment 9

5 years ago
So I have instrumented CheckForAttachmentNotification with a "debugger" keyword and this is the result when the error appears:
nBox=object
gMsgCompose=null
------------------------------------------------------------------------
Hit JavaScript "debugger" keyword. JS call stack...
0 CheckForAttachmentNotification(event = true) ["chrome://messenger/content/messengercompose/MsgComposeCommands.js":1948]
    this = [object ChromeWindow]
1 anonymous(timer = [xpconnect wrapped nsITimer @ 0xa003e440 (native @ 0xa2f981a0)]) ["chrome://messenger/content/messengercompose/MsgComposeCommands.js":4556]
    this = [object Object]

------------------------------------------------------------------------
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'[JavaScript Error: "nBox.getNotificationWithValue is not a function" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 1949}]' when calling m
ethod: [nsITimerCallback::notify]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]
************************************************************

So the function is called from a timer. My theory is that it may be run when the window is shutting down already. Expect a patch shortly.
(Assignee)

Comment 10

5 years ago
Created attachment 832595 [details] [diff] [review]
patch v2

OK, this looks conceptually better. Let's not call the function when the window is not ready. I have run some of the tests that had the error message and they are fixed by this. Chiaki, please run the whole mozmill to see if the error vanished everywhere.

I added some close_window into the cloudfile test as I didn't like it had kept ~20 compose windows opened while running.
Attachment #804050 - Attachment is obsolete: true
Attachment #832595 - Flags: feedback?(ishikawa)
(Reporter)

Comment 11

5 years ago
(In reply to :aceman from comment #10)
> Created attachment 832595 [details] [diff] [review]
> patch v2
> 
> OK, this looks conceptually better. Let's not call the function when the
> window is not ready. I have run some of the tests that had the error message
> and they are fixed by this. Chiaki, please run the whole mozmill to see if
> the error vanished everywhere.
>  
   ...

Thank you :aceman, I will try.
At last count I saw 29 errors of this nature in the whole |make mozmill| test run.
Let me see how few it can get :-)

Stay tuned.
(Reporter)

Comment 12

5 years ago
Great news. The error messages are completely eliminated!

Comparison of frequencies of "Exception... " error lines.

BEFORE:

==================================
Generic Exceptions just in case
==================================

     29 [Exception... "'[JavaScript Error: "nBox.getNotificationWithValue is not a function" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 1942}]' when calling method: [nsITimerCallback::notify]"	nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]
      6 [Exception... "'[JavaScript Error: "aMsgHdr is null" {file: "chrome://messenger/content/mailWindowOverlay.js" line: 2834}]' when calling method: [nsIMsgHeaderSink::onEndMsgHeaders]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]
      4 [Exception... "'[JavaScript Error: "this.view.displayedFolder is null" {file: "chrome://messenger/content/folderDisplay.js" line: 1072}]' when calling method: [nsIMsgSearchNotify::onSearchDone]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"	 location: "JS frame :: resource:///modules/searchSpec.js :: SearchSpec_dissociateView :: line 141"  data: yes]
      3 [Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIMsgMailNewsUrl.server]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: resource:///modules/activity/alertHook.js :: alertHook.onAlert :: line 48"  data: no]
      2 [Exception... "'<error>' when calling method: [nsIContentHandler::handleContent]"  nsresult: "0x805d0001 (<unknown>)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"	data: no]
      1 [Exception... "Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]"  nsresult: "0x80004003 (NS_ERROR_INVALID_POINTER)"	 location: "JS frame :: chrome://messenger/content/folderDisplay.js :: <TOP_LEVEL> :: line 2029"  data: no]
      1 [Exception... "'[JavaScript Error: "this.folderDisplay.view.dbView is null" {file: "chrome://messenger/content/messageWindow.js" line: 252}]' when calling method: [nsIMsgDBViewCommandUpdater::summarizeSelection]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: resource:///modules/dbViewWrapper.js :: DBViewWrapper__createView :: line 1047"  data: yes]
      1 [Exception... "'[JavaScript Error: "gMsgCompose is null" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 3266}]' when calling method: [nsIObserver::observe]"	nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: chrome://global/content/globalOverlay.js :: canQuitApplication :: line 45"	data: yes]
      1 [Exception... "'[JavaScript Error: "document.getElementById(...) is null" {file: "chrome://messenger/content/chat/imStatusSelector.js" line: 36}]' when calling method: [nsIObserver::observe]"	 nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: resource:///modules/chatHandler.jsm :: ChatCore.init/<.onPromptStart :: line 74"  data: yes]


AFTER:

==================================
Generic Exceptions just in case
==================================

      6 [Exception... "'[JavaScript Error: "aMsgHdr is null" {file: "chrome://messenger/content/mailWindowOverlay.js" line: 2834}]' when calling method: [nsIMsgHeaderSink::onEndMsgHeaders]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]
      4 [Exception... "'[JavaScript Error: "this.view.displayedFolder is null" {file: "chrome://messenger/content/folderDisplay.js" line: 1072}]' when calling method: [nsIMsgSearchNotify::onSearchDone]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"	 location: "JS frame :: resource:///modules/searchSpec.js :: SearchSpec_dissociateView :: line 141"  data: yes]
      3 [Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIMsgMailNewsUrl.server]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: resource:///modules/activity/alertHook.js :: alertHook.onAlert :: line 48"  data: no]
      2 [Exception... "'<error>' when calling method: [nsIContentHandler::handleContent]"  nsresult: "0x805d0001 (<unknown>)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"	data: no]
      1 [Exception... "Component returned failure code: 0x80004003 (NS_ERROR_INVALID_POINTER) [nsIMsgDBView.getMsgHdrsForSelection]"  nsresult: "0x80004003 (NS_ERROR_INVALID_POINTER)"	 location: "JS frame :: chrome://messenger/content/folderDisplay.js :: <TOP_LEVEL> :: line 2029"  data: no]
      1 [Exception... "'[JavaScript Error: "this.folderDisplay.view.dbView is null" {file: "chrome://messenger/content/messageWindow.js" line: 252}]' when calling method: [nsIMsgDBViewCommandUpdater::summarizeSelection]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: resource:///modules/dbViewWrapper.js :: DBViewWrapper__createView :: line 1047"  data: yes]
      1 [Exception... "'[JavaScript Error: "gMsgCompose is null" {file: "chrome://messenger/content/messengercompose/MsgComposeCommands.js" line: 3266}]' when calling method: [nsIObserver::observe]"	nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: chrome://global/content/globalOverlay.js :: canQuitApplication :: line 45"	data: yes]
      1 [Exception... "'[JavaScript Error: "document.getElementById(...) is null" {file: "chrome://messenger/content/chat/imStatusSelector.js" line: 36}]' when calling method: [nsIObserver::observe]"	 nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: resource:///modules/chatHandler.jsm :: ChatCore.init/<.onPromptStart :: line 74"  data: yes]


The patch works beautifully.


>So I have instrumented CheckForAttachmentNotification with a "debugger" keyword and this is the result when the error appears:

This "debugger" keyword thing sounds interesting. Is this how we can trigger JS debugger automatically?

From comment 10
> I added some close_window into the cloudfile test as I didn't like it had kept ~20 compose windows opened while running.

Yes, I also noticed this test. I was wondering why the windows were opened simultaneously but assumed
that there must have been a reason. So they were just left opened because closing them were forgotten !?


I probably
(Reporter)

Updated

5 years ago
Attachment #832595 - Flags: feedback?(ishikawa) → feedback+
(Assignee)

Updated

5 years ago
Attachment #832595 - Flags: review?(mkmelin+mozilla)
Attachment #832595 - Flags: review?(mconley)
(Assignee)

Comment 13

5 years ago
(In reply to ISHIKAWA, Chiaki from comment #12)
> The patch works beautifully.
Thanks for testing.

> >So I have instrumented CheckForAttachmentNotification with a "debugger" keyword and this is the result when the error appears:
> This "debugger" keyword thing sounds interesting. Is this how we can trigger
> JS debugger automatically?
No it just dumps the current stack (nesting of functions being called) at the spot where the "debugger" keyword is in the code. Nothing interactive.

> From comment 10
> > I added some close_window into the cloudfile test as I didn't like it had kept ~20 compose windows opened while running.
> Yes, I also noticed this test. I was wondering why the windows were opened
> simultaneously but assumed
> that there must have been a reason. So they were just left opened because
> closing them were forgotten !?
I don't know but probably it does not matter whether they are open simultaneously or not. I just assume it can take more memory to have many windows open and it also clutters the taskbar when watching the test. We can ask mconley whether the simultaneous opening is intentional or not.
Flags: needinfo?(mconley)
(Reporter)

Comment 14

5 years ago
(In reply to :aceman from comment #13)
> (In reply to ISHIKAWA, Chiaki from comment #12)
> > The patch works beautifully.
> Thanks for testing.
> 

You are very welcome.

> > >So I have instrumented CheckForAttachmentNotification with a "debugger" keyword and this is the result when the error appears:
> > This "debugger" keyword thing sounds interesting. Is this how we can trigger
> > JS debugger automatically?
> No it just dumps the current stack (nesting of functions being called) at
> the spot where the "debugger" keyword is in the code. Nothing interactive.

Is this it?
https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Statements/debugger
After all |make mozmill| or |make xpcshell-tests| are non-interactive, this would be handly.
Next time, I got hit by strange JS issue, I would try to use it.

THX

Re the windows kept open.: I wish the test programs have more comments.
I was trying to see why
mozilla/toolkit/mozapps/extensions/test/xpcshell/test_bug616841.js
was failing during |make xpcshell-tests| and
am baffled at the code. There must be a background of this test that will fill a page or two of A4 paper, and there is single "// Tests that string comparisons work correctly in callbacks".
I am not even sure if I need to set my LANG, LC_ALL, etc. to a particular setting from my locale
to make this work correctly. It would be really handy for later generation to know what is "\u010C" character at first glance. But I digress.
(I hope the readers of this comment understand that the test programs generally lack good comments to make the tests self-documenting, and it makes maintenance of test rather difficult. That :aceman and I are puzzled why the windows are kept open, "Was it intentional or just a poor programming style?"
is a proof of this observation.
Yes, some tests are well-commented, and I think older ones tend to have better comments for some reason.)

TIA
(Assignee)

Comment 15

5 years ago
(In reply to ISHIKAWA, Chiaki from comment #14)
> Is this it?
> https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Statements/
> debugger
Yes.

> I wish the test programs have more comments.
> I was trying to see why
> mozilla/toolkit/mozapps/extensions/test/xpcshell/test_bug616841.js
> was failing during |make xpcshell-tests| and
> am baffled at the code. 
> Yes, some tests are well-commented, and I think older ones tend to have
> better comments for some reason.)
I try to comment my new tests. See e.g. test-send-button.js or test-account-settings-infrastructure.js or test-account-values.js.

Comment 16

5 years ago
Comment on attachment 832595 [details] [diff] [review]
patch v2

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

Looks good! r=mkmelin
Attachment #832595 - Flags: review?(mkmelin+mozilla)
Attachment #832595 - Flags: review?(mconley)
Attachment #832595 - Flags: review+
(In reply to :aceman from comment #13)
> We can
> ask mconley whether the simultaneous opening is intentional or not.

Sorry for the late response.

There's no good reason at all for why these windows remain open. Closing them is absolutely fine. Probably just an oversight on my part.
Flags: needinfo?(mconley)
(Assignee)

Comment 18

5 years ago
Thanks, I think we have all the required info now and the patch can remain as is.
Keywords: checkin-needed
https://hg.mozilla.org/comm-central/rev/e035e1c899bd
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Flags: in-testsuite+
Keywords: checkin-needed
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 28.0
You need to log in before you can comment on or make changes to this bug.