1464823 - [Wayland] GLContextEGL::SwapBuffers() races with main thread wl_display_* calls.

Status: RESOLVED FIXED

(Core :: Widget: Gtk, defect)

Description

[Christian Stadelmann]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101 Firefox/60.0
Build ID: 20100101

Steps to reproduce:

1. Open firefox-wayland (works from a fresh profile)
2. open about:config
3. change layers.acceleration.force-enabled to true
4. restart firefox-wayland
5. open anything which has a popover, e.g. the menu shown from sandwich button or the library menu or the downloads symbol. It is also being triggered when bookmarking a page or opening the "page actions" ("…") symbol or the lock symbol in url bar.


Actual results:

GUI freezes completely. No interaction possible. No error messages or crashes either. Firefox can be terminated cleanly by sending it a SIGTERM


Expected results:

No freeze. Just behave as without acceleration.


Affected version:

Firefox build on Fedora 28, firefox-60.0.1-3.fc28.x86_64


Additional info:
This does not affect the main menu (which is visible after pressing the Alt key) nor the context menu at any position I checked including the URL bar.

Comment 1

[Takuro Ashie [:ashie]]

This is the bug I mentioned at bug1438144comment13.

Comment 2

[Martin Stránský [:stransky] (ni? me)]

There's the backtrace from Compositor thread which causes the freeze. It's because mozilla::gl::GLContextEGL::SwapBuffers() calls wl_display_dispatch_queue() on default display/queue as well as the main thread which causes a race condition here.

#0  0x00007ffff6da6589 in poll () at /lib64/libc.so.6
#1  0x00007ffff28776a9 in poll (__timeout=-1, __nfds=1, __fds=0x7fffc6f65ce0) at /usr/include/bits/poll2.h:46
#2  0x00007ffff28776a9 in wl_display_poll (display=display@entry=0x7ffff6a61440, events=events@entry=1)
    at src/wayland-client.c:1717
#3  0x00007ffff287913c in wl_display_dispatch_queue (display=0x7ffff6a61440, queue=0x7fffb49ec380)
    at src/wayland-client.c:1790
#4  0x00007fffc19650bb in  () at /lib64/libEGL_mesa.so.0
#5  0x00007fffc19560ea in eglSwapBuffers () at /lib64/libEGL_mesa.so.0
#6  0x00007fffe18010bd in mozilla::gl::GLLibraryEGL::fSwapBuffers(void*, void*) const (this=0x7fffeb8c5780 <mozilla::gl::sEGLLibrary>, dpy=0x7fffc2db2800, surface=0x7fffade57000) at /home/komat/tmp676-trunk-gtk3/src2/gfx/gl/GLLibraryEGL.h:229
#7  0x00007fffe1811ad8 in mozilla::gl::GLContextEGL::SwapBuffers() (this=0x7fffacc87000)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/gl/GLContextProviderEGL.cpp:501
#8  0x00007fffe18e4dc2 in mozilla::layers::CompositorOGL::EndFrame() (this=0x7fffade6d400)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/opengl/CompositorOGL.cpp:1771
#9  0x00007fffe1a5c0b8 in mozilla::layers::LayerManagerComposite::Render(mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&, mozilla::gfx::IntRegionTyped<mozilla::gfx::UnknownUnits> const&) (
    this=0x7fffaccf5af0, aInvalidRegion=..., aOpaqueRegion=...)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/composite/LayerManagerComposite.cpp:995
