Bug 117689 – [GTK][Meta] REGRESSION (r150890): Timeouts and errors in /WebKit2APITests/TestWebKitWebView, /WebKit2APITests/TestContextMenu unit tests

• Component: WebKitGTK
• Status: NEW

[Zan Dobersek]

The following two unit tests started timing out after r150890:
/WebKit2APITests/TestWebKitWebView
/WebKit2APITests/TestContextMenu

http://trac.webkit.org/changeset/150890

First build with r150890:
http://build.webkit.org/builders/GTK%20Linux%2064-bit%20Release/builds/38155
http://build.webkit.org/builders/GTK%20Linux%2064-bit%20Release/builds/38155/steps/API%20tests/logs/stdio

The build before that:
http://build.webkit.org/builders/GTK%20Linux%2064-bit%20Release/builds/38154
http://build.webkit.org/builders/GTK%20Linux%2064-bit%20Release/builds/38154/steps/API%20tests/logs/stdio

Also note that the 'libEGL warning: GLX/DRI2 is not supported' warnings start appearing after this commit.

[Zan Dobersek]

Gustavo might as well nailed it:
(03:23:09 PM) kov: zdobersek, looks like the gstreamer AC integration does not respect the runtime setting
(03:23:59 PM) kov: this should probably do a settings check to see whether ac is enabled http://trac.webkit.org/browser/trunk/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamerBase.h#L108

[Zan Dobersek]

I'll have a try with Gustavo's proposal.

[Zan Dobersek]

