1382150 - Initializing the WebGL context takes ~70 ms in opening the facebook chat tab

Status: NEW

(Core :: Graphics: CanvasWebGL, defect, P3)

Description

[Cervantes Yu [:cyu] [:cervantes]]

When I was profiling bug 1366960, I found that the facebook chat tab, when first opened, will create a canvas element and initialize a webgl context for it. This takes ~16 ms in user space, but the whole time span is about 70 ms (please refer to the attached WPA screenshot). In comparison, Google chrome only takes 35 ms to initialize the WebGL context.

PS. This isn't counted in the measurement for bug 1366960 because the canvas is created *inside* the chat tab, and before this there is already screen changes that draws the chat tab. But this does slow down the content inside the chat tab so I think this is still worth investigating.

Comment 1

[Cervantes Yu [:cyu] [:cervantes]]

Attachment: Init the webgl context, captured from WPA

Comment 2

[Jeff Muizelaar [:jrmuizel]]

Can you get a gecko profile of this happening?

Comment 3

[Cervantes Yu [:cyu] [:cervantes]]

Gecko profile: https://perfht.ml/2ub4bOa
Please note that mozilla::dom::CanvasRenderingContextHelper::GetContext() is reported taking 24 ms in the profile, but actually the whole time span is ~70ms because there are missing samples (holes on the stack graph) and are not counted. Also there are several DLL loads before this taking ~200 ms, which also look like relevant.

PS. This is taken on a machine with a hard drive. The 70 ms result in comment 1 is taken on a machine with SSD.

Comment 4

[Cervantes Yu [:cyu] [:cervantes]]