#10 0x00007fffe1a59d8a in mozilla::layers::LayerManagerComposite::UpdateAndRender() (this=0x7fffaccf5af0)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/composite/LayerManagerComposite.cpp:534
#11 0x00007fffe1a59990 in mozilla::layers::LayerManagerComposite::EndTransaction(mozilla::TimeStamp const&, mozilla::layers::LayerManager::EndTransactionFlags) (this=0x7fffaccf5af0, aTimeStamp=..., aFlags=mozilla::layers::LayerManager::END_DEFAULT)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/composite/LayerManagerComposite.cpp:464
#12 0x00007fffe1a82127 in mozilla::layers::CompositorBridgeParent::CompositeToTarget(mozilla::gfx::DrawTarget*, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const*) (this=0x7fffade56800, aTarget=0x0, aRect=0x0)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/ipc/CompositorBridgeParent.cpp:1062
#13 0x00007fffe1a8a7c1 in mozilla::layers::CompositorVsyncScheduler::ForceComposeToTarget(mozilla::gfx::DrawTarget*, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const*) (this=0x7fffade6d280, aTarget=0x0, aRect=0x0)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/ipc/CompositorVsyncScheduler.cpp:279
#14 0x00007fffe1a8240b in mozilla::layers::CompositorBridgeParent::ForceComposeToTarget(mozilla::gfx::DrawTarget*, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const*) (this=0x7fffade56800, aTarget=0x0, aRect=0x0)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/ipc/CompositorBridgeParent.cpp:1135
#15 0x00007fffe1a80d93 in mozilla::layers::CompositorBridgeParent::RecvFlushRendering() (this=0x7fffade56800)
    at /home/komat/tmp676-trunk-gtk3/src2/gfx/layers/ipc/CompositorBridgeParent.cpp:604
#16 0x00007fffe124cd88 in mozilla::layers::PCompositorBridgeParent::OnMessageReceived(IPC::Message const&, IPC::Message*&) (this=0x7fffade56800, msg__=..., reply__=@0x7fffc6f66968: 0x0)
    at /home/komat/tmp676-trunk-gtk3/src2/objdir/ipc/ipdl/PCompositorBridgeParent.cpp:1453
#17 0x00007fffe1251365 in mozilla::layers::PCompositorManagerParent::OnMessageReceived(IPC::Message const&, IPC::Message*&) (this=0x7ffff6adae30, msg__=..., reply__=@0x7fffc6f66968: 0x0)
    at /home/komat/tmp676-trunk-gtk3/src2/objdir/ipc/ipdl/PCompositorManagerParent.cpp:271
#18 0x00007fffe0dcc9b2 in mozilla::ipc::MessageChannel::DispatchSyncMessage(IPC::Message const&, IPC::Message*&) (this=0x7fffc3eb1100, aMsg=..., aReply=@0x7fffc6f66968: 0x0) at /home/komat/tmp676-trunk-gtk3/src2/ipc/glue/MessageChannel.cpp:2104
#19 0x00007fffe0dcc652 in mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) (this=0x7fffc3eb1100, aMsg=...)
    at /home/komat/tmp676-trunk-gtk3/src2/ipc/glue/MessageChannel.cpp:2062
#20 0x00007fffe0dcbca7 in mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) (this=0x7fffc3eb1100, aTask=...) at /home/komat/tmp676-trunk-gtk3/src2/ipc/glue/MessageChannel.cpp:1912

Comment 3

[Martin Stránský [:stransky] (ni? me)]

Attachment: wip

Wip workaround for the issue.

Comment 4

[Martin Stránský [:stransky] (ni? me)]

Attachment: Bug 1464823 - [Wayland] Don't paint until we have a visible wl_surface,

Mesa Wayland eglSwapBuffers() implementation contains a bug if eglSwapBuffers() is called
from non-main thread.

When eglSwapBuffers() waits for frame callback (to be synced with display) it calls
wl_display_dispatch_queue() to get Wayland events from the display (and thus the frame callback event).

Unfortunatelly the same display connection (display fd) is operated by Gtk+ main loop which runs its own
loop on the same display connection. That leads to race condition between main and compositor thread.

Review commit: https://reviewboard.mozilla.org/r/248164/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/248164/

Comment 5

[Martin Stránský [:stransky] (ni? me)]

Reported at Mesa as https://bugs.freedesktop.org/show_bug.cgi?id=106753

Comment 6

[Daniel Stone]

wl_display_dispatch_queue does _not_ dispatch the default queue. The queue dispatched by Mesa internally is a separate internal queue created only by Mesa and nothing else. It is safe against race conditions.

If Mozilla itself works with the Wayland connection's socket, it needs to use the wl_display_prepare_read() API in order to ensure thread safety.