(In reply to comment #1)
> Gustavo might as well nailed it:
> (03:23:09 PM) kov: zdobersek, looks like the gstreamer AC integration does not respect the runtime setting
> (03:23:59 PM) kov: this should probably do a settings check to see whether ac is enabled http://trac.webkit.org/browser/trunk/Source/WebCore/platform/graphics/gstreamer/MediaPlayerPrivateGStreamerBase.h#L108

Turns out that accelerated compositing is enabled by default on WK2. This basically means that taking the runtime setting into account wouldn't change the current behavior, so the problem would persist.

[Gustavo Noronha (kov)]

How come layout tests are not failing, then?

[Brian Holt]

I'm finding that this is failing for 64bit debug builds with 

UIClientTest::add("WebKitWebView", "create-ready-close", testWebViewCreateReadyClose);

ASSERTION FAILED: m_currentItem
../../Source/WebCore/loader/HistoryController.cpp(116) : void WebCore::HistoryController::restoreScrollPositionAndViewState()
1   0x7ff62fa93254 /home/WebKit/WebKitBuild/Debug/.libs/libjavascriptcoregtk-3.0.so.0(WTFCrash+0x1e) [0x7ff62fa93254]

which happens because in Source/WebCore/loader/FrameLoader.cpp:2170 
m_loadType == FrameLoadTypeReload is true, calling history()->restoreScrollPositionAndViewState();

The funny thing is that if I make this the *only* test or put it first then it passes.  Worse, if I put it first then 
ModalDialogsTest::add("WebKitWebView", "allow-modal-dialogs", testWebViewAllowModalDialogs);
fails with the same error.  So its something to do with state and I'm not sure how to address this.

[Brian Holt]

(In reply to comment #5)
> I'm finding that this is failing for 64bit debug builds with 
> 
> UIClientTest::add("WebKitWebView", "create-ready-close", testWebViewCreateReadyClose);
> 
> ASSERTION FAILED: m_currentItem
> ../../Source/WebCore/loader/HistoryController.cpp(116) : void WebCore::HistoryController::restoreScrollPositionAndViewState()
> 1   0x7ff62fa93254 /home/WebKit/WebKitBuild/Debug/.libs/libjavascriptcoregtk-3.0.so.0(WTFCrash+0x1e) [0x7ff62fa93254]
> 
> which happens because in Source/WebCore/loader/FrameLoader.cpp:2170 
> m_loadType == FrameLoadTypeReload is true, calling history()->restoreScrollPositionAndViewState();
> 
> The funny thing is that if I make this the *only* test or put it first then it passes.  Worse, if I put it first then 
> ModalDialogsTest::add("WebKitWebView", "allow-modal-dialogs", testWebViewAllowModalDialogs);
> fails with the same error.  So its something to do with state and I'm not sure how to address this.
 
The reload load type is set in the PolicyChecker in this stack trace:
#0  WebCore::PolicyChecker::setLoadType (this=0x99dc00, loadType=WebCore::FrameLoadTypeReload)
    at ../../Source/WebCore/loader/PolicyChecker.h:65
#1  0x00007ffff3fafb41 in WebCore::FrameLoader::loadWithDocumentLoader (this=0x8a11f0, loader=0x91b460, 
    type=WebCore::FrameLoadTypeReload, prpFormState=...) at ../../Source/WebCore/loader/FrameLoader.cpp:1378
#2  0x00007ffff3fb0611 in WebCore::FrameLoader::reloadWithOverrideEncoding (this=0x8a11f0, encoding=...)
    at ../../Source/WebCore/loader/FrameLoader.cpp:1491
#3  0x00007ffff37acbd9 in WebKit::WebPage::setCustomTextEncodingName (this=0x9f3a00, encoding=...)
    at ../../Source/WebKit2/WebProcess/WebPage/WebPage.cpp:3321

[Anton Obzhirov]

My 2 cents here: the problem occurs after reloading of the test page. In testWebViewCustomCharset webkit_web_view_set_custom_charset(test->m_webView, "utf8"); will trigger reload of the page. Since it is asynchronous operation at some point later other test will assert in void WebCore::HistoryController::restoreScrollPositionAndViewState(). (if you add test->waitUntilLoadFinished(); next line after webkit_web_view_set_custom_charset(test->m_webView, "utf8"); it will assert in the current test). Did anybody else come across this problem before? As for r150890 change - don't think it it is directly related to this problem - may be timing has changed or something like that.

[Brian Holt]

I've spent quite some time trying to find fixes for the multiple problems in this unit test and it seems that some of the tests are context-dependent, that is, it passes on the first run and the fails on the second for example (mouse-target does that).

Can I propose to split TestWebKitWebView into a number of unit tests that test related things? So for example a TestAuthenticationRequest, a TestModalDialogs, a TestFileChooserRequest, TestUIClient...  That way we will be able to skip with finer granularity and it should be easier to fix tests (not have to fix more than one issue to get it back up and running)?

[Brian Holt]

I think I've found the source of the timeouts.  With DISPLAY=:0 (i.e. the X server) the entire test passes in 1 second.  With DISPLAY=:55 (Xvfb as set up in run-gtk-tests) here is 1 of 6 tests, taking just under 30s.

brian.holt@ws-1156:WebKit (bug120202)$ ./WebKitBuild/Debug/Programs/WebKit2APITests/TestWebViewAuthentication 
/webkit2/WebKitWebView/authentication-request: 
*** 2013-08-27.10:34:29  [../../Source/WebKit2/UIProcess/API/gtk/tests/TestWebViewAuthentication.cpp:54] AuthenticationTest

*** 2013-08-27.10:34:29  [../../Source/WebKit2/UIProcess/API/gtk/tests/TestWebViewAuthentication.cpp:89] waitForAuthenticationRequest

(lt-WebKitWebProcess:20782): GLib-GObject-CRITICAL **: g_object_unref: assertion `G_IS_OBJECT (object)' failed

*** 2013-08-27.10:34:54  [../../Source/WebKit2/UIProcess/API/gtk/tests/TestWebViewAuthentication.cpp:80] runAuthentication

*** 2013-08-27.10:34:54  [../../Source/WebKit2/UIProcess/API/gtk/tests/TestWebViewAuthentication.cpp:84] runAuthentication

*** 2013-08-27.10:34:54  [../../Source/WebKit2/UIProcess/API/gtk/tests/TestWebViewAuthentication.cpp:91] waitForAuthenticationRequest OK

The time is spent waiting in the g_main_loop, in poll().  

I thought that the problem may be to do with the GLib-CRITICAL, so here is a backtrace of the WebProcess 

Breakpoint 1, g_return_if_fail_warning (log_domain=0x7ffff009e464 "GLib-GObject", 
    pretty_function=0x7ffff00a1943 <__PRETTY_FUNCTION__.12903> "g_object_unref", expression=0x7ffff00a0577 "G_IS_OBJECT (object)")
    at gmessages.c:1019
1019	  g_log (log_domain,
(gdb) bt
#0  g_return_if_fail_warning (log_domain=0x7ffff009e464 "GLib-GObject", 
    pretty_function=0x7ffff00a1943 <__PRETTY_FUNCTION__.12903> "g_object_unref", expression=0x7ffff00a0577 "G_IS_OBJECT (object)")
    at gmessages.c:1019
#1  0x00007ffff1cd412c in search_closure_free (data=0x74ed80) at secret-methods.c:52
#2  0x00007ffff1712278 in clear_op_res (simple=0x7492b0) at gsimpleasyncresult.c:259
#3  g_simple_async_result_finalize (object=0x7492b0) at gsimpleasyncresult.c:279
#4  0x00007ffff007b018 in g_object_unref (_object=0x7492b0) at gobject.c:3024
#5  0x00007ffff1cd3443 in on_search_service (source=<optimised out>, result=0x881150, user_data=<optimised out>)
    at secret-methods.c:255
#6  0x00007ffff17130a7 in g_simple_async_result_complete (simple=0x881150) at gsimpleasyncresult.c:777
#7  0x00007ffff1cdd985 in on_init_base (source=<optimised out>, result=0x7fff60003600, user_data=<optimised out>)
    at secret-service.c:679
#8  0x00007ffff17130a7 in g_simple_async_result_complete (simple=0x7fff60003600) at gsimpleasyncresult.c:777
#9  0x00007ffff17131a9 in complete_in_idle_cb (data=<optimised out>) at gsimpleasyncresult.c:789
#10 0x00007fffefd86f55 in g_main_dispatch (context=0x677460) at gmain.c:3054
#11 g_main_context_dispatch (context=context@entry=0x677460) at gmain.c:3630
#12 0x00007fffefd87298 in g_main_context_iterate (context=0x677460, block=block@entry=1, dispatch=dispatch@entry=1, 
    self=<optimised out>) at gmain.c:3701
#13 0x00007fffefd8770a in g_main_loop_run (loop=0x693e60) at gmain.c:3895
#14 0x00007ffff621f96a in WebProcessMainGtk ()
   from /home/likewise-open/SERILOCAL/brian.holt/Code/gnome3B/WebKit/WebKitBuild/Release/.libs/libwebkit2gtk-3.0.so.25
#15 0x00007ffff590776d in __libc_start_main (main=0x4006f0 <main>, argc=2, ubp_av=0x7fffffffcae8, init=<optimised out>, 
    fini=<optimised out>, rtld_fini=<optimised out>, stack_end=0x7fffffffcad8) at libc-start.c:226
#16 0x0000000000400721 in _start ()

[Brian Holt]

A breakpoint in secret.c:52 under the X backend, yields a different backtrace to the Xvfb backend. 

Breakpoint 1, search_closure_free (data=0x81b380) at secret-methods.c:52
52		g_object_unref (closure->service);
(gdb) bt
#0  search_closure_free (data=0x81b380) at secret-methods.c:52
#1  0x00007ffff1712278 in clear_op_res (simple=0x962890) at gsimpleasyncresult.c:259
#2  g_simple_async_result_finalize (object=0x962890) at gsimpleasyncresult.c:279
#3  0x00007ffff007b018 in g_object_unref (_object=0x962890) at gobject.c:3024
#4  0x00007ffff17130a7 in g_simple_async_result_complete (simple=0x8c3df0) at gsimpleasyncresult.c:777
#5  0x00007ffff17131a9 in complete_in_idle_cb (data=<optimised out>) at gsimpleasyncresult.c:789
#6  0x00007fffefd86f55 in g_main_dispatch (context=0x677460) at gmain.c:3054
#7  g_main_context_dispatch (context=context@entry=0x677460) at gmain.c:3630
#8  0x00007fffefd87298 in g_main_context_iterate (context=0x677460, block=block@entry=1, dispatch=dispatch@entry=1,  self=<optimised out>) at gmain.c:3701
#9  0x00007fffefd8770a in g_main_loop_run (loop=0x72fc40) at gmain.c:3895
#10 0x00007ffff621f96a in WebProcessMainGtk ()
   from /home/likewise-open/SERILOCAL/brian.holt/Code/gnome3B/WebKit/WebKitBuild/Release/.libs/libwebkit2gtk-3.0.so.25
#11 0x00007ffff590776d in __libc_start_main (main=0x4006f0 <main>, argc=2, ubp_av=0x7fffffffcae8, init=<optimised out>, 
    fini=<optimised out>, rtld_fini=<optimised out>, stack_end=0x7fffffffcad8) at libc-start.c:226
#12 0x0000000000400721 in _start ()

[Zan Dobersek]

When running the test outside of Xvfb, did you still run it through the run-gtk-tests script?

If so, this is obviously somehow affected by the Xvfb display (which would be odd).

If not, try modifying the run-gtk-tests script so it uses the default display (i.e. DISPLAY=:0), and then run the test through the script. I'd bet that in this case, the test would still time out, meaning that the run-gtk-tests script fails short at setting up a proper testing environment (most likely a necessary environment is left out).

[Carlos Garcia Campos]

(In reply to comment #11)
> When running the test outside of Xvfb, did you still run it through the run-gtk-tests script?
> 
> If so, this is obviously somehow affected by the Xvfb display (which would be odd).
> 
> If not, try modifying the run-gtk-tests script so it uses the default display (i.e. DISPLAY=:0), and then run the test through the script. I'd bet that in this case, the test would still time out, meaning that the run-gtk-tests script fails short at setting up a proper testing environment (most likely a necessary environment is left out).

You don't need to modify the script, simply use --no-xvfb and the current display will be used.

[Brian Holt]

I've been assuming that https://bugs.webkit.org/show_bug.cgi?id=120202 will get in and working on the three independent tests and TestContextMenu.  Here follows a list of the errors found:

TestWebKitWebView:
Release: snapshot test -> obtained surface too large ( > 50 pixels)
         page-visibility ->  g_assert(JSValueIsString(context, value)) fails

Debug: snapshot test (same as release)
       page-visibility (same as release)
       custom-charset test -> History controller assertion failed
       Takes 100s under run-get-tests under both X and Xvfb
       but runs instantly as standalone (X and Xvfb)

TestWebViewAuthentication:
Release and Debug: passes under X (run-gtk-tests)
                   fails under Xvfb -> times out in libsecret looking for a service from dbus

TestWebViewUIClient:
Release: passes under X (run-gtk-tests)
         fails under Xvfb -> NV-GLX missing and times out

Debug: passes under X (run-gtk-tests)
       fails under Xvfb -> mouse-target (assertion in HashTranslator)

TestContextMenu:
Release: fails under X -> default-menu assertion failure webkit_context_menu_item_is_separator(item)
         warning under Xvfb -> GLX not available

Debug: default-menu test (same as release)
       after that it passes

[Brian Holt]

(In reply to comment #11)
> When running the test outside of Xvfb, did you still run it through the run-gtk-tests script?
> 
> If so, this is obviously somehow affected by the Xvfb display (which would be odd).
> 
> If not, try modifying the run-gtk-tests script so it uses the default display (i.e. DISPLAY=:0), and then run the test through the script. I'd bet that in this case, the test would still time out, meaning that the run-gtk-tests script fails short at setting up a proper testing environment (most likely a necessary environment is left out).

After trying out all the various tests under run-gtk-tests I've compiled a list of the errors.  It seems that the X vs Xvfb behaviour is especially bad for the Authentication tests but does cause some other issues.

I'd like to address each of these errors in turn, but probably each under their own bug. What do you think?

[Zan Dobersek]

Yes, separate bugs are best.

[Zan Dobersek]

All the blocking bugs have been fixed.
Brian, is there anything left here to do?

[Brian Holt]

(In reply to comment #16)
> All the blocking bugs have been fixed.
> Brian, is there anything left here to do?

I've just raised 4 bugs to track the other issues found in these unit tests, and renamed this to be a meta bug.

[Zan Dobersek]

Cool, thanks.

Unassigning myself from here since this bug is now meta.

[Carlos Garcia Campos]

Does /WebKit2APITests/TestContextMenu still fail for you? auth tests and mouse-target still fail for me, but context menu doesn't. Why did we skip the whole web view suite if only auth and mouse-target tests timed out? I've split the web view test in bug #126284 and skipped only auth and mouse-target. Maybe we can also unskip the context menu tests.

[Brian Holt]

(In reply to comment #19)
> Does /WebKit2APITests/TestContextMenu still fail for you? auth tests and mouse-target still fail for me, but context menu doesn't. Why did we skip the whole web view suite if only auth and mouse-target tests timed out? I've split the web view test in bug #126284 and skipped only auth and mouse-target. Maybe we can also unskip the context menu tests.

The ContextMenu tests are working for me, so I vote to unskip them.

[Carlos Alberto Lopez Perez]

Seems that the context menu tests fails with xvfb when the system has mesa < 10. The failure seems related with the message:

libEGL warning: GLX/DRI2 is not supported


With mesa > 10 (tested 10.1.0-5 from Debian) the context menu tests now works.


*However*, seems that something is still wrong, because if you run the tests with LIBGL_DEBUG=verbose the following warnings show:

libGL: OpenDriver: trying /usr/lib/x86_64-linux-gnu/dri/tls/swrast_dri.so
libGL: OpenDriver: trying /usr/lib/x86_64-linux-gnu/dri/swrast_dri.so
libGL: driver does not expose __driDriverGetExtensions_swrast(): /usr/lib/x86_64-linux-gnu/dri/swrast_dri.so: undefined symbol: __driDriverGetExtensions_swrast


The Debian bug https://bugs.debian.org/743843 seems to be related. I'm not sure about the importance of this warnings.

[Martin Robinson]

(In reply to comment #21)
> Seems that the context menu tests fails with xvfb when the system has mesa < 10. The failure seems related with the message:
> 
> libEGL warning: GLX/DRI2 is not supported
> 
> 
> With mesa > 10 (tested 10.1.0-5 from Debian) the context menu tests now works.
> 
> 
> *However*, seems that something is still wrong, because if you run the tests with LIBGL_DEBUG=verbose the following warnings show:
> 
> libGL: OpenDriver: trying /usr/lib/x86_64-linux-gnu/dri/tls/swrast_dri.so
> libGL: OpenDriver: trying /usr/lib/x86_64-linux-gnu/dri/swrast_dri.so
> libGL: driver does not expose __driDriverGetExtensions_swrast(): /usr/lib/x86_64-linux-gnu/dri/swrast_dri.so: undefined symbol: __driDriverGetExtensions_swrast
> 
> 
> The Debian bug https://bugs.debian.org/743843 seems to be related. I'm not sure about the importance of this warnings.

I wonder if this will be fixed by: https://bugs.webkit.org/show_bug.cgi?id=131472

[Carlos Alberto Lopez Perez]

(In reply to comment #22)
> I wonder if this will be fixed by: https://bugs.webkit.org/show_bug.cgi?id=131472

I tested the patch, but it (still) don't helps here.

The issue is the same because the added mesa to jhbuild isn't building the swrast DRI driver, so the system one is still beeing used.

Maybe the swrast_dri driver should be also built? In order to load it, we can use the environment variable LIBGL_DRIVERS_PATH. Probably we only should set this env variable when running the tests under Xvfb (but not when launching the minibrowser for example)

[Martin Robinson]

(In reply to comment #23)
> (In reply to comment #22)
> > I wonder if this will be fixed by: https://bugs.webkit.org/show_bug.cgi?id=131472
> 
> I tested the patch, but it (still) don't helps here.
> 
> The issue is the same because the added mesa to jhbuild isn't building the swrast DRI driver, so the system one is still beeing used.
> 
> Maybe the swrast_dri driver should be also built? In order to load it, we can use the environment variable LIBGL_DRIVERS_PATH. Probably we only should set this env variable when running the tests under Xvfb (but not when launching the minibrowser for example)

That in bug 131472, doesn't affect run-gtk-tests. It only uses LD_LOAD_PATH when running the WebKitTestRunner test harness. That might be why it didn't fix the issue?

[Carlos Garcia Campos]

Is this still a problem? those tests have been skipped for too long :-(

[Carlos Garcia Campos]

I've unskipped the context menu tests in r188032 to check if it still fails in the bots or not.

[Carlos Alberto Lopez Perez]

/webkit/WebKitWebView/mouse-target passes now on GTK. Expectations updated at 263883@main