Open Bug 814651 Opened 12 years ago Updated 5 years ago

why? settimeout does not execute with delay (setTimeout which is requested by addon's stateListener.ComposeProcessDone at composition window won't fire, because composition window is not cached and actually closed from Tb 17)

Categories

(MailNews Core :: Composition, defect)

defect
Not set
major

Tracking

(Not tracked)

People

(Reporter: xiaozhu, Unassigned)

References

Details

(Keywords: regression, reproducible, Whiteboard: [needs retest][regression by bug 777063])

Attachments

(2 files, 7 obsolete files)

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.64 Safari/537.11

Steps to reproduce:

I am a add-on developer, in my code ,I use setTimeout(myfunc, 0, uri) to register a callback function after current execution, it worked well before thunderbird 17. 

From thunderbird 17, it does not work anymore, it seems that I have to delcare a function express here to call my function, that is not bad. I follow that as following:

var ttid = setTimeout(new function(){myfunc();}, 0);
logger.trace("get ttid as:" + ttid);

In my log, I can get a timeoutid and it works now, but it was executed in the current function context without delay! I tried delay as 1, 1000, it does not work too.




Actual results:

setTimeout does not works with delay


Expected results:

it should be executed after current function context finished.
Severity: normal → critical
it seems that I made a mistake on my source, I miscalled new function, but if I modify my source like following:

var ttid = setTimeout(function(){myfunc();}, 0);
logger.trace("get ttid as:" + ttid);