There was one Mesa bug where swrast would always hang like this, which was due to a typo (dispatching the wrong queue) rather than any fundamental lack of thread safety. That is fixed in later patch release versions for 17.3 (I think 17.3.8 onwards), 18.0 (18.0.2 onwards); 18.1 and 18.2 are fine.

Comment 7

[Martin Stránský [:stransky] (ni? me)]

(In reply to Daniel Stone from comment #6)
> wl_display_dispatch_queue does _not_ dispatch the default queue. The queue
> dispatched by Mesa internally is a separate internal queue created only by
> Mesa and nothing else. It is safe against race conditions.
> 
> If Mozilla itself works with the Wayland connection's socket, it needs to
> use the wl_display_prepare_read() API in order to ensure thread safety.
> 
> There was one Mesa bug where swrast would always hang like this, which was
> due to a typo (dispatching the wrong queue) rather than any fundamental lack
> of thread safety. That is fixed in later patch release versions for 17.3 (I
> think 17.3.8 onwards), 18.0 (18.0.2 onwards); 18.1 and 18.2 are fine.

Sure, I'm not an expert there. I uploaded the requested logs at https://bugs.freedesktop.org/show_bug.cgi?id=106753 for further investigation.

Comment 8

[Jonas Ådahl]

Copying my comment from the FDO bug report:

So what it looks like is that:

1. Firefox creates two surfaces, wl_surface@39 and wl_surface@40
2. Firefox turn wl_surface@40 into a desynchronous subsurface on top of wl_surface@39
3. Firefox turn wl_surface@39 into a xdg_toplevel and commits the initial (empty) state
4. The compositor sends the configure event to the xdg_toplevel
5. Firefox replies immediately with ack_configure() without attaching a buffer

This will probably consume any compositor: you just mapped a window, asked to configure it (draw the first frame), but what happened is that no content was posted even though the configure event was acknowledged

6. Firefox asks for a frame callback, attaches a new buffer to the subsurface and commits it

When Firefox tries to do eglSwapBuffers() again

When it does this, it waits for the frame callback, but that will never happen because the toplevel was never mapped, meaning the subsurface never has a chance to be displayed, meaning the frame callback will never be invoked.

The xdg_surface interface states the following:

      For an xdg_surface to be mapped by the compositor, the following
      conditions must be met:
      (1) the client has assigned an xdg_surface-based role to the surface
      (2) the client has set and committed the xdg_surface state and the
	  role-dependent state to the surface
      (3) the client has committed a buffer to the surface

The third condition here was never met.

This raises the question, what is the intended content of the subsurface and what is the intended content of the toplevel?

Comment 9

[Lee Salzman [:lsalzman]]

Comment on attachment 8982142 [details]
Bug 1464823 - [Wayland] Don't paint until we have a visible wl_surface,

https://reviewboard.mozilla.org/r/248164/#review254464

Comment 10

[Jonas Ådahl]

Just to point out, there doesn't seem to be any race condition in Mesa, so the motivation in the patch is incorrect. Mesa can handle multiple threads with a single wl_display just fine. What happens is that since eglSwapInterval(1) is used, the swap-buffers call waits for the VSync-callback of the old buffer (buffer was painted), which won't happen because it has not been mapped yet by Firefox.

Comment 11

[Martin Stránský [:stransky] (ni? me)]

(In reply to Jonas Ådahl from comment #10)
> Just to point out, there doesn't seem to be any race condition in Mesa, so
> the motivation in the patch is incorrect. Mesa can handle multiple threads
> with a single wl_display just fine. What happens is that since
> eglSwapInterval(1) is used, the swap-buffers call waits for the
> VSync-callback of the old buffer (buffer was painted), which won't happen
> because it has not been mapped yet by Firefox.

Jonas, Thanks for the info, I need to think it over.

Comment 12

[Martin Stránský [:stransky] (ni? me)]

(In reply to Jonas Ådahl from comment #10)
> Just to point out, there doesn't seem to be any race condition in Mesa, so
> the motivation in the patch is incorrect. Mesa can handle multiple threads
> with a single wl_display just fine. What happens is that since
> eglSwapInterval(1) is used, the swap-buffers call waits for the
> VSync-callback of the old buffer (buffer was painted), which won't happen
> because it has not been mapped yet by Firefox.

Yes, the swap-buffers/VSync-callback is called on subsurface owned/managed by Firefox and the parent toplevel surface is owned by Gtk. 

Mesa is called early here and the swap-buffers/VSync-callback is called before Gtk updates content of the toplevel window - that's why we don't have a valid xdg_surface here.

Comment 13

[Takuro Ashie [:ashie]]

Attachment: avoid-freeze-wayland-with-egl.patch

> Mesa is called early here and the swap-buffers/VSync-callback is called before Gtk updates content of the toplevel window - that's why we don't have a valid xdg_surface here.

I also confirmed it, and can avoid it by the attached patch.
But the patch is still too ugly.
How can I know properly whether the surface is committed or not from outside of GDK?

Comment 14

[Martin Stránský [:stransky] (ni? me)]

Comment on attachment 8982142 [details]
Bug 1464823 - [Wayland] Don't paint until we have a visible wl_surface,

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/248164/diff/1-2/

Comment 15

[Martin Stránský [:stransky] (ni? me)]

(In reply to Takuro Ashie from comment #13)
> Created attachment 8983659 [details] [diff] [review]
> avoid-freeze-wayland-with-egl.patch
> 
> > Mesa is called early here and the swap-buffers/VSync-callback is called before Gtk updates content of the toplevel window - that's why we don't have a valid xdg_surface here.
> 
> I also confirmed it, and can avoid it by the attached patch.
> But the patch is still too ugly.

I just updated the patch, Thanks!

Comment 16

[Hiroshi Hatake [:cosmo0920]]

(In reply to Martin Stránský [:stransky] from comment #15)
> (In reply to Takuro Ashie from comment #13)
> > Created attachment 8983659 [details] [diff] [review]
> > avoid-freeze-wayland-with-egl.patch
> > 
> > > Mesa is called early here and the swap-buffers/VSync-callback is called before Gtk updates content of the toplevel window - that's why we don't have a valid xdg_surface here.
> > 
> > I also confirmed it, and can avoid it by the attached patch.
> > But the patch is still too ugly.
> 
> I just updated the patch, Thanks!

I got SEGV with your patch on my devices(RZ/G1M, R-Car M3). :'(
But SEGV detail is concealed because SEGV occurred within PowerVR driver.

Comment 17

[Martin Stránský [:stransky] (ni? me)]

(In reply to Hiroshi Hatake [:cosmo0920] from comment #16)
> (In reply to Martin Stránský [:stransky] from comment #15)
> > (In reply to Takuro Ashie from comment #13)
> > > Created attachment 8983659 [details] [diff] [review]
> > > avoid-freeze-wayland-with-egl.patch
> > > 
> > > > Mesa is called early here and the swap-buffers/VSync-callback is called before Gtk updates content of the toplevel window - that's why we don't have a valid xdg_surface here.
> > > 
> > > I also confirmed it, and can avoid it by the attached patch.
> > > But the patch is still too ugly.
> > 
> > I just updated the patch, Thanks!
> 
> I got SEGV with your patch on my devices(RZ/G1M, R-Car M3). :'(
> But SEGV detail is concealed because SEGV occurred within PowerVR driver.

Can you attach at least some backtrace of the crash?

Comment 18

[Hiroshi Hatake [:cosmo0920]]

```
(gdb) bt
#0  0xa473c9b8 in ?? () from /usr/lib/libpvrPVR2D_WAYLANDWSEGL.so
#1  0x0001f65c in calloc ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
```

Comment 19

[Martin Stránský [:stransky] (ni? me)]

(In reply to Hiroshi Hatake [:cosmo0920] from comment #18)
> ```
> (gdb) bt
> #0  0xa473c9b8 in ?? () from /usr/lib/libpvrPVR2D_WAYLANDWSEGL.so
> #1  0x0001f65c in calloc ()
> Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Please try to disable e10s (set browser.tabs.remote.autostart to false) and attach backtrace of all threads.

Comment 20

[Hiroshi Hatake [:cosmo0920]]

Attachment: thread_apply_all_bt.txt

Comment 21

[Hiroshi Hatake [:cosmo0920]]

Thread 37 backtrace looks mozilla::detail::ConditionVariableImpl::wait_for(mozilla::detail::MutexImpl&, mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator> const&) () infinity printed.

Ashie's patch can work on R-Car&RZ/G1.

Comment 22

[Martin Stránský [:stransky] (ni? me)]

(In reply to Hiroshi Hatake [:cosmo0920] from comment #21)
> Thread 37 backtrace looks
> mozilla::detail::ConditionVariableImpl::wait_for(mozilla::detail::MutexImpl&,
> mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator> const&) ()
> infinity printed.

That bt does not look very useful, looks like some recursion happens on stack which is exhausted. Maybe some code fails when moz_container_get_wl_surface() / moz_container_get_wl_egl_window() return nullptr?

Comment 23

[Hiroshi Hatake [:cosmo0920]]

I obtained EGL API calling trace with apitrace.

API calling trace dump says:

---
// process.name = "/usr/lib/firefox/firefox"
0 eglGetDisplay(display_id = 0xb6a21120) = 0x1
1 eglInitialize(dpy = 0x1, major = NULL, minor = NULL) = EGL_TRUE
9 eglChooseConfig(dpy = 0x1, attrib_list = {EGL_SURFACE_TYPE, EGL_WINDOW_BIT, E
GL_RENDERABLE_TYPE, EGL_OPENGL_ES2_BIT, EGL_RED_SIZE, 8, EGL_GREEN_SIZE, 8, EGL
_BLUE_SIZE, 8, EGL_ALPHA_SIZE, 8, EGL_NONE}, configs = {0x2, 0x1, 0x3}, config_
size = 64, num_config = &3) = EGL_TRUE
14 eglCreateWindowSurface(dpy = 0x1, config = 0x2, win = NULL, attrib_list = {}
) // incomplete
---

Comment 24

[Martin Stránský [:stransky] (ni? me)]

Thanks, looks like win = NULL is the problem here, as moz_container_get_wl_egl_window() can return nullptr as an invalid surface. I'll investigate that.

Comment 25

[Jan Horak [:jhorak]]

Comment on attachment 8982142 [details]
Bug 1464823 - [Wayland] Don't paint until we have a visible wl_surface,

https://reviewboard.mozilla.org/r/248164/#review256980

Comment 26

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f13d1acd73da
[Wayland] Don't paint until we have a visible wl_surface, r=jhorak,lsalzman

Comment 27

[Dorel Luca [:dluca]]

https://hg.mozilla.org/mozilla-central/rev/f13d1acd73da

Comment 28

[Martin Stránský [:stransky] (ni? me)]

(In reply to Hiroshi Hatake [:cosmo0920] from comment #23)
> I obtained EGL API calling trace with apitrace.
> 
> API calling trace dump says:
> 
> ---
> // process.name = "/usr/lib/firefox/firefox"
> 0 eglGetDisplay(display_id = 0xb6a21120) = 0x1
> 1 eglInitialize(dpy = 0x1, major = NULL, minor = NULL) = EGL_TRUE
> 9 eglChooseConfig(dpy = 0x1, attrib_list = {EGL_SURFACE_TYPE,
> EGL_WINDOW_BIT, E
> GL_RENDERABLE_TYPE, EGL_OPENGL_ES2_BIT, EGL_RED_SIZE, 8, EGL_GREEN_SIZE, 8,
> EGL
> _BLUE_SIZE, 8, EGL_ALPHA_SIZE, 8, EGL_NONE}, configs = {0x2, 0x1, 0x3},
> config_
> size = 64, num_config = &3) = EGL_TRUE
> 14 eglCreateWindowSurface(dpy = 0x1, config = 0x2, win = NULL, attrib_list =
> {}
> ) // incomplete
> ---

Please file a follow up bug for that - I'll look at it. Thanks.

Comment 29

[Hiroshi Hatake [:cosmo0920]]

I've filed a followup bug. Thanks.