865549 - Browser Console landing added 10 minutes to Windows debug browser-chrome tests

Status: RESOLVED WORKSFORME

(DevTools :: Console, defect, P1)

Description

[Phil Ringnalda (:philor)]

https://tbpl.mozilla.org/?tree=Fx-Team&tochange=26fb3bd67f5f&fromchange=07aae4e9a66a is the Browser Console landing and the push before it.

If you look at debug browser-chrome run times, they jumped 5-10 minutes, which is most severe with WinXP and Win7 debug, because buildbot has a 2 hour time limit per buildstep, and thanks to our gradual climb as shown in http://people.mozilla.org/~catlee/sattap/f10048de.png we were already getting close to being up against that. Now we are up against it, losing around one run a day to a timeout until the next time someone adds a bunch of new tests, or makes one work harder, or makes us slower, when we'll suddenly start timing out in nearly every one.

Ted suggested that "that patch mentions using the debugger api, wonder if it somehow enables the debugger api and forgets to disable it" which based on too small a sample size does seem likely to be the case. Comparing the time from the start of the test run up to the first devtools/ test, then the time for all the devtools/ tests, then the time for the tests which follow devtools/, we seem to be at around the same time, a couple minutes longer, around eight minutes longer. Making the tests *after* your tests run more slowly than they did before certainly does sound like leaving debugging turned on.

If so (or, really, even if not):

<jimb> It might be interesting to have the test harness assert that no compartments are in debug mode by the time we begin to shut down.
<jimb> That way we could catch "leaked" Debuggers.

Comment 1

[Mihai Sucan [:msucan]]

This is interesting. Thanks for the bug report.

Jim: I am doing what was suggested to prevent having the target window stay in debug mode:

    this._dbgWindow = this.dbg.addDebuggee(this.window);
    this.dbg.removeDebuggee(this.window);

I don't ever do dbg.enabled = true. Shouldn't this be enough to avoid the debug mode for the given window?

If the Browser Console slows down the whole browser it means the Web Console also slows down web pages - something we wanted to avoid.

How can I check if a given window's compartment is in debug mode?

Comment 2

[Phil Ringnalda (:philor)]

Slightly less critical now, since we just said "screw it, we're slow" and increased the timeout to 9000 seconds instead of 7200.

Comment 3

[Jim Blandy :jimb]

(In reply to Mihai Sucan [:msucan] from comment #1)
> How can I check if a given window's compartment is in debug mode?

You know, I'd really like to have a way to get this information. I don't think there is one at the moment. Debug mode is an implementation detail --- ideally we wouldn't have it at all --- but some sort of diagnostic interface could certainly expose that, and it would be valuable for testing and debugging, as in this bug.

> Jim: I am doing what was suggested to prevent having the target window stay
> in debug mode:
> 
>     this._dbgWindow = this.dbg.addDebuggee(this.window);
>     this.dbg.removeDebuggee(this.window);
> 
> I don't ever do dbg.enabled = true. Shouldn't this be enough to avoid the
> debug mode for the given window?

Yep. If the window is not a debuggee of any Debugger instance, then it shouldn't be in debug mode.

Did you put the removeDebuggee in the finish clause of a try/finish, to make sure it runs even if the things you do while the window is a debuggee throw an execption? What I mean is:

try {
   this._dbgWindow = this.dbg.addDebuggee(this.window);
   ... do stuff ...
} finally {
   this.dbg.removeDebuggee(this.window);
}

> If the Browser Console slows down the whole browser it means the Web Console
> also slows down web pages - something we wanted to avoid.

Absolutely!

Comment 4

[Mihai Sucan [:msucan]]

Thanks for the reply.

(In reply to Jim Blandy :jimb from comment #3)
> (In reply to Mihai Sucan [:msucan] from comment #1)
> > How can I check if a given window's compartment is in debug mode?
> 
> You know, I'd really like to have a way to get this information. I don't
> think there is one at the moment. Debug mode is an implementation detail ---
> ideally we wouldn't have it at all --- but some sort of diagnostic interface
> could certainly expose that, and it would be valuable for testing and
> debugging, as in this bug.

Can we add something like that? I'd like to investigate this issue.


> > Jim: I am doing what was suggested to prevent having the target window stay
> > in debug mode:
> > 
> >     this._dbgWindow = this.dbg.addDebuggee(this.window);
> >     this.dbg.removeDebuggee(this.window);
> > 
> > I don't ever do dbg.enabled = true. Shouldn't this be enough to avoid the
> > debug mode for the given window?
> 
> Yep. If the window is not a debuggee of any Debugger instance, then it
> shouldn't be in debug mode.
> 
> Did you put the removeDebuggee in the finish clause of a try/finish, to make
> sure it runs even if the things you do while the window is a debuggee throw
> an execption? What I mean is:
> ...

I did not wrap this part of the code in a try-catch. If it throws exceptions show in tests and things break rather badly, since this a central piece of code for the console.

Comment 5

[Mihai Sucan [:msucan]]

Tentatively setting this bug as P1 until we better understand the situation here. This looks like a regression in performance of web pages caused by the landing of bug 783499 and a general browser slowdown during and after the use of the browser console (due to the landing of bug 587757). One of the main goals for bug 783499 was to avoid perf issues.

Jim: when you have time, any help would be appreciated here. I would like to begin investigation once I know how to check if a given compartment is in debug mode or not (based on a window object or something). Thanks!

Comment 6

[(not currently active) Ted Mielczarek]

Can you do a try push with those tests disabled and see if that does in fact reduce the test runtime?

Comment 7

[Mihai Sucan [:msucan]]

I spent time today to check if the browser or the web console slow down any javascript in the browser or in content scripts. I didn't manage to reproduce any slowdowns.

Try push with latest fx-team (browser console tests included):
https://tbpl.mozilla.org/?tree=Try&rev=98cf5d226ec7

Try push with the browser console tests removed (otherwise, the same code as above):
https://tbpl.mozilla.org/?tree=Try&rev=9cfbb001efb3

Is tbpl constant enough in terms of running speed for mochitests? Eg. is this enough for us to tell there's a real slowdown? My worry is that tbpl varies a lot (I never really checked runtime numbers, so maybe I'm wrong).

Comment 8

[Phil Ringnalda (:philor)]

Typically within a couple of minutes - the last three runs on fx-team including your parent were 91/92/92 minutes on the old slaves on Win7 debug, and 59/57/59 minutes on the new slaves.

Comment 9

[Phil Ringnalda (:philor)]

I probably should have mentioned how to tell the old and new slaves apart, since now those try runs are comparing multiple runs on the old slow slaves for the control with multiple runs on the new fast slaves for the test.

At any rate, either Ted's magic fix from bug 431048 or inlining isTenured in bug 864085 wiped out any noticeable effect of those tests, and at worst they add part of a minute of runtime. I'd recommend that someone who actually understands it file whatever ought to be filed about making sure you can't ever leak debugging, and WFM this bug.

Comment 10

[Mihai Sucan [:msucan]]

Thank you! Yes, it seems the browser console tests have minimal impact.

(what are the new ix machines btw?)

Reported bug 874052.