1189829 - Fix O(n^2) behavior in nsConsoleService::ClearMessagesForWindowID

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

Pretty classic O(n^2) array manipulation behavior there.

Comment 1

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

[Tracking Requested - why for this release]: We shouldn't ship this.

Comment 2

[Daniel Holbert [:dholbert]]

The code that khuey's concerned about is (I think):
> 78   for (uint32_t i = 0; i < mBufferSize && mMessages[i]; i++) {
[...]
> 93     uint32_t j = i;
> 94     // Now shift all the following messages
> 95     for (; j < mBufferSize - 1 && mMessages[j + 1]; j++) {
> 96       mMessages[j] = mMessages[j + 1];
> 97     }
[...]
> 105     // Ensure the next iteration handles the messages we just shifted down
> 106     i--;
> 107   }

http://mxr.mozilla.org/mozilla-central/source/xpcom/base/nsConsoleService.cpp?mark=78-78,94-97&rev=49ae0961591e#78

This indeed looks like it has O(n^2) performance, and would blow up time-wise if we're clearing a nontrivial portion of mMessages.

Comment 3

[Liz Henry (:lizzard) (relman/hg->git project)]

Tracking for 42 since this is a regression (from bug 1185144 looks like)

Comment 4

[Nathan Froyd [:froydnj]]

Attachment: fix quadratic behavior in nsConsoleService

This ought to fix it.

Comment 5

[Daniel Holbert [:dholbert]]