(In reply to Cervantes Yu [:cyu] [:cervantes] from comment #3)
> not counted. Also there are several DLL loads before this taking ~200 ms,
> which also look like relevant.
> 
I checked that patched_LdrLoadDll() is called from
mozglue.dll!patched_LdrLoadDll Line 591	C++
[External Code]	
xul.dll!`anonymous namespace'::LoadLibrarySystem32 Line 367	C++
xul.dll!mozilla::gl::GLLibraryEGL::EnsureInitialized Line 345	C++
xul.dll!mozilla::gl::GLContextProviderEGL::CreateOffscreen Line 973	C++
xul.dll!mozilla::CreateGLWithANGLE Line 625	C++
xul.dll!mozilla::WebGLContext::CreateAndInitGLWith Line 681	C++
xul.dll!mozilla::WebGLContext::CreateAndInitGL Line 793	C++
xul.dll!mozilla::WebGLContext::SetDimensions Line 1014	C++
xul.dll!mozilla::dom::CanvasRenderingContextHelper::UpdateContext Line 249	C++
xul.dll!mozilla::dom::CanvasRenderingContextHelper::GetContext Line 204	C++
xul.dll!mozilla::dom::HTMLCanvasElement::GetContext Line 984	C++
xul.dll!mozilla::dom::HTMLCanvasElementBinding::getContext Line 254	C++
xul.dll!mozilla::dom::GenericBindingMethod Line 3066	C++
xul.dll!js::InternalCallOrConstruct Line 470	C++
xul.dll!Interpret Line 3066	C++
xul.dll!js::RunScript Line 410	C++

But our stackwalker skips the frames from [External Code] to Interpret() so it shows in the profiler that JS calls directly into patched_LdrLoadDll().

Comment 5

[Jeff Muizelaar [:jrmuizel]]

So Chrome has a single context that it multiplexes everything into. This allows them to pay some of this initialization cost at startup. That being said, there's probably some things we could do to improve this. For one, it looks some of the ANGLE code for getting the extensions is not very efficient (see the chunks of time being spent in std::string).

Comment 6

[Jeff Muizelaar [:jrmuizel]]

Also, before pursuing any work on this it would be worth trying to get a higher resolution profile (perhaps using vtune/codexl/visual studio)

Comment 7

[Michael Leu[:Lenzak](UTC+8)]

I tried profiling Nightly when it is browsing a facebook page with VisualStudio, but I didn't see it create any WebGL context, only some canvas 2D drawing.

From reading the code in charge of loading EGL library on Windows, I think most of the time is spent on loading DLL libraries.

I will try different facebook pages to trigger the WebGL context creation.

Comment 8

[Cervantes Yu [:cyu] [:cervantes]]

(In reply to Michael Leu[:Lenzak](UTC+8) from comment #7)
> I tried profiling Nightly when it is browsing a facebook page with
> VisualStudio, but I didn't see it create any WebGL context, only some canvas
> 2D drawing.
> 
> From reading the code in charge of loading EGL library on Windows, I think
> most of the time is spent on loading DLL libraries.
> 
> I will try different facebook pages to trigger the WebGL context creation.

The test case is opening a chat tab after signing in facebook. The context is created inside the chat dialog. You might also want to restart the browser before testing this so that the DLLs really get loaded.

Comment 9

[Kelsey Gilbert [:jgilbert]]

I'm unclear why the chat tab would be creating a webgl context. Can you just either pre-alloc a context with requestIdleCallback or lazily alloc the context creation?

Comment 10

[Michael Leu[:Lenzak](UTC+8)]

I have reproduced the same situation in facebook messenger and profiled it.

I tried 2 scenarios:

1. First open facebook messenger chatbox.
2. Close facebook tab and reopen facebook and open the messenger chatbox.

1. takes about 33ms to initialize WebGL context.
2. takes only 2ms to initialize WebGL context.

The 2 stacks look different, although both of them called CanvasRenderingContextHelper::UpdateContext.

It seems that 1. calls egl::Initialize which takes about 26ms is the most significant factor which affect initial time.

However, even though second WebGLContext loading is faster, no visible difference between loading time of facebook chatbox.

Comment 11

[Michael Leu[:Lenzak](UTC+8)]

The WebGL context initializing time is affected by IO performance.

Profiling in Comment 10 is performed in an SSD.

I redo the profiling on a HDD, the first webgl context initializing time is 511ms and second initializing time is about 30ms.

In addition, the chatbox loading time is notably slower than on SSD.

Comment 12

[Michael Leu[:Lenzak](UTC+8)]

Attachment: ANGLE disabled vs ANGLE enabled

Oh... I made a mistake.

The 511ms profile is performed with ANGLE disabled.

So I made a comparison between ANGLE enabled and disabled, both on HDD.

It turns out that loading ANGLE's dll is quite cheap, the most significant part is actually ANGLE context initialization which doesn't take quite long.

Comment 13

[Peter Chang[:pchang]]

(In reply to Michael Leu[:Lenzak](UTC+8) from comment #10)
> I have reproduced the same situation in facebook messenger and profiled it.
> 
> I tried 2 scenarios:
> 
> 1. First open facebook messenger chatbox.
> 2. Close facebook tab and reopen facebook and open the messenger chatbox.
> 
> 1. takes about 33ms to initialize WebGL context.
> 2. takes only 2ms to initialize WebGL context.
> 
Why we got 70ms in comment 0?
> The 2 stacks look different, although both of them called
> CanvasRenderingContextHelper::UpdateContext.
> 
> It seems that 1. calls egl::Initialize which takes about 26ms is the most
> significant factor which affect initial time.
> 
> However, even though second WebGLContext loading is faster, no visible
> difference between loading time of facebook chatbox.

So the initialization of WebGL context is slower only in the first time.
And user can't tell the difference between the first and second time opening chat box.

(In reply to Michael Leu[:Lenzak](UTC+8) from comment #12)
> Created attachment 8891219 [details]
> ANGLE disabled vs ANGLE enabled

Why do we need to consider the scenario with ANGEL disabled?

Comment 14

[Michael Leu[:Lenzak](UTC+8)]

(In reply to Peter Chang[:pchang] from comment #13)
> (In reply to Michael Leu[:Lenzak](UTC+8) from comment #10)
> > I have reproduced the same situation in facebook messenger and profiled it.
> > 
> > I tried 2 scenarios:
> > 
> > 1. First open facebook messenger chatbox.
> > 2. Close facebook tab and reopen facebook and open the messenger chatbox.
> > 
> > 1. takes about 33ms to initialize WebGL context.
> > 2. takes only 2ms to initialize WebGL context.
> > 
> Why we got 70ms in comment 0?

I tested it on a different PC, I think it is because of hardware difference.

> > The 2 stacks look different, although both of them called
> > CanvasRenderingContextHelper::UpdateContext.
> > 
> > It seems that 1. calls egl::Initialize which takes about 26ms is the most
> > significant factor which affect initial time.
> > 
> > However, even though second WebGLContext loading is faster, no visible
> > difference between loading time of facebook chatbox.
> 
> So the initialization of WebGL context is slower only in the first time.
> And user can't tell the difference between the first and second time opening
> chat box.
>

Yes, the most time-consuming part is initializing ANGLE's library but it's not significant comparing to the whole chatbox opening time.
 
> (In reply to Michael Leu[:Lenzak](UTC+8) from comment #12)
> > Created attachment 8891219 [details]
> > ANGLE disabled vs ANGLE enabled
> 
> Why do we need to consider the scenario with ANGEL disabled?

I once think disabling ANGLE should be faster just like those WebGL benchmarks we profiled.

But we didn't know it needs much more time for initialization until now.

I think this information is useful since Jeff is considering disabling ANGLE.

Comment 15

[Michael Leu[:Lenzak](UTC+8)]

I retested WebGLContext initialization time with following controlled factors.

All test are tested with ANGLE enabled.

1. HDD or SSD (Both configuration has Windows inside SSD, only Firefox in different drives)

2. First open in a boot, reopen tab and reopen browser.

The result is below:

` \|[First Open]|[Reopen Tab]|[Reopen Browser]|
-----------------------------------------------
HDD|   111.8ms  |   1.2ms    |     29ms       |
-----------------------------------------------
SSD|    81.7ms  |   2.4ms    |     28.5ms     |    
-----------------------------------------------

We can see HDD/SSD only affect first open browser in a boot, because we need to load those DLL files into RAM.
After first open browser, the DLLs are loaded into OS cache so initialization time is faster when we open browser again.

Although we initialize WebGL context faster, the difference is less than 0.1sec which is not visually significant.

I will now observe what chrome perform on it and try to profile it.

Comment 16

[BugBot [:suhaib / :marco/ :calixte]]

The bug assignee didn't login in Bugzilla in the last 7 months.
:jgilbert, could you have a look please?
For more information, please visit auto_nag documentation.