948554 - Record max incremental cycle collector slice pause time

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Comment 1

[Andrew McCreight [:mccr8]]

L64 debug, without bc: https://tbpl.mozilla.org/?tree=Try&rev=c77d537f39fc

Comment 2

[Andrew McCreight [:mccr8]]

Attachment: part 1 - Rename PrepareForCycleCollection and make it a method.

This name is more precise, because we must call it once per slice,
not once per CC.  Being a method on the CC stats object is more consistent.

Comment 3

[Andrew McCreight [:mccr8]]

Attachment: part 2 - Convert some of nsJSEnvironment to TimeStamp for greater precision.

I was getting some weird too-big slice times, I think due to PRTime problems, so
I just converted these over to TimeStamp.

Comment 4

[Andrew McCreight [:mccr8]]

Attachment: part 3 - Capture max slice time in logs and telemetry.

Comment 5

[Olli Pettay [:smaug][[e-mail]]]

(In reply to Andrew McCreight [:mccr8] from comment #3)
> I was getting some weird too-big slice times, I think due to PRTime
> problems
Hmm, this sounds odd.

Comment 6

[Andrew McCreight [:mccr8]]

(In reply to Olli Pettay [:smaug] from comment #5)
> Hmm, this sounds odd.
Yeah, I may have just had some kind of other bug in my patch that I happened to fix later.  I'm not entirely sure.

Comment 7

[Andrew McCreight [:mccr8]]

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/adc20d941bd8
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/2b43b310858b
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/472a1be79a9f

Comment 8

[Andrew McCreight [:mccr8]]

backed out by Ryan for a Win7 debug xpcshell orange:

Assertion failure: !aOther.IsNull() (Cannot compute with aOther null value), at c:\builds\moz2_slave\m-in-w32-d-0000000000000000000\build\obj-firefox\dist\include\mozilla/TimeStamp.h:313

and maybe Win7 debug xpcshell timeouts.

https://hg.mozilla.org/integration/mozilla-inbound/rev/b464f609a193

Comment 9

[Andrew McCreight [:mccr8]]

Attachment: part 2b - Make TimeUntilNow return 0 for null args.

I think I figured out what was triggering the assertion: under some circumstances, you
can end up calling ShouldTriggerCC() before sLastCCEndTime is set. But with that fixed,
it turns out that every call to TimeUntilNow does a null check on the argument, which
is annoying and error prone. So, in this patch, which I will land folded into part 2,
I just return 0 for TimeUntilNow() if the argument is null. It is used to answer questions
like "Has enough time passed?" and "Is this span of time larger than this other one?"
so it seems like a reasonable thing to do. As part of the fix, I also removed the
null check in the next patch.

try run: https://tbpl.mozilla.org/?tree=Try&rev=892582b078f9

Comment 10

[Andrew McCreight [:mccr8]]

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/b0411822f934
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/3453305f7101
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/25b496a8f68c

Comment 11

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/b0411822f934
https://hg.mozilla.org/mozilla-central/rev/3453305f7101
https://hg.mozilla.org/mozilla-central/rev/25b496a8f68c

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+1]]

So this bug caused a regression in the GC API given that we now have a more precise timing available. Instead of milliseconds we are getting microseconds now. We discovered that changed behavior with memchaser and for now it is tracked in issue https://github.com/mozilla/memchaser/issues/184.

Andrew and Olli, is that an expected change or shall we hide that behind the API?

Comment 13

[Andrew McCreight [:mccr8]]

Isn't it actually bug 948554 that caused the regression?

Comment 14

[Andrew McCreight [:mccr8]]

Oh, sorry, that's this bug.  I got confused.  No, that's not expected behavior.

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+1]]

(In reply to Andrew McCreight [:mccr8] from comment #14)
> Oh, sorry, that's this bug.  I got confused.  No, that's not expected
> behavior.

Ok, so I will go ahead and file a new bug for that in a bit. Thanks for your feedback.