(Side note: should we make mMessages use smart pointers, instead of manually-refcounted raw pointers? e.g. perhaps it should have type "nsCOMArray<nsIConsoleMessage>*" instead of "nsIConsoleMessage**"?

If this seems sane to people who are actually wrestling with this code, I'm happy to file a followup on it, but I'm mentioning it here, because it seems like any patch that tweaks this array [e.g. this bug's patch] will have a nontrivial chance of accidentally breaking the refcounting, as long as we're relying on manual macro invocations. froydnj, what do you think?)

Comment 6

[Daniel Holbert [:dholbert]]

(er, I think I meant nsCOMArray<nsIConsoleMessage> actually -- not a pointer to a nsCOMArray.)

Comment 7

[Nathan Froyd [:froydnj]]

I am a fan of writing safe code.  And yes, doing comment 6 would be preferable, too.

Comment 8

[Daniel Holbert [:dholbert]]

(Cool, thanks. Filed bug 1195486 on converting mMessages to be safer then.)

Comment 9

[Eric Rahm [:erahm]]

Comment on attachment 8648901 [details] [diff] [review]
fix quadratic behavior in nsConsoleService

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

Good news: Your approach looks good aside from a few corner cases.
Bad news: I think there's enough fundamentally wrong with nsConsoleService's attempt at a circular buffer that we'd be better off just replacing it.

A maximum sized LinkedList feels right here (O(1) insertFront, popLast, remove (when iterating)). We don't need random access, there are only 250 entries max so the overhead of a doubly-linked list is negligible, there is only one console service so no multiplier effect.

This would get rid of a fair amount of "handle the circular buffer thing" logic (which is currently wrong), in general the code would be easier to read, and it would inherently fix the problem we're try to solve here.

All of that said, I can just re-review w/ fixes for the corner cases and we can punt to the follow up.

::: xpcom/base/nsConsoleService.cpp
@@ +80,5 @@
> +  for (; i < mBufferSize && mMessages[i]; i++, openSlot++) {
> +    // Slide the message down if necessary.
> +    if (i != openSlot) {
> +      mMessages[openSlot] = mMessages[i];
> +      mMessages[i] = nullptr;

Corner cases: 
#1 - If we match all entries, mMessages[0] will not be nulled out
#2 - If we *only* match the last entry, it will not be nulled out

@@ +100,3 @@
>  
> +    // Compensate for incrementing openSlot in the loop header.
> +    openSlot--;

Is this always safe if |openSlot == 0|? I'm too lazy to spec spelunk this :)

@@ -105,1 @@
>      mFull = false;

Latent bug:

So this is just wrong. We're doing a circular buffer, by setting mFull to false we've effectively corrupted the proper order (element 0 is now the 'oldest' entry, mCurrent is the 'newest' + 1).

Comment 10

[Nathan Froyd [:froydnj]]

(In reply to Eric Rahm [:erahm] from comment #9)
> This would get rid of a fair amount of "handle the circular buffer thing"
> logic (which is currently wrong), in general the code would be easier to
> read, and it would inherently fix the problem we're try to solve here.

Yeah, There are better data structures we could be using here, either rolling our own deque via a linked list or using another one.

> ::: xpcom/base/nsConsoleService.cpp
> @@ +80,5 @@
> > +  for (; i < mBufferSize && mMessages[i]; i++, openSlot++) {
> > +    // Slide the message down if necessary.
> > +    if (i != openSlot) {
> > +      mMessages[openSlot] = mMessages[i];
> > +      mMessages[i] = nullptr;
> 
> Corner cases: 
> #1 - If we match all entries, mMessages[0] will not be nulled out
> #2 - If we *only* match the last entry, it will not be nulled out

Does it make you feel any better to know that NS_RELEASE nulls out the pointer it frees?  I think that takes care of the corner cases here.

> @@ +100,3 @@
> >  
> > +    // Compensate for incrementing openSlot in the loop header.
> > +    openSlot--;
> 
> Is this always safe if |openSlot == 0|? I'm too lazy to spec spelunk this :)

Yes.  Arithmetic on unsigned types wraps like you would expect.  (Arithmetic that wraps on signed types is undefined behavior.)

> @@ -105,1 @@
> >      mFull = false;
> 
> Latent bug:
> 
> So this is just wrong. We're doing a circular buffer, by setting mFull to
> false we've effectively corrupted the proper order (element 0 is now the
> 'oldest' entry, mCurrent is the 'newest' + 1).

Wow, I just totally botched that review, then, didn't I?  Another reason to rewrite this code to make it clearer.  I'll fix that.

Comment 11

[Nathan Froyd [:froydnj]]

Attachment: fix quadratic behavior in nsConsoleService

Thank you for the thorough review!

This is the same patch, with the mFull bit deleted; I think the NS_RELEASE
nulling behavior takes care of your concerns about corner cases.

Comment 12

[Eric Rahm [:erahm]]

Comment on attachment 8649339 [details] [diff] [review]
fix quadratic behavior in nsConsoleService

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

Oh! Good to know about NS_RELEASE nulling, so no concerns there. We still need to properly deal with |mFull| though.

::: xpcom/base/nsConsoleService.cpp
@@ +104,3 @@
>  
> +  if (openSlot != i) {
> +    mCurrent = openSlot;

Unfortunately we need to properly set mFull. It's used in various places to make decisions on how we access the backing array.

Really I think the easiest thing is to just rip out the circular buffer (this isn't hyperbole, the code would become much less tedious and our n^2 issue would be fixed).

Comment 13

[Nathan Froyd [:froydnj]]

Attachment: fix quadratic behavior in nsConsoleService

All right, the failures on try look to be intermittents and nothing completely
embarrassing, so here's the attempt at rewriting things to be less awful.

Comment 14

[Eric Rahm [:erahm]]

Comment on attachment 8649445 [details] [diff] [review]
fix quadratic behavior in nsConsoleService

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

r=me Thank you for taking the time to do the proper fix.

::: xpcom/base/nsConsoleService.cpp
@@ +110,1 @@
>    }

Lets set mCurrentSize to zero here.

@@ +441,5 @@
>     */
>    MutexAutoLock lock(mLock);
>  
> +  ClearMessages();
> +  mCurrentSize = 0;

Can remove this if we move it to ClearMessages.

Comment 15

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/0b69076d3bad

Comment 16

[Nathan Froyd [:froydnj]]

I am curious to know whether the additional memory allocations we're doing now have any effect...

Comment 17

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/0b69076d3bad

Comment 18

[Nathan Froyd [:froydnj]]

Comment on attachment 8649445 [details] [diff] [review]
fix quadratic behavior in nsConsoleService

Approval Request Comment
[Feature/regressing bug #]: bug 814497
[User impact if declined]: performance badness
[Describe test coverage new/current, TreeHerder]: I think we have tests for this.
[Risks and why]: Low risk.
[String/UUID change made/needed]: None.

Comment 19

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8649445 [details] [diff] [review]
fix quadratic behavior in nsConsoleService

Fix a bad performance regression, taking it.

Comment 20

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/bb1e32492889