It would not work. the function I want to delay will never be executed.
Severity: critical → major
(In reply to xzer from comment #1)
> var ttid = setTimeout(function(){myfunc();}, 0);
> logger.trace("get ttid as:" + ttid);
> It would not work. the function I want to delay will never be executed.

No problem with my simple HTML/JavaScript.
seTimeout() request was executed as expected, and myfunc() was invoked as expected, by Firefox 17.0 on my MS Win-XP.

What phenomenon do you call by your "It would not work"?
How did you verified "the function I want to delay will never be executed"?
(In reply to WADA from comment #2)
> Created attachment 684984 [details]
> A simple test case with simple HTML/JavaScript
> 
> (In reply to xzer from comment #1)
> > var ttid = setTimeout(function(){myfunc();}, 0);
> > logger.trace("get ttid as:" + ttid);
> > It would not work. the function I want to delay will never be executed.
> 
> No problem with my simple HTML/JavaScript.
> seTimeout() request was executed as expected, and myfunc() was invoked as
> expected, by Firefox 17.0 on my MS Win-XP.
> 

In thunderbird 17, it does not work.

> What phenomenon do you call by your "It would not work"?
> How did you verified "the function I want to delay will never be executed"?

In my original function, there are log output, but there are never be output, and In my test function, I add log output and alert, either are executed.

https://addons.mozilla.org/en-US/thunderbird/files/browse/126876/

Here is my source, at the line 156 of /chrome/sendfilter.jar!/content/common.js, it does not work even it worked well before thunderbird 17. And I guess that perhasp I have to declare a function express and then I tried a function express, but it does not work too.

By the way, I can get a timeoutid when the setTimeout is called.
>In my original function, there are log output, but there are never be output, and In my test >function, I add log output and alert, either are executed.

sorry, .... neither are executed.
Have you looked in the Core/JS components of bugzilla if any intentional change was done to this function?
What this bug needs is clear steps to reproduce, probably involving a testcase or test extension as needed.
Flags: needinfo?(xiaozhu)
:aceman

it seems that this bug is related, but I have no idea about it

((CSP) when setTimeout is blocked by CSP, it should return zero)
https://bugzilla.mozilla.org/show_bug.cgi?id=805929

In this ticket, it seems that there are some limits on eval calling but I am not using it.

:bz

I do not know how to write a testcase of thunderbird, but I will try to supply a test extension for reproducing. btw, as I mentioned above, the current source is at 

https://addons.mozilla.org/en-US/thunderbird/files/browse/126876/

/chrome/sendfilter.jar!/content/common.js:156
Flags: needinfo?(xiaozhu)
(In reply to xzer from comment #3)
> In my original function, there are log output, but there are never be output, (snip)
> https://addons.mozilla.org/en-US/thunderbird/files/browse/126876/

Does your problem following?
(A) Log by following code is seen.
> 155 logger.trace("call SendFilter_ReloadImapSentFolder for waiting for 0 seconds");
> 156 setTimeout(SendFilter_ReloadImapSentFolder,0, folderURI);
> 157 logger.release();
(B) But log by following code is not seen in Tb 17.
> 116 function SendFilter_ReloadImapSentFolder(folderURI)
> 117 {
> 118 var logger = new SendFilter_Logger("SendFilter_ReloadImapSentFolder()");
>(snip)
> 133 logger.trace("finish SendFilter_ReloadImapSentFolder for waiting load listener");
> 144 logger.release();

If so, following phenomenon?

(1) release() of SendFilter_Logger object is defined as follows.
> 33 this.release = function(){
> 34 SendFilter_LoggerCounter--;
> 35 if (this.isEnable)
> 36 {
> 37 if (SendFilter_LoggerCounter == 0)
> 38 {
> 39 SendFilter_LoggerString = "Send Filter Log\n" + SendFilter_LoggerString;
> 40 SendFilter_Console.logStringMessage(SendFilter_LoggerString);
> 41 SendFilter_LoggerString = "";
> 42 }
(2) And, global variable of SendFilter_LoggerCounter is shared.
(3) Because scheduling of code requested by setTimeout/setInterval is absolutely asynchronous, following can occur. 
> At main context                          At window context 
>   With a SendFilter_Logger object
>     24 SendFilter_LoggerCounter++; =>1
>   request setTimeout with delay=0
>                                            Because of delay=0 and efficient multi-tasking, 
>                                            SendFilter_ReloadImapSentFolder is scheduled.
>                                            With a new local SendFilter_Logger object by line 118,
>                                              24 SendFilter_LoggerCounter++; ==> 2
>                                            144 logger.release();
>                                             34 SendFilter_LoggerCounter--; ==> 1
>                                            Because SendFilter_LoggerCounter>0,
>                                            40 SendFilter_Console.logStringMessage
>                                            is skipped
>   157 logger.release();     
>    34 SendFilter_LoggerCounter--; ==> 0
>   Because SendFilter_LoggerCounter==0,
>   40 SendFilter_Console.logStringMessage
>   is executed

What will happen if SendFilter_LoggerCounter is defined as private variable in SendFilter_Logger object(or property of SendFilter_Logger object)?
JavaScript in HTML is as fllows.
  (0) myfunc() is correctly defined in <head> section
  (1) setTimeOut(function(){myfunc();},delay_value):
  (2) first alert();
  (3) second alert();
  (4) other script code
  (5) end of main script code

In Firefox 17 on MS-Win, scheduling of myfunc() before execution of step4/step5(==end of main script code), between step3(==second alert) and step4/tep5, or sometimes between step2(==first alert) and step3(==second alert), was always observed with two alert() after setTimeout request.
In Seamonkey 2.1.4 on MS-Win, I couldn't observe this "schediling of myfunc() before step5(==end of main script code)". Log data by myfunc() which is appened to a <div> of the HTML was always observed after step5(==end of main script code).

Above indicates that scheduling mechanism is changed in recent Gecko or other code. I believe it's correct change from perspective of multi-tasking, and it's improved efficiency in multi-tasking.
Attachment #684984 - Attachment is obsolete: true
Bug opener, if my assumptions are correct, you can perhaps see your trace data by SendFilter_ReloadImapSentFolder() with next change only. 
>     37 if (SendFilter_LoggerCounter == 0)
> ==> 37 if (SendFilter_LoggerCounter >= 0)
Is it right?
sorry, I have no time to create a test extension before this weekend, please wait.

to WADA:

Thanks for your digging, the global log counter is designed for outputting all logs in same context as one single log.

And, the real point is that my real logic was not executed, to confirm this problem, I checked log, it was not output, then I add alert to my function, it was not shown too, then I reported it.
Test HTML/JavaScript V3.
For ease of obsevation, debug data(trace data) is written to Sub Window #1.
"alert() by myfunc() at Sub Window #2 and "alert() by myfunc() at Main Window" is added for first myfunc() execution with delay=0.

(In reply to xzer from comment #11)
> then I add alert to my function, it was not shown too, then I reported it.

"neither are executed" of you comment #4 was correction of "either are executed". I wrongly read that "I add log output and alert" is not executed yet...

Observation of my HTML/JavaScript test case in Firefox 17.
 
(a) While first alert() at main window by main task is kept shown, trace data by myfunc() is not written to sub window and alert() by myfunc() at sub window is not shown. Trace data by myfunc() is written after "OK" reply to the first alert() at main window.
This indicates that while alert() is kept open, myfunc requested by setTimeout is not scheduled.  

(b) While alert() by myfunc() at sub window is kept open, and while alert() by myfunc() at main window is kept open, trace data by main task at main window is ot written and subsequent alert() by main task at main window is not shown.
This indicates that while alert() is kept open, even when the alert() is requested by asynchronous task of myfunc() which was invoked by setTimeout, even when the alert() is requested at window which was opened by window.open(), execution of main code at main window/main task is not scheduled.  

If something similar event to above "alert() at main task at main window" happens while main task is running, scheduling of SendFilter_ReloadImapSentFolder() requested by setTimeout() may not be executed.

Is this kind of phenoenon or event relevant to your case including alert() in SendFilter_ReloadImapSentFolder() case?
Attachment #685992 - Attachment is obsolete: true
Additional obervation.
(c) Until alert() by myfunc() is ended and myfunc() executes return, other myfunc() requested by setTimeout with larger delay value(1000msec and 2000msec in test) is not scheduled even despite of that requested delay has already expired.
This indicates that execution of code requested by multiple setTimeout() are seriarized.
So, if "wait for something" like alert() happens in currently running task invoked by setTimeout(), code requested by subsequent setTimeout() may not be scheduled even when requested delay expires.
I created a extension to reproduce this problem.

This extension do following two things:

1. add a button to compose new mail window.
  (if it is not shown by default, add it by customize)
  click the button, the setTimeout works well.

2. replace a system function and call the same function called by the added button
  I replaced stateListener.ComposeProcessDone to a customized function, that is what I did
  in the original extension which did not work well. Then when you send a mail, my customized
  function will call the original system function at first, after that, call the same function
  called by the added button. At this time, the setTimeout does not work.


following is the source:


var testSetTimeout_Console = Components.classes["@mozilla.org/consoleservice;1"].getService(Components.interfaces.nsIConsoleService)

function testSetTimeout_showMessage(t){
    var message = "testSetTimeout_showMessage:" + t;
    alert(message);
    testSetTimeout_Console.logStringMessage(message);
}

function testSetTimeout_doTest() {
    alert("this alert is in main function context by click button");
    testSetTimeout_showMessage();
    var ttid = setTimeout(function(){testSetTimeout_showMessage("cc");}, 0);
    testSetTimeout_Console.logStringMessage("ttid=" + ttid);
}

//here we replace the original ComposeProcessDone
var testSetTimeout_OriginComposeProcessDone=stateListener.ComposeProcessDone;
function testSetTimeout_replaceComposeProcessDone(aResult){
  testSetTimeout_OriginComposeProcessDone(aResult);
  testSetTimeout_doTest();
}
stateListener.ComposeProcessDone=testSetTimeout_replaceComposeProcessDone;
Attachment #687400 - Attachment is obsolete: true
(In reply to xzer from comment #16)
> an extension for reproduce the setTimeout problem

(0) Installed the extension on Tb 17.0, on Win-XP.
(1) Open a composition window, add "test Settimeout" button.
(2) Click the "test Settimeout" button.
    => alert(), log in Error Console, are shown as expected, including one by
       function(){testSetTimeout_showMessage("cc");},0 requested by setTimeout.
(3) Send Later
    => alert(), log in Error Console, by main task are shown.
    => Composition window is closed.
    => No alert/log by function(){testSetTimeout_showMessage("cc");},0.
Above was same with mail.openMessageBehavior=1 in Tb 17.
Above was same with mail.compose.max_recycled_windows=8 in Tb 17.

Following was also observd at Error Consolde by click "test Settimeout" button, and "Send Later without recipent".
(1) testSetTimeout_showMessage:undefined (by main, "undefined" due to no parm)  
(2) Following exception due no recipient.
> Timestamp: 2012/12/02 17:00:55
> Error: GenericSendMessage FAILED: [Exception... "Component returned failure code:
> 0x805530df [nsIMsgCompose.SendMsg]"  nsresult: "0x805530df (<unknown>)"
> location: "JS frame :: chrome://messenger/content/messengercompose/MsgComposeCommands.js
> :: GenericSendMessage :: line 2808"  data: no]
> Source File: chrome://messenger/content/messengercompose/MsgComposeCommands.js
Line: 2811
(3) testSetTimeout_showMessage:cc (requested by setTimeout)
Because of "no recipient", error dialog was shown, and composition window was kept open.

A my conern in your test case.
If "window at where setTimedout'ed code/function will be scheduled" is closed, I think setTimedout'ed code/function won't be executed.

(Q1) Mail composition window is actually closed in Tb 17 always without reuse?

If mail.compose.max_recycled_windows=N, and mCachedWindows[i].window starts from i=0 and ends with i=(N-1), I think all cached composition window is closed after end of mail composition... 
> http://mxr.mozilla.org/comm-central/source/mailnews/compose/src/nsMsgComposeService.cpp#203
> 203 void nsMsgComposeService::DeleteCachedWindows()
> 204 {
> 205   int32_t i;
> 206   for (i = 0; i < mMaxRecycledWindows; i ++)
> 207   {
> 208     CloseHiddenCachedWindow(mCachedWindows[i].window);
> 209     mCachedWindows[i].Clear();
> 210   }
> 211 }

(Q2) "Reuse of composition window by mailnews.reuse_message_window and mail.compose.max_recycled_windows" was broken after preference change to  mail.openMessageBehavior in Tb 3.0, between Tb 16 and Tb 17?

mailnews.reuse_message_window=true is removed from mailnews.js of Thunderbird by bug 467768 in Tb 3.0, and was replaced by new mail.openMessageBehavior.
> Following #fdef was added by bug 467768. 
> http://mxr.mozilla.org/comm-central/source/mailnews/mailnews.js#302
> 302 #ifdef MOZ_SUITE
> 303 pref("mailnews.reuse_message_window", true);
> 304 #endif
> http://mxr.mozilla.org/comm-central/source/mail/app/profile/all-thunderbird.js#443
> 443 // If a message is opened using Enter or a double click, what should we do?
> 444 // 0 - open it in a new window
> 445 // 1 - open it in an existing window
> 446 // 2 - open it in a new tab
> 447 pref("mail.openMessageBehavior", 2);
> 448 pref("mail.openMessageBehavior.version", 0);

reuse_message_window is seen in following modules only.
> http://mxr.mozilla.org/comm-central/search?string=reuse_message_window&find=&findi=&filter=^[^\0]*%24&hitlimit=&tree=comm-central
openMessageBehavior is seen in following modules only.
http://mxr.mozilla.org/comm-central/search?string=openMessageBehavior&find=&findi=&filter=^[^\0]*%24&hitlimit=&tree=comm-central
FYI.
Checked your test-extension, with Tb 10.0.4 ESR(ja, on Win-XP), with single composition window only, with mail.openMessageBehavior=2(default).
(case-1) mail.compose.max_recycled_windows=1(deault) :
  After Send Later, testSetTimeout_showMessage:cc was shown at Error Console.
(case-2) mail.compose.max_recycled_windows=0 :
  After Send Later, testSetTimeout_showMessage:cc was NOT shown at Error Console.

As for your extension, I think "code/function requested by setTimeout in your extenstion is not scheduled when composition window is not kept as hidden/chached composition window" itself is pretty normal phenomenon.
I think problem you are looking is;
  hidden/chached composition window is somehow not kept from Tb 17,
  despite that mail.compose.max_recycled_windows=1 is still defaulted.
I think the intention is to remove caching of the compose window (there is a bug for it) so maybe nobody should rely on it in new code.
(In reply to :aceman from comment #19)
> I think the intention is to remove caching of the compose window (there is a
> bug for it) so maybe nobody should rely on it in new code.

IIRC, I did read bug which had removed "caching of compose window" in order to bypass problems due to "caching of compose window", but I'm not sure, and even if that was actually done, I don't know about "done in which Tb release" and "done by which bug".
Even if "caching of compose window is removed from Tb 17" is true, I think reason why "bug opener's extention won't work from Tb 17 any more" should be clearly analized/explained in this bug.

:aceman, do you know bug/patch which had removed "caching of compose window" in Tb 17?
WADA, thanks, it seems that you have get the reason.

I also think the real reason of why it won't work "from 17" should be clarified. 

And also, whether there is a temporary way to fix this problem?
(In reply to xzer from comment #21)
> And also, whether there is a temporary way to fix this problem?

As seen in test with mail.compose.max_recycled_windows=0 in Tb 16 or older, your function/code requested by setTimeout() won't be scheduled upon end of mail composition if user requests "no cached composition window".
To resolve this issue, I think that at least setTimeout() by your extension should be requsted at Tb's main window which won't be closed until termination of Tb.

By the way, can you add (a) code to detect number of current cached composition windows and their status etc., (b) code to detect event of mail composion window close or hiding(returning to hidden/cached status) to your test extension?
Wada, see bug 777063, bug 777732, bug 779074. Only bug 777063 has real code landed in TB17, but I am not sure what it actually does. There are patches called "Remove recycling compose code" (author :jcranmer), but it does not look like it ever landed (it is r-).
Attachment #686425 - Attachment is obsolete: true
This is a copy of xzer's test extension.
Differnces are;
- Button is aded to main TooolBar of Tb's main mail window.
- When button is clicked, JavaScript code is executed under main window.
- JavaScript code obtains window objects via enumerator of window-mediator,
  and show properties of them at Error Console.

Following is format of Error Console log.
> [???-win=XXX/enum=YYY] = element=[object ChromeWindow], properties={ list of property name of the window object }
where ???=enumerator type(DOM or XUL), XXX=index number of window object, YYY=index in enumerator output(-1 == "not retured by enumerator", i.e. actually closed or hidden)

Following is Error Console log after next operation;
(1) Open main window => [DOM-win=0/enum=0]
(2) Open Error Console => [DOM-win=1/enum=1]
(3) Open mail composition window(plain text), close => [DOM-win=2/enum=-1]
(4) Open Activity Manager => [DOM-win=3/enum=2]
(5) Open mail composition window(HTML), close => [DOM-win=4/enum=-1]
(6) Open Adress Book window => [DOM-win=5/enum=3]

> 2012/12/05 03:33:03.811
> MyButton: Test#=7
> Number of windows returned by DOM enumerator = 4
> [DOM-win=0/enum=0] = element=[object ChromeWindow], properties={ADDR_DB_LARGE_COMMIT,AboutSupportOverlay, ... }
> [DOM-win=1/enum=1] = element=[object ChromeWindow], properties={NS_ASSERT,STATE_FULLSCREEN, ... }
> [DOM-win=2/enum=-1] = element=[object ChromeWindow], properties={AddAttachments,AddDirectoryServerObserver, ... }
> [DOM-win=3/enum=2] = element=[object ChromeWindow], properties={ACTIVITY_LIMIT,AutoChosen, ... }
> [DOM-win=4/enum=-1] = element=[object ChromeWindow], properties={AddAttachments,AddDirectoryServerObserver, ... }
> [DOM-win=5/enum=3] = element=[object ChromeWindow], properties={AbClose,AbDelete,AbDeleteDirectory, ... }
> Number of windows returned by XUL enumerator = 4
> [XUL-win=0/enum=0] = element=[object ChromeWindow], properties={QueryInterface,XULBrowserWindow, ... }
> [XUL-win=1/enum=1] = element=[object ChromeWindow], properties={QueryInterface}
> [XUL-win=2/enum=-1] = element=[object ChromeWindow], properties={QueryInterface}
> [XUL-win=3/enum=2] = element=[object ChromeWindow], properties={QueryInterface}
> [XUL-win=4/enum=-1] = element=[object ChromeWindow], properties={QueryInterface}
> [XUL-win=5/enum=3] = element=[object ChromeWindow], properties={QueryInterface}

I don't know about difference between DOM window object and XUL window object obtained by enumerator, for which toString() returns [object ChromeWindow] always. 

In Tb 10.0.4 ESR, when mail composition window(plain text mode) is opened again, same window object as [DOM-win=2] is passed again by enumerator, and  [DOM-win=2/enum=-1] is changed to [DOM-win=2/enum=NN], and when mail composition window(HTML mode) is opened again, same window object as [DOM-win=4] is passed again by enumerator, and [DOM-win=4/enum=-1] is changed to [DOM-win=4/enum=NN].

This indicates that cached composition window is re-used and is returned to enumerator's list.

In Tb 17.0, number of window objects increases upon each mail composition window close and open. Once a window object is not passed by enumerator, same window object will not be passed by enumerator again, so status of [DOM-xxx/eum=-1] and [XUL-xxx/eum=-1] will be kept forever.

This indicates that (a) mail composition window is actually closed, (b) cached composition window is never reused(is not returned enumerator's list again).
Regression window:

(Good : composition window is cached, and is re-used)
> http://ftp.mozilla.org/pub/mozilla.org/thunderbird/nightly/2012/07/2012-07-30-03-05-40-comm-central/thunderbird-17.0a1.en-US.win32.zip

(Bad : composition window is not cached)
> http://ftp.mozilla.org/pub/mozilla.org/thunderbird/nightly/2012/07/2012-07-31-03-10-44-comm-central/thunderbird-17.0a1.en-US.win32.zip

Changes pushed after 2012-07-30 00:00:00, before 2012-07-31 06:00:00
> http://hg.mozilla.org/comm-central/pushloghtml?startdate=2012-07-30+00%3A00%3A00&enddate=2012-07-31+06%3A00%3A00

Note-1:
If your test extension is enabled and Send Later is executed with 2012-07-30 build, Tb crashes always. This is perhaps problem of bug 777063 when special situation happens, for example, timeout fired while Tb is trying to terminate composition and to save cached composition window.
Note-2:
Crash with your test extension doesn't occur in Tb 2012-07-31 build(i.e. crash of bug 777063 is resolved), but problem of this bug starts to occur.
Note-3:
If following is requested for XUL window which is not returned by getXMLWindowEnumerator("") any more(for example, already closed window such as Address Book, Activity Manager), exception occurs(Interface not available) in any Tb build. This is normal phenomenon because window is actually closed.
> var DOMwindow = XULwindow
>          .QueryInterface(Components.interfaces.nsIInterfaceRequestor)
>          .getInterface(Components.interfaces.nsIDOMWindow) ;
This exception was observed for "closed mail composition window" too in 2012-07-30 build.
This exception doesn't occur in 2012-07-30 build with mail.compose.max_recycled_windows>=1(recycle of mail composition is normally done by Tb), even when already known XUL window object is not returned by getXMLWindowEnumerator("")(hidden by Tb's request of "remove from enumeration list").
So, I think phenomenon is "mail composition window is actually closed and is not cached in 2012-07-30 build", instead of "cached but not re-used".
Confirming per phenomena observed by our test extensions.
Status: UNCONFIRMED → NEW
Component: Untriaged → Composition
Ever confirmed: true
OS: Windows 7 → All
Product: Thunderbird → MailNews Core
Hardware: x86_64 → All
Summary: settimeout does not execute with delay → settimeout does not execute with delay (setTimeout which is requested by addon's stateListener.ComposeProcessDone at composition window won't fire, because composition window is not cached and actually closed from Tb 17)
(Exception-1)
When function get_Root_DOM_win_from_DOMwin accesses DOM window obtained by WindowMedator's getEnumerator() after window close, exception is raised.
(Exception-2)
When function get_DOM_win_from_XULwin accesses XUL window obtained by WindowMedator's getXULWindowEnumerator() after window close, exception is raised.

(function-1) get_Root_DOM_win_from_DOMwin
      Rootwin = DOMwin
               .QueryInterface(Components.interfaces.nsIInterfaceRequestor)
               .getInterface(Components.interfaces.nsIWebNavigation)
               .QueryInterface(Components.interfaces.nsIDocShellTreeItem)
               .rootTreeItem
               .QueryInterface(Components.interfaces.nsIInterfaceRequestor)
               .getInterface(Components.interfaces.nsIDOMWindow)
               .QueryInterface(Components.interfaces.nsIDOMChromeWindow) ;

(Exception-1)
2012/12/06 10:46:42.309
MyButton: Exception in get_Root_DOM_win_from_DOMwin, seq=2
[Exception... "Component returned failure code: 0x80004002 (NS_NOINTERFACE) [nsIInterfaceRequestor.getInterface]"  nsresult: "0x80004002 (NS_NOINTERFACE)"  location: "JS frame :: chrome://mybutton/content/MyButton.js :: get_Root_DOM_win_from_DOMwin :: line 154"  data: no]

(function-2) get_DOM_win_from_XULwin
      DOMwin = XULwin
               .QueryInterface(Components.interfaces.nsIInterfaceRequestor)
               .getInterface(Components.interfaces.nsIDOMWindow) ;

(Exception-2)
2012/12/06 10:46:42.316
MyButton: Exception in get_DOM_win_from_XULwin, seq=2
[Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIInterfaceRequestor.getInterface]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: chrome://mybutton/content/MyButton.js :: get_DOM_win_from_XULwin :: line 140"  data: no]

(A) In any of Tb trunk 2012-07-30 build and Tb trunk 2012-07-31 build, both exception always occurs when remembered/ordinal XUL window/DOM window is already closed.
(B-1) In Tb trunk 2012-07-30 build with mail.compose.max_recycled_windows>=1, both exception desn't occurs on already-closed composition window, because it's cached.
(B-2) In Tb trunk 2012-07-30 build with mail.compose.max_recycled_windows==0, both exception always occurs on already-closed composition window, because it's not cached.
(C) In Tb trunk 2012-07-31 build, both exception always occurs on already-closed composition window, regardless of mail.compose.max_recycled_windows setting(default=1).
Attachment #688605 - Attachment is obsolete: true
FYI.
Quick regression window check of bug 777063 and this bug.
> --------------------   -------------------  ------------------------------------------------
> Extension              Extension            
>  by xzer                by WADA              Thunderbird Trunk Build
> --------------------   -------------------
> crash     setTimeout   exception on            Directory of
>                         closed compose win       thunderbird-17.0a1.en-US.win32.zip
> --------------------   -------------------  ------------------------------------------------
> No Crash  Fires        No Exception          2012-07-17-03-02-01-comm-central/ (First-Tb17)
> No Crash  Fires        No Exception          2012-07-23-03-06-06-comm-central/ 
> --------------------   -------------------  ------------------------------------------------
>                                              Crash started to occur (bug 777063)
> --------------------   -------------------  ------------------------------------------------
> Crash     ???          No Exception          2012-07-25-03-02-01-comm-central/ 
> Crash     ???          No Exception          2012-07-26-03-02-01-comm-central/ 
> Crash     ???          No Exception          2012-07-27-03-05-09-comm-central/ 
> Crash     ???          No Exception          2012-07-30-03-05-40-comm-central/ 
> --------------------   -------------------  ------------------------------------------------
>                                              Crash stopped by change of bug 777063,
>                                              but this bug started to occur
> --------------------   -------------------  ------------------------------------------------
> No Crash  Not fires    Exception occurs      2012-07-31-03-10-44-comm-central/ 
> --------------------   -------------------  ------------------------------------------------
After composision window close,
>                                   Enumerator                       isCachedWindow()  Exception        
> 2012-07-30-03-05-40-comm-central/   Doesn't return Composer window    true             doesn't occur
> 2012-07-31-03-10-44-comm-central/   Doesn't return Composer window    false            occurs
> Thunderbird 17 official releae      Doesn't return Composer window    false            occurs
After composision window open again,
>                                   Enumerator                       isCachedWindow()  Exception        
> 2012-07-30-03-05-40-comm-central/   Returns same window object        false            doesn't occur
> 2012-07-31-03-10-44-comm-central/   Returns new window object         false            occurs on closed window
> Thunderbird 17 official releae      Returns new window object         false            occurs on closed window
I believe composer-window-caching was kille by patch forbug 777063.

By the way, by adding Observer, notification of "xul-window-destroyed" upon composition window close was normally observed by both builds before patch for bug 777063 and builds after patch for bug 777063.
If you want to know about the notification which is relevant to patch for bug 777063, adding function of my extension by editing JS source, please.
Attachment #689158 - Attachment is obsolete: true
Test procedure:
(1) Remove extension if installed, add extension
(2) Start Tb, open Error Console
(3) Open composition window
    Click button-1(get windows via enumerator), click button-2(isCachedWindow).
    Check Error Console.
(4) Close composition window
    Click button-1(get window via enumerator), click button-2(isCachedWindow).
    Check Error Console.
(5) Repeat (3)/(4) several times.
(6) Remove extension
Whiteboard: [regression by bug 777063]
Attached patch Proposed patch (obsolete) — Splinter Review
Assignee: nobody → neil
Status: NEW → ASSIGNED
Attachment #742006 - Flags: review?(mbanner)
Attachment #742006 - Flags: feedback?(m-wada)
(In reply to neil@parkwaycc.co.uk from comment #31)
> Proposed patch

This bug is not bug to report regression caused by patch of bug 777063.
(1) Detective work for culprit who killed "setTimeout requested by add-on" was started.
(2) During (1), we found phenomenon of "compose window is not reused
    although mail.compose.max_recycled_windows=5(default) is used".
(3) As for "setTimeout requested by add-on",
    because it's requested by stateListener.ComposeProcessDone,
    it won't work if mail.compose.max_recycled_windows=0.
(4) => Main culprit of "setTimeout doesn't work" is add-on himself.
(5) Detective work for culprit of "compose window is not reused
    even though mail.compose.max_recycled_windows=5" started.
(6) Regression window of "compose window is not reused" is found
    => bug 777063 was highlighted as a suspect
(7) Because "recycle of compose window" is not mandatory feature
    nowadays, I thought removal of "recycle of compose window" might
    be intentionally done.
    So I asked you bug 777063 comment #30 on 2012-12-06.
In parallel with above detective works, severe memory leak, which is by "compose window open and close", which is regression started from Tb 17, was reported to bug 818607.
(8) In bug 818607, detective work for culprit who produced memory leak by "compose window open and close" was started.
(9) Major culprit was found soon fortunately.
    It was Bug 765074 which is problem produced by Tb 12.
(10) However, bug 818607 is regression started from Tb 17. So we started detective work for culprit of "memory leak started from Tb 17".
(11) Regression window was found by bug 818607 comment #40.
     Surprisingly, it was absolutely same as this bug(814651).
     => bug 777063 was highlighted again as most important suspect.
(12) So, I asked you bug 777063 comment #31 on 2013-04-25.

Although regression by your patch for bug 777063 was discovered first in this bug, I don't think patch proposal to this is not so appropriate, because major activity in this bug is finding "why setTimeout requested by add-on doesn't work after Tb 17".

Neil, open separate and crisp bug for follow-up of your patch in bug 777063, for ease of tracking of problems/bug search/QA works/testing, please. And, please describe why "recycle of compose window" was killed by your patch in the new bug for us.
After it, we can refer the new bug in both this bug(814651) and bug 818607
Comment on attachment 742006 [details] [diff] [review]
Proposed patch

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

Propose patch by separate/crisp bug, please.
Attachment #742006 - Flags: feedback?(m-wada)
Attachment #742006 - Attachment is obsolete: true
Attachment #742006 - Flags: review?(mbanner)
Assignee: neil → nobody
Status: ASSIGNED → NEW
Keywords: qawanted
Summary: settimeout does not execute with delay (setTimeout which is requested by addon's stateListener.ComposeProcessDone at composition window won't fire, because composition window is not cached and actually closed from Tb 17) → why? settimeout does not execute with delay (setTimeout which is requested by addon's stateListener.ComposeProcessDone at composition window won't fire, because composition window is not cached and actually closed from Tb 17)
Cross-linking to impacted Bug 1046207.

(In reply to :aceman from comment #23)

Wada, see bug 777063, bug 777732, bug 779074. Only bug 777063 has real code
landed in TB17, but I am not sure what it actually does.

These are all closed in 2016

Flags: needinfo?(acelists)
Keywords: qawanted

Yes, compose window recycling was removed now.
This bug needs new testing and steps to reproduce.

Flags: needinfo?(acelists)
Whiteboard: [regression by bug 777063] → [needs retest][regression by bug 777063]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: