125100 - Long delay closing all windows, mozilla hangs [win32]

Status: VERIFIED FIXED

(SeaMonkey :: UI Design, defect, P1)

Description

[Nick Atkins]

From Bugzilla Helper:
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:0.9.8+)
Gecko/20020212
BuildID:    2002021203

There is a 3-4 second delay when closing windows.  This happens with at least
mailnews, composer and browser.  Mozilla hangs during this time.

Reproducible: Always
Steps to Reproduce:
1. Open window
2. Close it


Actual Results:  Window does not close immediately but hangs for several seconds

Expected Results:  Window should close immediately, browser should not hang.

This was also in the nightly from Feb 11th.

Comment 1

[Blake Ross]

Cc'ing dp.  Recent occurrence, involving those main windows?  Don't know why
that SetWorkingSetSize fix would cause this, but it seems suspect.

Comment 2

[Suresh Duddi (gone)]

Yup certainly looks like it. Taking over bug.

Nick, I am assuming this doesnt happen this bad before Feb 9. Would be great if
we get more info on your system:

RAM:
Processor speed:

Comment 3

[Nick Atkins]

No, it only started happening with yesterday's build (as far as I can remember).
 My machine is a 256M 800MHz Dell.  

Comment 4

[Suresh Duddi (gone)]

QA any help to reproduce this inhouse. I tried this on a Win2k 128MB 200MHz
machine and couldn't reproduce it.

Comment 5

[sairuh (rarely reading bugmail)]

jrgm / kerz, do either of you see this?

Comment 6

[sairuh (rarely reading bugmail)]

i don't think i encountered this using 2002.02.11.11 comm bits on win2k, pIII
500mHz --then again, i've recently been focusing on an accessibility test build
on win2k, rather than the trunk...

Comment 7

[John Morrison]

I can't reproduce it per se. I do have a scenario where there is a visible 
delay in closing the windows, and the CPU spikes while something happens (as in 
spikes more than any other app does when just closing a window). 

Set your homepage in the browser to something large (a DOM or CSS spec page [or 
nsCSSFrameConstructor.cpp for masochists] and then open 10 windows. Minimize 
all the windows, then restore two mozilla windows. Close the top showing 
mozilla window while watching the task manager. (1) there is a delay in window 
closing (or at least a delay in repainting the underneath mozilla window); (2) 
there is a notable CPU spike; (3) when the window is closed, I see memory (Mem 
usage in task manager) shoot up to ~30MB, then rapidly down to ~13MB and 
immediately back to ~16MB [your numbers will vary].

However, I can't say that, aside from point (3), a build from am of 02/08 is 
subjectively any different in the way it behaves for the above scenario (i.e., 
we are slow at disposing of those windows). 

I tried running while dumping out the DEBUG_dp timing info in the patch that 
was checked in for affecting working set. At most, I was measuring 21 msec for 
the call to SetProcessWorkingSetSize, although that doesn't mean that there 
aren't side effects from this.

I think a nice Quantify profile of just window closing would be a useful thing 
to have a look at, particularly to figure out which closing tasks might 
possibly be deferred so that other windows get repainted without such a long 
delay.

Comment 8

[Suresh Duddi (gone)]

Those number shiftings in the task manager is expected. 21msec is acceptable.
But  user is complaining of a 3-4 sec delay.

Nick, could we get some more info on your settings.
- what applications are you running at the time when you close the window
  (we are interested in heavy weight processes)
   TaskManager->Applications is what I am looking for
- TaskManger->Performance
  What does your memory and CPU usage say just before you closed the window
- How big is your Swap
  MyComputer->Properties->Advanced->PerformanceOptions
  You should see Total size of page file

Comment 9

[Suresh Duddi (gone)]

Jrgm, anyway we can give your build with DEBUG_dp timings to Nick ?

Nick, thanks so much for your help so far. Would you be willing to run a build
that has timing built in so we can isolate where you are losing this 3-4 secs.

Comment 10

[Nick Atkins]

Attachment: My processes

Nothing really happening.

Comment 11

[Nick Atkins]

Attachment: My processes

My process status.  Unfortunately not able to grab it at the exact time I close
the window.

Comment 12

[Nick Atkins]

Attachment: CPU and memory spikes as I close Mozilla windows

Each spike is a close window action.

Comment 13

[Nick Atkins]

(please ignore the first attachment, I sent that before I was ready ;-)

My swap is 384M.  Yes, I can run the debug build.  Let me know where to get it
and what to do with it.  Cheers.

Comment 14

[Suresh Duddi (gone)]

Whow. Thanks for such a quick turnaround Nick.

Your memory usage is 252k (almost close to your total physical memory of 256MB).
It is possible for memory compaction that happen during window close to cause
pages to get swapped out if there are other processes hungry for memory. This
swap out and future swap in as you use other windows, can cause the delay that
you are seeing.

The key here is other processes that are hungry for memory.

jrgm, you can probably similate this if we do close window while we say have a
build going...

Comment 15

[Nick Atkins]

My memory usage isn't a great deal I'll think you'll find.  And I'm not actually
*doing* anything significant on the machine (like builds or running CPU-bound
processes).  All that work is done on a separate Linux box ;-)

I just reverted back to build 2002020803 and the problem no longer occurs with
that build. Compose and Browser windows go away instantly and there is no "hang".  

The problem does occur in the latest nightly on Asa's mozillazine page.

Comment 16

[John Morrison]

Hmm, the build I have is an optimized build with symbols, which weighs in at a 
mere 95MB. Not sure how to get the whole thing to Nick. 

Perhaps I can just attach a copy of 'appshell.dll' which has the debug_dp
printf's from nsXULWindow.cpp forced on. Nick could download this (about 340KB
when zipped) and replace appshell.dll in a build from today. Thoughts?

Comment 17

[Suresh Duddi (gone)]

That should totally work. Can you guys try that. In the mean time, I will do a
optimized build with the timing enabled (no symbols), just in case.

Comment 18

[John Morrison]

Attachment: zip'd copy of "appshell.dll"; save as 'appshell.zip' [application/octet-stream]

Okay, here is a zipped copy of appshell.dll, which has the debug printf's
forced to be on. 

Save this attachment as 'appshell.zip', and then extract 'appshell.dll' from
the zip file. Then, in a build from today (optimally, might work in a
relatively recent build if no interfaces changed) rename
.\components\appshell.dll to .\components\_appshell.dll, and then copy the new
version of appshell.dll into .\components\

Then start mozilla from a command line, with ".\mozilla -console", to get a
console window. Timing measures of the the calls to _heapmin and
SetProcessWorkingSetSize will be shown in that console when a mozilla window is
closed.

Comment 19

[Nick Atkins]

Ok, I did what you said.  The output looks like this:

stdout directed to dynamic console
stderr directed to dynamic console
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 2714 ms
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 4120 ms
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 2780 ms

The first shrinkage is a new empty browser window being closed
The second one is a browser with 4 tabs of various websites loaded being closed
The third one is mail composer (nothing entered) being closed

Comment 20

[Nick Atkins]

