1338335 - Much slower than Chrome in this canvas testcase with SkiaGL on Mac

Status: NEW

(Core :: Graphics, defect, P3)

Description

[Greg Tatum [:gregtatum]]

I'm building a new flame chart for the perf.html project which uses 2d canvas to draw lots of boxes on the screen, with text overlaying it. I was working on making sure it was fast, and came across some performance issues with the canvas calls themselves. mstange suggested I file a bug on it.

STR:
 * run: git clone https://github.com/gregtatum/perf.html
 * run: cd perf.html
 * run: git checkout flame-chart-perf-timing
 * run: npm install
 * run: npm start
 * visit: http://localhost:4242/public/10ef409b5262e09bc6514bd7e53640c6cfe74764/flameChart/?thread=0
 * check "invert callstack"
 * Zoom in with the mouse wheel.
 * As more stacks are rendered, observe how sluggish it becomes.
 * See timing information in the console.log

e.g. console.log in Firefox:
> FlameChartCanvas render took 257ms to execute.
> !!! Drawn on AnimationFrame # 8617 with the time delta 320.320000000007

e.g. console.log in Chrome:
> FlameChartCanvas render took 16ms to execute.
> !!! Drawn on AnimationFrame # 990 with the time delta 35.07499999999709

The profile you are viewing in that link is a profile I took of the code itself. I tried the same thing in Chrome and it was able to keep up pretty well with the amount of draw calls this view was blasting at it.

The canvas draw code is located in:
https://github.com/gregtatum/perf.html/blob/flame-chart-perf-timing/src/content/components/FlameChartCanvas.js

And the tight loop where it's drawing everything is:
https://github.com/gregtatum/perf.html/blob/flame-chart-perf-timing/src/content/components/FlameChartCanvas.js#L112-L156

My next attempt at optimizing this code was to try and group all of my call by color, but mstange suggested I file this first because of the speed disparity.

Comment 1

[Markus Stange [:mstange]]

We have long pauses in ClientCanvasLayer::RenderLayer(), inside GrDrawContext::prepareForExternalIO(). Of the 8334ms in prepareForExternalIO in that profile, 961ms (12%) are spent inside GLContextCGL::MakeCurrentImpl.

Comment 2

[Milan Sreckovic [:milan] (needinfo for best results)]

(In reply to Greg Tatum [:gregtatum] [@gregtatum] from comment #0)
>...
> 
> My next attempt at optimizing this code was to try and group all of my call
> by color, but mstange suggested I file this first because of the speed
> disparity.

Thanks for filing it!  What kind of performance change do you get if you set gfx.canvas.azure.accelerated to false and restart?

Comment 3

[Greg Tatum [:gregtatum]]

It definitely feels a lot more responsive, although the times are still in the same range a bit.

gfx.canvas.azure.accelerated = false

> !!! Drawn on AnimationFrame # 2067 with the time delta 174.66999999999825
> Updated the ctx.fillStyle this many times: 14313
> FlameChartCanvas render took 118ms to execute.
> !!! Drawn on AnimationFrame # 2068 with the time delta 135.49500000000262
> Updated the ctx.fillStyle this many times: 14078
> FlameChartCanvas render took 112ms to execute.
> !!! Drawn on AnimationFrame # 2069 with the time delta 167.97000000000116
> Updated the ctx.fillStyle this many times: 13847
> FlameChartCanvas render took 101ms to execute.
> !!! Drawn on AnimationFrame # 2109 with the time delta 16.650000000001455
> Updated the ctx.fillStyle this many times: 13847
> FlameChartCanvas render took 121ms to execute.
> !!! Drawn on AnimationFrame # 2110 with the time delta 131.9300000000003
> Updated the ctx.fillStyle this many times: 12623
> FlameChartCanvas render took 106ms to execute.
> !!! Drawn on AnimationFrame # 2111 with the time delta 118.65000000000146

The odd thing is the occasional outlier of 16ms.

Running the same test with it toggled back on, it also felt a lot less responsive to mouse input just in general:

gfx.canvas.azure.accelerated = true

> !!! Drawn on AnimationFrame # 1769 with the time delta 263.79999999999563
> Updated the ctx.fillStyle this many times: 10364
> FlameChartCanvas render took 42ms to execute.
> !!! Drawn on AnimationFrame # 2038 with the time delta 15.959999999999127
> Updated the ctx.fillStyle this many times: 10364
> FlameChartCanvas render took 44ms to execute.
> !!! Drawn on AnimationFrame # 2039 with the time delta 282.1399999999994
> Updated the ctx.fillStyle this many times: 12893
> FlameChartCanvas render took 54ms to execute.
> !!! Drawn on AnimationFrame # 2040 with the time delta 353.11500000000524
> Updated the ctx.fillStyle this many times: 14757
> FlameChartCanvas render took 57ms to execute.
> !!! Drawn on AnimationFrame # 2041 with the time delta 385.3199999999997
> Updated the ctx.fillStyle this many times: 15059
> FlameChartCanvas render took 58ms to execute.
> !!! Drawn on AnimationFrame # 2055 with the time delta 16.715000000003783
> Updated the ctx.fillStyle this many times: 15123
> FlameChartCanvas render took 59ms to execute.
> !!! Drawn on AnimationFrame # 2056 with the time delta 394.4099999999962
> Updated the ctx.fillStyle this many times: 18928
> FlameChartCanvas render took 77ms to execute.
> !!! Drawn on AnimationFrame # 2057 with the time delta 505.86500000000524
> Updated the ctx.fillStyle this many times: 19042
> FlameChartCanvas render took 74ms to execute.
> !!! Drawn on AnimationFrame # 2367 with the time delta 16.729999999995925
> Updated the ctx.fillStyle this many times: 19042
> FlameChartCanvas render took 77ms to execute.
> !!! Drawn on AnimationFrame # 2368 with the time delta 507.04499999999825
> Updated the ctx.fillStyle this many times: 21855
> FlameChartCanvas render took 77ms to execute.

Comment 4

[George Wright (:gw280) (needinfo me!)]

(In reply to Markus Stange [:mstange] from comment #1)
> We have long pauses in ClientCanvasLayer::RenderLayer(), inside
> GrDrawContext::prepareForExternalIO(). Of the 8334ms in prepareForExternalIO
> in that profile, 961ms (12%) are spent inside GLContextCGL::MakeCurrentImpl.

Most likely coming from here: http://searchfox.org/mozilla-central/source/gfx/gl/SkiaGLGlue.cpp#33

Comment 5

[Milan Sreckovic [:milan] (needinfo for best results)]

Is this showing up on other platforms as well, or is it OS X specific?

Comment 6

[BugBot [:suhaib / :marco]]

Clear a needinfo that is pending on an inactive user.

Inactive users most likely will not respond; if the missing information is essential and cannot be collected another way, the bug maybe should be closed as INCOMPLETE.

For more information, please visit auto_nag documentation.