Bug 42432

Created attachment 83292 [details] Work-in-Progress patch This is a work-in-progress patch, therefor it does not include any changelogs. As I've written in the mail to the list[1], this patch assigns current time to only some of the required attributes. The rest are impossible to be set with the current time because either we do not perform that task (domain lookup) or because libsoup does not offer appropriate interface for needed events to be signalized to us. This patch makes the Gtk port perform reasonably well on the Web Timing demo[2] - the redirect counting works and the request and response times logically make up the fetch time, but what's missing (compared to Chromium's performance) is the DSN time (we don't perform that step, so this is not really a problem) and the connect time. The connect time is something that should be made available, but I don't know whether it is possible to correctly implement it in the current resource loading procedure. I'd more than welcome any input on this specific problem. Other than that, with this patch applied some of the web timing tests already pass while others need a bit more tweaking. [1] https://lists.webkit.org/pipermail/webkit-gtk/2011-February/000409.html [2] http://webtimingdemo.appspot.com/

Created attachment 84869 [details] Patch 1: Implementation This patch brings (incomplete) support for the Navigation Timing specification to the Gtk port. I consider the support incomplete because the domain lookup times are not set. Libsoup at this moment does not offer signals we could connect to in order to get notified when domain lookup starts or ends. As/If they're added, the implementation should be properly updated. Another small hack this implementation utilizes is setting the connectEnd time when we receive response. Dan Winship recommended on the libsoup mailing list[1] this could be done by connecting to SoupConnection's notify::state signal which is emitted when state of the connection changes. When state would change from SOUP_CONNECTION_CONNECTING to any other it would mean that connection has ended (successfully or unsuccessfully, it does not matter in this case) and the connectEnd attribute should be assigned the current time. This proved unusable when testing. Because the SoupConnection object is 'semi-private API' (and is on its way to be replaced by a more 'gio-oriented API', explained in the message by Dan) there is no reasonable way to add the SoupConnection to a ResourceHandle so we could disconnect signal handlers when ResourceHandle is deleted. This was shown in testing by crashes when trying to access ResourceLoadTiming object of the ResourceHandle's response. I'd like to see this properly implemented when libsoup makes the change in the API, though. [1] https://mail.gnome.org/archives/libsoup-list/2011-February/msg00004.html

Created attachment 84870 [details] Patch 2: Enabling the passing tests This patch enables the tests that now pass. There are still a few tests that fail: fast/dom/Window/window-properties-performance.html - Heap size is unlimited in JavaScriptCore, see bug #53592[1] http/tests/misc/webtiming-origins.html - problem with origins, probably not timing-specific http/tests/misc/webtiming-slow-load.php - haven't spotted the cause of failure for this one yet http/tests/misc/webtiming-ssl.php - another Navigation Timing attribute that is not set is secureConnectionStart - we should look into libsoup to see if the code there can be modified to notify us of this event [1] https://bugs.webkit.org/show_bug.cgi?id=53592

The third patch would enable timing support when building, but I'd like to clarify whether we want this to be already enabled by default in configure.ac now or to wait for libsoup to get extra functionality and start shipping out a properly working implementation.

Are you looking for a reviewer for these patches? I'm familiar with Web Timing but not GTK. If that is okay, I'm happy to take a look.

Perhaps Sergio would be willing to do an informal review here since he's very familiar with the soup networking backend.

Comment on attachment 84869 [details] Patch 1: Implementation View in context: https://bugs.webkit.org/attachment.cgi?id=84869&action=review > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:63 > +using namespace WTF; Do we really need this? > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:412 > + 0, 0, 0, 0, handle); We do this in cleanupSoupRequestOperation, why would we need this here? > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:573 > +} This seems correct but the problem is that you are handling the "connection-created" signal of any request issued to the SoupSession. Take into account that this callback will be called whenever the SoupSession needs to create a connection (and not only for this particular ResourceHandle). There are some other problems too, see below in the g_signal_connect() part > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:587 > +} Same problem than above, the difference is that in this case you are able to check that the SoupMessage provided by libsoup in the second argument is the same than the one you have in d->m_soupMessage. Otherwise you'll have to discard it as it will be handled by another ResourceHandle. > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:646 > + g_signal_connect(session, "connection-created", G_CALLBACK(connectionCreatedCallback), handle); This is not going to work for one reason. libsoup reuses the connections that have not been closed by the server whenever possible. In such cases libsoup just uses the connections, so no new connection is created and thus, the "connection-created" signal won't be emitted. > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:879 > + g_signal_connect(session, "connection-created", G_CALLBACK(connectionCreatedCallback), handle); Same comment than in the other "conneciton-created" signal connection and something more. Non-HTTP protocols may not involve any kind of network connection at all, for example data: or file:. For those protocols the "connection-created" signal does not make any sense as no connections are used.

