934163 - Tracer actors should be more performant

Status: RESOLVED FIXED

(DevTools :: Debugger, defect)

Description

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Instead of sending every frame enter / exit immediately, the tracer actors should buffer them and send the buffer every 50ms or when the event queue is empty.

Comment 1

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: WIP buffer-frame-enter-exit.patch

This passes all tests, but when I play with the tracer on code mirror, it actually feels the same or even slower :(

Comment 2

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Am I missing something in this patch, or is buffering just not the way to go?

Comment 3

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Upped the time to 200ms and that doesn't seem to help either.

Comment 4

[Panos Astithas (he/him) [:past] (please ni?)]

I can't spot anything obviously wrong. Did you measure how many packets are being buffered on average? If the number is very low, then that could explain the overall slowdown with this patch.

Did you try to profile the tracer? Perhaps the biggest contributor to the slowness is something else.

Comment 5

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

(In reply to Panos Astithas [:past] from comment #4)
> I can't spot anything obviously wrong. Did you measure how many packets are
> being buffered on average? If the number is very low, then that could
> explain the overall slowdown with this patch.

Output from typing "fuck this is slow" with 50ms buffer:

FITZGEN: SENDING 2 PACKETS
FITZGEN: SENDING 446 PACKETS
FITZGEN: SENDING 26 PACKETS
FITZGEN: SENDING 14 PACKETS
FITZGEN: SENDING 14 PACKETS
FITZGEN: SENDING 14 PACKETS
FITZGEN: SENDING 14 PACKETS
FITZGEN: SENDING 16 PACKETS
FITZGEN: SENDING 14 PACKETS
FITZGEN: SENDING 94 PACKETS
FITZGEN: SENDING 1006 PACKETS
FITZGEN: SENDING 2350 PACKETS
FITZGEN: SENDING 284 PACKETS
FITZGEN: SENDING 938 PACKETS
FITZGEN: SENDING 378 PACKETS
FITZGEN: SENDING 1426 PACKETS


> 
> Did you try to profile the tracer? Perhaps the biggest contributor to the
> slowness is something else.

Last time I tried during the summit, I wasn't able to get any good info because every JS call just seemed way slower, but the debugger hooks weren't really registering in the profiles. Will try again.

Comment 6

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Discovered that we are thrashing the layout on every log message. See bug 929349 comment 11 for details.

It is noticeably faster once removing the code that causes the thrashing, but still wayyyy slower than I would like it to be. Profiling isn't pointing out any single obvious bottleneck to me.

Comment 7

[Panos Astithas (he/him) [:past] (please ni?)]

Attachment: Tracer profile

Here is a profile of the tracer working on http://jsbin.com/iqijok/1, without the patch in this bug applied. It looks like we could get some wins in the frontend with less layout work (working on that) and in the backend, if we skip some of the more expensive parts of createValueGrip, like findSafeGetterValues. Since the tracer is not going to return fully inspectable objects, maybe it would make sense to streamline createValueGrip in this case as much as possible.

Comment 8

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Actually, I think buffering should happen in the frontend, not the backend since remote debuggees don't have a ton of memory available. It would be in their interest to fire the packet off and forget about it ASAP.

Comment 9

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: improve-tracer-backend-perf.patch

Limits the number of properties we grab to 5.

Limits number of arguments we grab to 5.

Doesn't send object properties.

Remove the generic TraceTypes stuff and inline it.

Comment 10

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: improve-tracer-backend-perf.patch

Only difference from the last patch is that it doesn't try to add 5 non-object properties, it just tries to add 5 properties and doesn't add objects. Checking for objects was too expensive.

Comment 11

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: tracer-perf.patch

This adds buffering again, which actually improves perf a TON. Tests are being a little finicky and aren't passing again yet.

Comment 12

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: tracer-perf.patch

All tests are passing locally.

https://tbpl.mozilla.org/?tree=Try&rev=008539aa68ce

Comment 13

[Panos Astithas (he/him) [:past] (please ni?)]

Comment on attachment 8336293 [details] [diff] [review]
tracer-perf.patch

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

Looks good. Do we have any docs on the tracer protocol that we need to update?

::: toolkit/devtools/server/actors/tracer.js
@@ +650,3 @@
>    } catch(ex) {
>      // The above can throw if aObject points to a dead object.
>      // TODO: we should use Cu.isDeadWrapper() - see bug 885800.

Bug 885800 is done, care to use Cu.isDeadWrapper here?

Comment 14

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

https://hg.mozilla.org/integration/fx-team/rev/d9ef33623670

Comment 15

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

(In reply to Panos Astithas [:past] from comment #13)
> Comment on attachment 8336293 [details] [diff] [review]
> tracer-perf.patch
> 
> Review of attachment 8336293 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Looks good. Do we have any docs on the tracer protocol that we need to
> update?

The only docs at the moment are an attachment on the original bug. We should get them into Jim's DebuggerDocs repo once we start actually shipping the tracer.

Comment 16

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: tracing-followup.patch

Woops, forgot to address the isDeadWrapper comment. Quick review, Panos?

Comment 17

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

https://hg.mozilla.org/integration/fx-team/rev/2c71d40fbee0

Comment 18

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/d9ef33623670
https://hg.mozilla.org/mozilla-central/rev/2c71d40fbee0