Additional.  The first window opened closes instantly but an new window (ctrl-n)
closes with this delay.  The main problem is the apparent hanging (window
remains painted on screen and doesn't go away).

stdout directed to dynamic console
stderr directed to dynamic console
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 777 ms
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 1186 ms
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 1214 ms
DEBUG: HeapCompact() success - 0 ms
DEBUG: Honey! I shrunk the resident-set! - 1031 ms

First and last value is the first window being closed
Second and third value is the second window being closed.

Not sure if these stats really illustrate the problem, as I said the main
problem is a visual hanging of the window where it remains painted.

Comment 21

[Suresh Duddi (gone)]

Nick that is of incredible help. As we suspected, it is the resident set mucking
that takes so much time on your machine. Why is the interesting question ? Esp
since on lesser machine (128MB 200MHz) it seem to take not more than 20 ms.

Ccing Garrett for any clues.

Comment 22

[Damian Yerrick]

Possibilities:
Should we not shrink the resident set until say five seconds after the
window closes?  Should we shrink it gradually, say a couple megs every
few seconds?

Comment 23

[Cathleen]

OS does the shriking for us, when we envoke the system call.
We could try using a timmer.

Comment 24

[Suresh Duddi (gone)]

I am going to try the timer trick next and see how it feels.

Comment 25

[Suresh Duddi (gone)]

Attachment: Heap Compaction on timer

On window close, we set a 100ms timer. Heapcompaction happens on the timer.

Comment 26

[Suresh Duddi (gone)]

Attachment: appshell.zip containing appshell.dll with fix

Nick, could you give this appshell.dll a try. Instructions for using it is the
same as befor from jrgm. Thanks.

Comment 27

[Martijn Kint]

Confirming om OS X build ID 2002021403


Very, very slow opening and closing of windows, especially new windows invoked
by the window.open command on pages. Takes about 3 to 4 seconds on a G4 450 Mhz.
512 MB Ram

Compared it to NS 6.2.1 wich only takes about a second to open new windows.

Comment 28

[John Morrison]

Okay, fair enough comment, except the particular code under discussion in this 
bug is only executed on win32 platforms, since it is calling particular win32 
APIs (and even then, only if they are available on the user's OS version).
So, the OS/X issue would be something separate from this bug. If there isn't 
a bug open that fits your description/experience, then please file one 
(although I expect that a bug already exists).

Comment 29

[Cathleen]

filed bug 125758 for comment #27  Mac OS X issue.

Comment 30

[Nick Atkins]

Suresh, I tried your appshell.dll but I saw no difference.  The first window
opened closes without hanging.  Subsequent windows still hang.  Sorry ;-(

Comment 31

[Damian Yerrick]

I was thinking of a delay more on the order of 1000ms. Would that help?

Comment 32

[Segura M.]

I use 0.9.9,under NT4, and stopping windows
is too much long !

Comment 33

[M. A. Sridhar]

This looks very similar to bug #127634. I have this problem all the time on my
PC (Win NT 4 SP6, 384M RAM, Athlon 650 processor) running 0.9.9. I often open 8
to 10 windows, and when I click the 'exit' menu item, it can take as much as 30
seconds for all windows to close. Very irritating.

Does anyone know whether this bug is fixed in a newer nightly build?

Comment 34

[Nick Atkins]

IMHO it is the same bug (a dupe).  And, I can categorically tell you that this
problem stil occurs on my latest nightly build (2002032408).

Comment 35

[Sebastian Späth]

I can confirm this on a Win98 with 512 MB of RAM. Closing the Windows hangs
everything for 3-4 seconds (although the taskbar icon vanishes before the freeze).

Comment 36

[Suresh Duddi (gone)]

Now wait. This fix is a noop for win98.

Comment 37

[pitrou]

Hello,

I have the same problem with Mozilla 0.99 at home (on a 700 Mhz Athlon with
192 Mb RAM under Windows 2000 Professional). Mozilla 0.98 was ok, so this is
a serious  regression (and _really_ annoying in everyday usage). This happens 
when closing any kind of window (browser, mail...) ; one must wait several 
seconds before Mozilla wakes up again, redraws itself and accepts user input.
It looks like some heavy garbage collecting is done (I mean, it's the impression 
it gives from the symptoms, I did'nt investigate in the source code ;-)).

For me, it's part of the two or three big problems that make Mozilla not
completely ready for every end-user.

Antoine.

Comment 38

[Suresh Duddi (gone)]

Ok. Since I cant reproduce this inhouse, and so many of you are seeing this, I
am going to eliminate the working set reduction that happens on window close.

patch follows...

Comment 39

[Suresh Duddi (gone)]

Attachment: Stopping working set reduction on window close

Comment 40

[Garrett Arch Blythe]

Comment on attachment 76752 [details] [diff] [review]
Stopping working set reduction on window close

In case review needed, I reviewed.

Comment 41

[Nick Atkins]

Which next build will the patch be included in?

Comment 42

[John Morrison]

Well, next steps are to get another review (sr), then get approval to land 
(a=) and then find a time to land. Should likely happen in the next few days;
stay tuned to this bug, and dp will mark the bug FIXED when he lands this 
patch.

Comment 43

[Suresh Duddi (gone)]

*** Bug 123729 has been marked as a duplicate of this bug. ***

Comment 44

[Matthias Versen [:Matti]]

*** Bug 134834 has been marked as a duplicate of this bug. ***

Comment 45

[Suresh Duddi (gone)]

Nominating for adt approval.

Comment 46

[Jaime Rodriguez, Jr.]

We'll look at accepting this one, once it has a sr=

Comment 47

[Ere Maijala (slow)]

I've built an optimized build including this patch. Seems to improve performance
a *lot*. Sr= please anyone?

Comment 48

[Suresh Duddi (gone)]

Ccing alecf for sr=

Comment 49

[Alec Flett]

Comment on attachment 76752 [details] [diff] [review]
Stopping working set reduction on window close

sr=alecf
oh baby this was driving me nuts.

That said, I'm sorry to see the actual functionality go away - this is Yet
Another Idle Function - i.e. work we could be doing when we think the user has
been idle for a while. 
I really think we ought to consider adding an idle-detection service of some
kind.

This is also something I would have liked to see happen whenever I hit "sleep"
on my notebook (Because apps which take up less memory take less time to
restore from a sleeping state)

also, is this something that can happen on a background thread, instead of
killing it entirely?

Comment 50

[Ere Maijala (slow)]

Before anyone re-implements this, please read my rant from bug 123729. Thanks :)

Comment 51

[Jaime Rodriguez, Jr.]

adt1.0.0+ (on ADT's behalf) approval for checkin into 1.0.

Comment 52

[Asa Dotzler [:asa]]

Comment on attachment 76752 [details] [diff] [review]
Stopping working set reduction on window close

a=asa (on behalf of drivers) for checkin to the 1.0 trunk

Comment 53

[Suresh Duddi (gone)]

Alec, I think turbo-last-window close would be an ideal spot for this. But I
really think we need atleast one milestone to try this out. Let us see.

Comment 54

[Sam Emrick]

Question? Was too much of fix backed out? From the data above and code 
inspection it seems to me it was setProcessWorkingSetSize causing the 
bulk of the delay. How about leave in the heapmin() and just back out 
the os call (it marks all pages of the process idle, thus first 
candidates to discard or page-out). 

Comment 55

[Cathleen]

*** Bug 127634 has been marked as a duplicate of this bug. ***

Comment 56

[Suresh Duddi (gone)]

Fix checked in monday @ 9pm california time (PDT). Ere Maijala is verifying the
fix (thanks Ere).

Sam: here are my reasons for backing out heapmin too
 - With my testing I didn't see heapmin() reclaiming any memory at all
 - Thought we need to do this at a different place rather than on every window close

Comment 57

[Nick Atkins]

Got today's build: 2002041003 and initial testing looks good.  Windows close as
quick as one might expect.  Good work!

Comment 58

[Suresh Duddi (gone)]

Thanks Nick. Closing FIXED.

Comment 59

[Ere Maijala (slow)]

Marking this verified, although there seems to be a similar problem when
minimizing a window. But it's place for a new bug I think.

Comment 60

[Ere Maijala (slow)]

The minimizing problem seems to be a Windows feature. Other programs have same
symptoms. Case closed.