Comment on attachment 84869 [details] Patch 1: Implementation View in context: https://bugs.webkit.org/attachment.cgi?id=84869&action=review Thanks for the review! >> Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:63 >> +using namespace WTF; > > Do we really need this? True, this is not really needed. Will remove it and use WTF::currentTime(). >> Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:412 >> + 0, 0, 0, 0, handle); > > We do this in cleanupSoupRequestOperation, why would we need this here? This disconnects every handler that is connected to the SoupSession object, more specifically it disconnects handlers to the connection-created and request-started signals. I don't see this already being done in the current code. >> Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:573 >> +} > > This seems correct but the problem is that you are handling the "connection-created" signal of any request issued to the SoupSession. Take into account that this callback will be called whenever the SoupSession needs to create a connection (and not only for this particular ResourceHandle). There are some other problems too, see below in the g_signal_connect() part Is there a way of ensuring that the connection that was created definitely belongs to a certain ResourceHandle? Current attempt at this is that this callback is connected to the SoupSession object in either startHTTPRequest or startNonHTTPRequest and then disconnected in cleanupSoupRequestOperation, but is that sufficient enough? >> Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:587 >> +} > > Same problem than above, the difference is that in this case you are able to check that the SoupMessage provided by libsoup in the second argument is the same than the one you have in d->m_soupMessage. Otherwise you'll have to discard it as it will be handled by another ResourceHandle. I'll add that check. >> Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:646 >> + g_signal_connect(session, "connection-created", G_CALLBACK(connectionCreatedCallback), handle); > > This is not going to work for one reason. libsoup reuses the connections that have not been closed by the server whenever possible. In such cases libsoup just uses the connections, so no new connection is created and thus, the "connection-created" signal won't be emitted. This might not be a problem as PerformanceTiming::connectStart returns previous time values when no connection (as in network request) is made and therefor connectStart variable is not set. This part is located here: [1] http://trac.webkit.org/browser/trunk/Source/WebCore/page/PerformanceTiming.cpp#L200 >> Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:879 >> + g_signal_connect(session, "connection-created", G_CALLBACK(connectionCreatedCallback), handle); > > Same comment than in the other "conneciton-created" signal connection and something more. Non-HTTP protocols may not involve any kind of network connection at all, for example data: or file:. For those protocols the "connection-created" signal does not make any sense as no connections are used. In that case no connection should be made to this signal, will remove this statement.

Comment on attachment 84869 [details] Patch 1: Implementation Please combine these two patches into one larger patch. That way we can land the implementation and unskip the tests at the same time.

Created attachment 93584 [details] Patch

