Bug 8740 – REGRESSION: benchjs test 1 has slowed by over 150%

• Component: New Bugs
• Status: RESOLVED WONTFIX

[Jon]

Between r13721 and r13738, the speed of the 24fun (benchjs) math test slowed byover 150% on my quad, from ~1.3s to ~3.3s. Most likely this has something to do with WebKit's coalesced updating changes, though I am far from knowing what I'm talking about.

[Dave Hyatt]

This regression only occurs with the status bar showing, and is a bug in WebBrowser... not WebKit or Core.

[Dave Hyatt]

Jon, can you add your hardware information?  We are not seeing this on all machines.

[Darin Adler]

We've figured out what's going on here and we're trying to decide what to do to fix it.

The slowness is due to interaction between the constant repainting in the web view, constant repainting in the status bar, the way AppKit decides when to do a display, and the way that the graphics system blocks the process if you start painting after a window flush but before it can write the data from that flush into the display's frame buffer.

[David Harrison]

Radar #4542808

[Tim Omernick]

I landed a fix for this on TOT a while back.

[Jon]

I'm reopening this because this test is still 30% slower in ToT than shipping WebKit. Also, the two keys added (WebKitThrottleWindowDisplayPreferenceKey and WebKitEnableDeferredUpdatesPreferenceKey) don't seem to have an effect anymore. The test had the same time no matter their settings. Also, the status bar doesn't seem to have an effect either.

As an aside, test 7 of the benchjs suite is 50% slower than shipping.

[Tim Omernick]

Jon, can you provide some more details?  Performance testing can be a tricky thing to get right; I'd like to hear about your methodology.

- Did you do a Debug or a Release build?  Debug builds are much slower than Release.
- What OS version are you on?
- What kind of machine?  How much RAM, etc?
- How many times did you run the test?
- How much variance was there between multiple runs of each test?
- What were the actual numbers you recorded?

[Jon]

Sorry. My setup is a quad G5 with 1GB RAM and 10.4.6. I tested a Release build.

Shipping WebKit averaged 1.19s (repeated 3 times) on the first test, while ToT averaged 1.65 (over 6 times). The settings of the preference keys didn't affect that average. High/low distance on ToT was .06s (1.63 -> 1.69) and .04s (1.18 -> 1.22) on shipping.

[Tim Omernick]

Mass-unassigning my bugs (I'm working on another team right now)

[Dave Hyatt]

Retest? I think this is fixed now.

[Jon]

No, no improvement. It's still 100% slower in ToT/Safari2.0.4 than 419.3/Safari2.0.4. This is 10.4.8 on a Quad G5. .75s for 419.3 and 1.6s for ToT. Having the WebKitEnableDeferredUpdatesPreferenceKey or WebKitEnableDeferredUpdatesPreferenceKey key set doesn't affect the result and neither does having the status bar visible. 

[Jon]

Damnit, I forgot to say that I'm using a Release build of r18232.

[Alexey Proskuryakov]

I also see a speed regression on my G4/1.25DP (1.6 sec with shipping Safari, 2.1 sec with a r18640 nightly). Mac OS X 10.4.8, 1 Gb RAM.

Hiding the status bar doesn't significantly reduce the times.

[Mark Rowe (bdash)]

Re-adding NeedsRadar as radar referenced here was resolved.

[Maciej Stachowiak]

<rdar://problem/4980995>

[Jon]

http://www.jonshier.com/8740TraceWithBar.zip

Above is a link to a trace of ToT running the count test with the status bar visible and the number of iterations set to 10000 instead of 1000. From my brief analysis it looks like WebChromeClient::setStatusBarText is being called twice. Once by KJS::Window::put and once by WebCore::Chrome:setStatusBarText. Both of those together seem to take about 29% of work. I'm going to test again with the status bar hidden and see what that shows.

Here are the results (averaged over 3 runs) for my expanded test (to be posted later once I get it fully reduced).

2.0.4/419.3 with status bar: 7.09s
2.0.4/419.3 without status bar: 6.81s
2.0.4/ToT with status bar: 33.38s
2.0.4/ToT without status bar: 16.78s

Quad G5, 1GB RAM, 10.4.8

[Jon]

Created attachment 13111 [details]
Reduction based on original BenchJS test.

Okay, I've reduced the BenchJS test as far as I'm comfortable with. Index.html loads the button, hit the button to run the test. Test will automatically run again 2 seconds after it completes. Note the time in the left can side.

From my basic analysis of the code, I think both the page and frame containing the text are both trying to set the status bar text, resulting in a duplication of work. It seems both Chrome::setStatusbarText and WebChromeClient::setStatusbarText are getting called. One by Safari and one by WebCore internally perhaps? JavaScriptCore may also be setting it, though I haven't been able to find that (though I would think it would go through Frame::setJSStatusBarText (also note the 'B's in those bars are variably capitalized)).

[Nikolas Zimmermann]

I can also confirm this performance regression - on a MacBook Pro.

[Maciej Stachowiak]

I see this too. Now working on it. Tests 6 and 7 are also regressed.

[Maciej Stachowiak]

TOT WebKit + TOT Safari spends 80% of its time on this test idle - I think this is the 10ms minimum timer threshold kicking in. There may have been a regression from coalesced updates or the status bar at some point but I think those are long gone.

[Maciej Stachowiak]

It's definitely our new timer limiting. When I remove the timer clamping, we complete the test in .275s, less than half the time Safari 2 takes. There is no way to fix the regression without reverting the timer change - we spend more time waiting on the timer (.899s) than our old total score (.674s)

[Maciej Stachowiak]

This is caused by the fix to http://bugs.webkit.org/show_bug.cgi?id=6998

[Maciej Stachowiak]

See also related bug 12866 and bug 12867

[Maciej Stachowiak]

This prety much can't be fixed. The 10ms timer limit forces a slowdown that we can't avoid.

[Jon]

Okay, forgive me if these are stupid questions. If the problem is due to the minimum 10ms timer, and the progress display and statusbar text have to refresh 1000 times, shouldn't the test take 10s + a bit? And doesn't the fact that hiding the status bar cuts the time roughly in half seem to indicate an entirely different problem? 

If I'm entirely off base I'd still like a more complete explanation, if possible.

[Maciej Stachowiak]

1) The status bar problem is actually a bug in Safari, not WebKit. Can't talk about the details though.

2) The reduced version actually runs the test 10 times as long as the real version - the timer fires only 100 times on the real test, at 10ms each, that should take 1 second plus a little bit, which is approximately true in all browsers.