(In reply to comment #10) > Created an attachment (id=93584) [details] > Patch This patch now combines the previous two and also resolves some of the issues that were brought up during Sergio's review (other are still open to debate IMO).

Comment on attachment 93584 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=93584&action=review Nice work. I think the new code in Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp should only be compiled in if web timing is enabled though. > LayoutTests/platform/gtk/Skipped:-302 > +# Navigation Timing http tests that are still failing > http/tests/misc/webtiming-origins.html > -http/tests/misc/webtiming-one-redirect.php > http/tests/misc/webtiming-slow-load.php > http/tests/misc/webtiming-ssl.php > -http/tests/misc/webtiming-two-redirects.php It'd be nice to have some understanding of why these are still failing. > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:35 > #include "ChromeClient.h" > #include "CookieJarSoup.h" > #include "CachedResourceLoader.h" > +#include "CurrentTime.h" Shouldn't all the new code in this file be guarded by #if ENABLE(WEB_TIMING)?

Created attachment 95285 [details] Patch Patch with added guards and explanations for still-failing tests

Comment on attachment 95285 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=95285&action=review I'm still concerned about Sergio's comment. Seems that this question should be resolved before we can land this: > This seems correct but the problem is that you are handling the "connection-created" signal of any request issued to the SoupSession. Take into account that this callback will be called whenever the SoupSession needs to create a connection (and not only for this particular ResourceHandle). There are some other problems too, see below in the g_signal_connect() part > LayoutTests/platform/gtk/Skipped:303 > +# Navigation Timing http tests that are still failing > +# Redirect stats are not zeroed out after a cross-origin redirect, > +# plus the third iframe does not load at all Do you mind opening a bug for this? > LayoutTests/platform/gtk/Skipped:306 > +# The load is not slow enough - sleeping for two seconds instead > +# of one makes the test succeed. Here as well? Please try to fix this test as a followup. > LayoutTests/platform/gtk/Skipped:310 > http/tests/misc/webtiming-ssl.php Perhaps this should be filed as a bug in upstream? > Source/WebCore/GNUmakefile.am:583 > +if ENABLE_WEB_TIMING > +FEATURE_DEFINES += ENABLE_WEB_TIMING=1 > +webcore_cppflags += -DENABLE_WEB_TIMING=1 > +endif # END ENABLE_WEB_TIMING What affect does this have on runtime performance. Do other ports enable it by default or only to run tests? > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:416 > + g_signal_handlers_disconnect_matched(handle->defaultSession(), G_SIGNAL_MATCH_DATA, > + 0, 0, 0, 0, handle); This can be one line.

Created attachment 97962 [details] Updated patch w/ a new approach to connection times This is an updated patch that handles the mentioned connection problems in a new way.

(In reply to comment #15) > Created an attachment (id=97962) [details] > Updated patch w/ a new approach to connection times > > This is an updated patch that handles the mentioned connection problems in a new way. In this post I'll describe changes in a more detailed way along with replies to other comments. This is more of a work-in-progress patch, just to present new methods that are used. For starters I've removed compilation guards - ResourceLoadTiming object is also used by the Web Inspector so there might even be some progression on that part. The ResourceLoadTiming object itself is not guarded by any compilation guards and neither should be any use of it. PerformanceTiming object is simply using ResourceLoadTiming to provide needed information so this is more implementation of ResourceLoadTiming usage than implementation of Web Timing specification itself. Also this patch updates ResourceLoadTiming only for HTTP requests as it seems useless to time events in almost-instant local file loading. But I'm not sure about that as I write, so I should look into it. (In reply to comment #14) > (From update of attachment 95285 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=95285&action=review > > I'm still concerned about Sergio's comment. Seems that this question should be resolved before we can land this: > > > This seems correct but the problem is that you are handling the "connection-created" signal of any request issued to the SoupSession. Take into account that this callback will be called whenever the SoupSession needs to create a connection (and not only for this particular ResourceHandle). There are some other problems too, see below in the g_signal_connect() part > In the updated patch every time a new HTTP request is started (in startHTTPRequest) the ResourceResponse is told that the connection will be reused. This flag can be set to false though if the connection-created signal is triggered on the SoupSession object. This flag is then checked in the PerformanceTiming object whenever connectStart or connectEnd attributes are requested - if true, the time of previous event is returned, otherwise the times in ResourceLoadTiming are used. The only problem is that there's no appropriate signals in libsoup to connect to to acquire connectStart and connectEnd times. Because of that I've added two corresponding signals to the SoupMessage object. I'll attach a patch here just for the sake of convenience but this should really be discussed with libsoup devs elsewhere, but I'd like to hear some thoughts about this approach. > > Source/WebCore/GNUmakefile.am:583 > > +if ENABLE_WEB_TIMING > > +FEATURE_DEFINES += ENABLE_WEB_TIMING=1 > > +webcore_cppflags += -DENABLE_WEB_TIMING=1 > > +endif # END ENABLE_WEB_TIMING > > What affect does this have on runtime performance. Do other ports enable it by default or only to run tests? > I don't think this would have any significant impact on performance, but there was some debate on the mailing list about how users with this feature enabled could be under threat of fingerprinting and privacy breach[1]. Chromium port enables this by default but I believe the best way for our port would be to have this feature disabled in configure.ac and enabled in build-webkit script for testing purposes. > > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:416 > > + g_signal_handlers_disconnect_matched(handle->defaultSession(), G_SIGNAL_MATCH_DATA, > > + 0, 0, 0, 0, handle); > > This can be one line. Fixed. > All other comments about layout tests are noted. These issues will be addressed as soon as we get the connections problems resolved. Also there are some evident bugs that I'd like to address before landing the implementation (mostly about redirects and how they're handled). [0] https://lists.webkit.org/pipermail/webkit-dev/2011-May/016803.html

Created attachment 97973 [details] Libsoup patch This is just a quick addition of the connect-start and connect-end signals to SoupMessage. This is not a proposed patch, just a quick hack to get precise time for mentioned events.

With glib and libsoup master, SoupMessage now has a "network-event" signal, that fires as network-related things are going on (including DNS, socket connection, and TLS handshaking). I think that (plus the session "request-started" signal to notice the case where the message is send on an existing connection) should be enough to cover everything in the timing spec... Try it out. (You should be able to build the new versions by editing Tools/gtk/jhbuild.modules so the libsoup tag is 7c2f1956808b31ade19a5cb24d16a465ad575421, and change glib to module="glib", tag="3f3e141ec8ffe8f40a2faced69d35cb161153107". I think...)

Created attachment 120652 [details] Patch

Comment on attachment 120652 [details] Patch Attachment 120652 [details] did not pass gtk-ews (gtk): Output: http://queues.webkit.org/results/11034592

Comment on attachment 120652 [details] Patch >--- a/Tools/gtk/jhbuild.modules >+++ b/Tools/gtk/jhbuild.modules >@@ -128,7 +128,7 @@ > </dependencies> > <branch module="libsoup" version="2.37.2.1+git" > repo="git.gnome.org" >- tag="5cbfc48caf76ced2e28ee06c9e40523273601dc6"/> >+ tag="7c2f1956808b31ade19a5cb24d16a465ad575421"/> > </autotools> you need to update glib too (switching it from tarball to git, with the correct tag). (Though the EWS build would have failed anyway since it doesn't seem to know how to handle jhbuild.modules changes...) >+# SSL start is getting a value when it should apparently not > http/tests/misc/webtiming-ssl.php This shouldn't be hard to fix...

As of today the EWS will run update-webkitgtk-libs after applying the patch, so let's try updating this patch =D

(In reply to comment #22) > As of today the EWS will run update-webkitgtk-libs after applying the patch, so let's try updating this patch =D Also a new review of the patch wouldn't harm :P

Comment on attachment 120652 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=120652&action=review > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:571 > + g_signal_connect(session, "request-started", G_CALLBACK(requestStartedCallback), handle); It's a bit gross that every ResourceHandle connects to this signal and then ignores it except for its own message. It would be cleaner to just connect once, statically... you could use g_object_set_data() to associate the handle with its SoupMessage? (I'm making a note to add something to libsoup so you don't need to get that signal off the session...) > LayoutTests/platform/gtk/Skipped:263 > +# Web Timing issues some of these might be because the network-events don't get emitted when reusing a persistent connection? Not sure if the existing WebKit code handles setting them to the right default values in that case

I'm working on updating the jhbuild part of this patch, but I hit a jhbuild limitation (see https://bugzilla.gnome.org/show_bug.cgi?id=668107). Meanwhile, here's the change I have: diff --git a/Tools/gtk/jhbuild.modules b/Tools/gtk/jhbuild.modules index 2dcbf63..2f88a0b 100644 --- a/Tools/gtk/jhbuild.modules +++ b/Tools/gtk/jhbuild.modules @@ -106,10 +106,10 @@ <dependencies> <dep package="libffi"/> </dependencies> - <branch module="/pub/GNOME/sources/glib/2.31/glib-2.31.2.tar.xz" version="2.31.2" + <branch module="/pub/GNOME/sources/glib/2.31/glib-2.31.8.tar.xz" version="2.31.8" repo="ftp.gnome.org" - hash="sha256:19d7921671a487c3c5759a57df7b8508afdbadd7764d62a47a82fff7b399032b" - md5sum="1cbdf314d7c87916a0c3dce83ac0285f"/> + hash="sha256:1ce3d275189000e1c50e92efcdb6447bc260b1e5c41699b7a1959e3e1928fbaa" + md5sum="6909664f29fae2f00cc3181c8c6a6aa7"/> </autotools> <autotools id="glib-networking"> @@ -138,9 +138,9 @@ <dependencies> <dep package="glib-networking"/> </dependencies> - <branch module="libsoup" version="2.37.2.1+git" + <branch module="libsoup" version="2.37.4+git" repo="git.gnome.org" - tag="5cbfc48caf76ced2e28ee06c9e40523273601dc6"/> + tag="b92be4347c981205ca2fb4362f8f03301d1ab905"/> </autotools> <autotools id="fontconfig" autogen-sh="configure">

Created attachment 122787 [details] Patch

Comment on attachment 122787 [details] Patch Patch with just the jhbuild stuff updated, to test the new EWS jhbuild stuff

(In reply to comment #24) > (From update of attachment 120652 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=120652&action=review > > > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:571 > > + g_signal_connect(session, "request-started", G_CALLBACK(requestStartedCallback), handle); > > It's a bit gross that every ResourceHandle connects to this signal and then ignores it except for its own message. It would be cleaner to just connect once, statically... you could use g_object_set_data() to associate the handle with its SoupMessage? That's true that is a bit overkill, hopefully not many ResourceHandle's exist at a time, but anyway I agree it could be done the way you mention. > (I'm making a note to add something to libsoup so you don't need to get that signal off the session...) > > > LayoutTests/platform/gtk/Skipped:263 > > +# Web Timing issues > > some of these might be because the network-events don't get emitted when reusing a persistent connection? Not sure if the existing WebKit code handles setting them to the right default values in that case hmm didn't take that into account, will double-check

Comment on attachment 122787 [details] Patch Attachment 122787 [details] did not pass gtk-ews (gtk): Output: http://queues.webkit.org/results/11269261

Created attachment 123939 [details] Patch

Last version of the patch including Gustavo's changes, Dan's suggestion to connect only once to request-started and a last-minute fix (reset the request time when the message is redirected).

Comment on attachment 123939 [details] Patch Attachment 123939 [details] did not pass gtk-ews (gtk): Output: http://queues.webkit.org/results/11343600

Dan, any clue regarding that build failure? Do we need to explicitly link the GI scanner to gmodule?

I think it's a problem with gobject-introspection being built against the system glib but run against the jhbuild glib? If so, easiest fix is probably to just add g-i to the jhbuild config.

Created attachment 124552 [details] Patch

Added G-I to jhbuild.modules; this addition requires that python-dev be installed (I got it installed on the EWSs and buildbot).

Created attachment 124556 [details] Patch

Comment on attachment 124556 [details] Patch Attachment 124556 [details] did not pass gtk-ews (gtk): Output: http://queues.webkit.org/results/11368581

*** Bug 77944 has been marked as a duplicate of this bug. ***

Created attachment 134524 [details] Patch

Comment on attachment 134524 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=134524&action=review LGTM > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:140 > +static int currentTimeMinusRequestTime(double requestTime); Can we give this function a more descriptive name, like milisecondsSinceRequest? > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:459 > +static void wroteBodyCallback(SoupMessage *, gpointer data) * position > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:472 > +static void requestStartedCallback(SoupSession *, SoupMessage *soupMessage, SoupSocket *, gpointer data) The * is in the wrong side for all of them here. > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:487 > + if (d->m_response.resourceLoadTiming()->sslStart != -1) > + // WebCore/inspector/front-end/ResourceTimingView.js assumes that SSL time is included > + // in connection time so must substract here the SSL delta that will be added later. > + d->m_response.resourceLoadTiming()->sendStart -= > + d->m_response.resourceLoadTiming()->sslEnd - d->m_response.resourceLoadTiming()->sslStart; Can we have {} around this? Multiple lines make it harder to make sure it's only a single statement. This comment could be improved too, I understood it after reading a couple of times, but it's not obvious that somewhere the time spent in ssl will be added somewhere (pointing to where would be good =D). > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:490 > +static void networkEventCallback(SoupMessage *, GSocketClientEvent event, GIOStream *, gpointer data) More * > Source/WebCore/platform/network/soup/ResourceHandleSoup.cpp:513 > + if (d->m_response.resourceLoadTiming()->dnsStart != -1) > + // WebCore/inspector/front-end/ResourceTimingView.js assumes that DNS time is included > + // in connection time so must substract here the DNS delta that will be added later. > + d->m_response.resourceLoadTiming()->connectStart -= > + d->m_response.resourceLoadTiming()->dnsEnd - d->m_response.resourceLoadTiming()->dnsStart; Ditto the comment about SSL above.

Committed r114736: <http://trac.webkit.org/changeset/114736>