Bug 251336 – [SOUP] Very slow to load the CNN or Globe and Mail websites

• Status: RESOLVED
• Resolution: MOVED
• Component: WebKitGTK

[Jeff Fortin]

Created attachment 464747 [details]
sysprof output on 44's tech preview flatpak

With Epiphany 44 "technology preview" flatpak (from GNOME Nightly) on a ThinkPad X220T (Intel Sandybridge graphics) in a Xorg/X11 GNOME session on Fedora 37, the following is noticeably slow:

1. In a new tab (or private browsing window), try loading https://www.theglobeandmail.com/ ; notice it tends to take a solid 10-20 seconds to respond and load. Firefox starts and finishes loading in less than a second.
2. When loaded, try scrolling (in my case, with the mouse wheel) to the bottom of the page. It will be slow, and in many areas, will experience choke points where the UI janks, lags, freezes temporarily, etc.

Also: reloading the page takes 14 seconds (according to my stopwatch). As you might imagine, doing the same thing in  Firefox takes only a second or less.

This was tested on a pretty fast 30 mbits connection, via wired ethernet.

Attached is a sysprof capture.

[Jeff Fortin]

Another test case website exhibiting similar performance problems in Epiphany is https://www.cnn.com ; it also takes about 15-20 seconds to load in Epiphany TP, whereas it takes 1 to 3 seconds in Firefox, both using private browsing windows.

[Michael Catanzaro]

(In reply to Jeff Fortin from comment #1)
> Another test case website exhibiting similar performance problems in
> Epiphany is https://www.cnn.com ; it also takes about 15-20 seconds to load
> in Epiphany TP, whereas it takes 1 to 3 seconds in Firefox, both using
> private browsing windows.

Smells like bug #247748.

It looks like the web process is pretty busy, but I don't see anything in particular that looks suspicious.

Secondarily: I notice the network process is spending an inordinate amount of time calling gnutls_x509_trust_list_add_system_trust(), which is supposed to be a one-time operation. That's weird. Well, it's a one-time operation per GTlsDatabase, but each GTlsConnection should use the default GTlsDatabase. I see p11-kit is also working pretty hard. So that's surprising and certainly not good, but it should also be a one-time problem that happens only when you first start the browser.

[Michael Catanzaro]

(In reply to Michael Catanzaro from comment #2)
> Secondarily: I notice the network process is spending an inordinate amount
> of time calling gnutls_x509_trust_list_add_system_trust(), which is supposed
> to be a one-time operation. That's weird. Well, it's a one-time operation
> per GTlsDatabase, but each GTlsConnection should use the default
> GTlsDatabase. I see p11-kit is also working pretty hard. So that's
> surprising and certainly not good, but it should also be a one-time problem
> that happens only when you first start the browser.

To be clear: that all has to finish before the first HTTP request even begins. So I think you profiled the first page load that the browser made after starting, right? (If not, something is *very* wrong. :)

[Jeff Fortin]

I think I profiled the first load after a fresh start yes, but from what I can see right now it's pretty much just as slow on subsequent loads (if you close the tab, open a new tab, and try to load the same site again; even in normal non-private-window mode). Furthermore, it eats the CPU cores while doing so, even before the page starts displaying content.

[Kdwk]

Loading these sites is still pretty slow, but scrolling is no longer an issue after https://github.com/WebKit/WebKit/commit/06b9ec1834d27a4fb8a324e29908ed274305620a

[Michael Catanzaro]

Excellent! Jeff, please retest after the next WebKitGTK update is out (will probably be called 2.39.91) and close if you agree it's fixed.

[Kdwk]

This cannot be observed in Gnome Web 44.2, a stable release of Web.

[Jeff Fortin]

Scrolling is smooth now with Epiphany 44.3 and WebKitGTK 2.40.3, however the load times are still embarrassingly slow in comparison to other browsers... and those loads are just as slow when reloading the pages. As a test case, it takes 10 to 11 seconds every time I try to load the Globe and Mail, whether I am in a private window or a regular one.

[Jeff Fortin]

Created attachment 466940 [details]
web inspector network profiling captures

I don't know if these are any good (the "Import" button in epiphany's web inspector's network tab doesn't do anything, and the import feature in Chromium also seems to be buggy as it doesn't show the waterfall chart or anything like that), but here's two HAR captures, comparing Epiphany (WebKitGTK) to Chromium (Blink).

[Jeff Fortin]

Created attachment 466941 [details]
screenshots of the web inspector network profiles

Screenshots, just in case the HAR files are not useful by themselves.

I'm not sure what I'm looking at, but from my uneducated perspective, it appears as if:

* WebKitGTK is trying to load all the images/assets/etc. in sequence, many of which are hundreds of miliseconds apart, instead of loading everything at once? Yet theglobeandmail.com is HTTP2 AFAICT (like every website I've encountered in recent years)...
* Nothing at all happens in the first second?
* Looking at the details of one of the connections (the first one), comparing Epiphany (left) vs Chromium (right), it seems like Epiphany wastes a solid third of a second just waiting on TCP or something (but apparently not waiting on DNS)
* When looking at the timing details of the various assets being loaded, every asset has a longer "waiting" time AND "download" time in Epiphany than Chromium. Sometimes 3 to 10 times longer, and it all adds up I guess... hence the 10 seconds load time instead of 1-2 seconds.

Those are just my naïve observations, I hope the HAR files will be more useful to you, or that you can reproduce the issue with those websites on your end in the same way.

This is all running on Wayland btw, but I doubt it changes anything as this seems more related to networking and parallelization than graphics...

[Michael Catanzaro]

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

[Michael Catanzaro]

That information should be useful. Thanks.

And yes, the HAR import feature has been broken for a long time. There is bug #245216 for that, but it's been broken for much longer.

> This is all running on Wayland btw, but I doubt it changes anything as this
> seems more related to networking and parallelization than graphics...

Right, the problem here is definitely networking. Something's either wrong with how we use libsoup, or else with libsoup itself. Not sure which.

[Jeff Fortin]

Also a potential factor why those websites are such good benchmarks to stress-test WebKitGTK compared to some other websites: although Epiphany (with its built-in ad blocker) says there are 161 resources across 30 domains when loading the Globe & Mail website (in the statusbar of the network inspector), according to gtmetrix.com (which I presume would be the count without an ad blocker) that website creates over 550 requests. CNN.com reportedly creates over 900 requests (but Epiphany sees "only" 220+ requests spread across 63+ domains, and takes 2.2 minutes until it considers the page fully loaded)!

[Michael Catanzaro]

Something very weird that I noticed: cnn.com consistently loads *much* faster using my personal jhbuild-built WebKitGTK (at 266205@main) than it does in Tech Preview (2.41.6).

Try one:
Michael's JHBuild: 8.83s
Epiphany Tech Preview: 35.50s
Firefox: 2.90s

Try two:
Michael's JHBuild: 7.08s
Epiphany Tech Preview: 31.33s
Firefox: 1.98s

The extreme different between my personal build vs. Tech Preview is difficult to explain. I was using a slightly older libsoup from April, but updating it to the latest version (to match Tech Preview) doesn't make any difference.

One possible difference that could speed things up is that something is wrong with GStreamer in my jhbuild environment:

(WebKitWebProcess:2): GStreamer-WARNING **: 11:49:43.875: External plugin loader failed. This most likely means that the plugin loader helper binary was not found or could not be run. You might need to set the GST_PLUGIN_SCANNER environment variable if your setup is unusual. This should normally not be required though.

[Philippe Normand]

(In reply to Michael Catanzaro from comment #14)
> 
> One possible difference that could speed things up is that something is
> wrong with GStreamer in my jhbuild environment:
> 
> (WebKitWebProcess:2): GStreamer-WARNING **: 11:49:43.875: External plugin
> loader failed. This most likely means that the plugin loader helper binary
> was not found or could not be run. You might need to set the
> GST_PLUGIN_SCANNER environment variable if your setup is unusual. This
> should normally not be required though.

That could be https://gitlab.freedesktop.org/gstreamer/gstreamer/-/issues/2877

[Michael Catanzaro]

(In reply to Michael Catanzaro from comment #14)
> Something very weird that I noticed: cnn.com consistently loads *much*
> faster using my personal jhbuild-built WebKitGTK (at 266205@main) than it
> does in Tech Preview (2.41.6).

So we've figured out that this bug is caused by flatpak itself:

 * Performance is good when building with jhbuild instead of flatpak
 * Performance is good when using GIO_USE_PORTALS=1 and GDK_DEBUG=portals
 * Performance is good when building and running the org.gnome.Epiphany.Debug.json flatpak-builder manifest in GNOME Builder

Notably, when using the flatpak-builder manifest in GNOME Builder, we are running the exact same software/dependencies as Epiphany Tech Preview, but not actually running under 'flatpak run', so this eliminates the potential that a bad version of some dependency (I was suspecting libsoup) is to blame for the difference. It also means we really have to test under 'flatpak run' itself to reproduce the problem.

Unfortunately this means it's really hard to set up an edit/compile/test workflow to debug the issue.

Patrick thinks we should debug (a) whether anything slow is happening during main context iterations that might be preventing the next main context iteration from running in a reasonable time, and also (b) soup-client-message-io-http2.c. However, I don't know how to do this reasonably. I think I would need to build and install a new flatpak runtime each time I want to add a printf somewhere. This makes it difficult to make any progress.

[Michael Catanzaro]

I see high CPU usage from p11-kit-remote when loading pages affected by this performance issue. Notably, p11-kit-remote isn't going to be used except when running under flatpak, so that lines up nicely with my findings above. Needs further investigation, though; could be a red herring.

[Jeff Fortin]

While Michael only sees this with the flatpaked version, I do see this with the regular version from Fedora's RPMs, with the slow, sometimes multi-minutes or infinite loading. Here are additional bloated news websites where loading individual articles (not just the front page) can trigger the issue:

* https://theonion.com
* https://deadspin.com
* https://jalopnik.com
* https://theroot.com
* https://thetakeout.com
* https://kotaku.com
* … etc. (they are all part of the same media ownership network)

It can be a bit unpredictable, but it seems to much more likely to happen if you open multiple of those articles in parallel, it tends to get stuck.

Here is a video demonstrating the issue: https://youtu.be/bfX_5xGaC8c

Sometimes they just sit around with the progressbar at a portion of the addressbar's length, without even displaying the contents (i.e. blank page), sometimes they load but it takes 2-5+ minutes before they start painting something, and sometimes they load and paint but stay stuck (as shown in the video after the 1 minute mark). Oftentimes, stopping a loading tab and trying to refresh does not fix it and it needs to be closed and reopened (if I recall past experiences correctly).

In comparison, Firefox loads them in less than a tenth of a second (even without uBlock Origin; with uBO, it becomes something like 1/20th of a second).

Paths for investigation:
* It might have something to do with p11-kit-remote, and/or;
* It might have to be something about "too many network requests at once"

[Michael Catanzaro]

The network process is spending an excessive amount of time calling gnutls_x509_trust_list_add_system_trust(). This is supposed to be instantaneous because it is not an async operation, but I suspect it's blocking the network process. It calls gnutls_x509_trust_list_add_trust_file(), which calls gnutls_pkcs11_obj_list_import_url3(), which calls gnutls_pkcs11_obj_list_import_url4(), which is as much as sysprof is willing to show me. But clearly the PKCS #11 operations are taking too long, no doubt talking to p11-kit-remote.

Meanwhile, p11-kit-remote is busy calling p11_kit_remote_serve_tokens() and p11_kit_remote_serve_profile(). The slow work here is Unix socket I/O. I suspect the network process side is waiting on this.

This has been a very quick 15 minute investigation and I might be wrong about it blocking because I haven't checked, but I suspect that's what's happening. Thank you sysprof and thank you frame pointers. I believe this is the first time I have successfully profiled anything ever.

One more thing. Although GnuTLS and p11-kit seem to be mostly to blame here, another problem is we should only need to create the default trust list once per network process. That is, if it's going to be slow, it should only be slow once. I was profiling a network process that had been running for a long time, so this should not have showed up at all; it shouldn't have been creating a new GTlsDatabase in the first place. We'll need to investigate this.

[Michael Catanzaro]

Yes, that's right. Here is Epiphany loading the homepage of cnn.com once:

(process:334): GLib-Net-DEBUG: 08:29:00.549: Initialized trust list for database 0x55731aa77c40 in 256 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:00.830: Initialized trust list for database 0x55731aa77c40 in 137 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:01.331: Initialized trust list for database 0x55731aa77c40 in 213 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:01.739: Initialized trust list for database 0x55731aa77c40 in 198 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:01.949: Initialized trust list for database 0x55731aa77c40 in 209 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:02.156: Initialized trust list for database 0x55731aa77c40 in 206 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:02.368: Initialized trust list for database 0x55731aa77c40 in 211 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:02.580: Initialized trust list for database 0x55731aa77c40 in 211 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:02.875: Initialized trust list for database 0x55731aa77c40 in 206 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:03.022: Initialized trust list for database 0x55731aa77c40 in 147 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:03.141: Initialized trust list for database 0x55731aa77c40 in 118 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:03.271: Initialized trust list for database 0x55731aa77c40 in 129 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:03.423: Initialized trust list for database 0x55731aa77c40 in 152 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:03.634: Initialized trust list for database 0x55731aa77c40 in 209 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:03.842: Initialized trust list for database 0x55731aa77c40 in 207 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:04.049: Initialized trust list for database 0x55731aa77c40 in 206 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:04.258: Initialized trust list for database 0x55731aa77c40 in 208 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:04.463: Initialized trust list for database 0x55731aa77c40 in 204 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:04.669: Initialized trust list for database 0x55731aa77c40 in 204 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:04.806: Initialized trust list for database 0x55731aa77c40 in 136 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:04.942: Initialized trust list for database 0x55731aa77c40 in 135 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:05.073: Initialized trust list for database 0x55731aa77c40 in 130 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:05.207: Initialized trust list for database 0x55731aa77c40 in 133 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:05.343: Initialized trust list for database 0x55731aa77c40 in 121 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:06.738: Initialized trust list for database 0x55731aa77c40 in 224 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:06.971: Initialized trust list for database 0x55731aa77c40 in 216 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:07.319: Initialized trust list for database 0x55731aa77c40 in 219 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:07.597: Initialized trust list for database 0x55731aa77c40 in 215 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:07.814: Initialized trust list for database 0x55731aa77c40 in 213 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:08.023: Initialized trust list for database 0x55731aa77c40 in 209 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:08.441: Initialized trust list for database 0x55731aa77c40 in 253 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:08.643: Initialized trust list for database 0x55731aa77c40 in 157 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:08.876: Initialized trust list for database 0x55731aa77c40 in 233 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:09.185: Initialized trust list for database 0x55731aa77c40 in 221 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:09.466: Initialized trust list for database 0x55731aa77c40 in 232 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:09.677: Initialized trust list for database 0x55731aa77c40 in 210 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:09.988: Initialized trust list for database 0x55731aa77c40 in 195 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:10.158: Initialized trust list for database 0x55731aa77c40 in 146 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:10.291: Initialized trust list for database 0x55731aa77c40 in 132 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:10.502: Initialized trust list for database 0x55731aa77c40 in 117 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:10.635: Initialized trust list for database 0x55731aa77c40 in 132 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:10.788: Initialized trust list for database 0x55731aa77c40 in 152 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:11.003: Initialized trust list for database 0x55731aa77c40 in 214 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:11.203: Initialized trust list for database 0x55731aa77c40 in 199 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:11.371: Initialized trust list for database 0x55731aa77c40 in 167 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:11.601: Initialized trust list for database 0x55731aa77c40 in 144 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:11.802: Initialized trust list for database 0x55731aa77c40 in 201 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:12.130: Initialized trust list for database 0x55731aa77c40 in 203 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:12.419: Initialized trust list for database 0x55731aa77c40 in 248 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:12.694: Initialized trust list for database 0x55731aa77c40 in 207 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:12.869: Initialized trust list for database 0x55731aa77c40 in 174 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:13.053: Initialized trust list for database 0x55731aa77c40 in 168 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:13.303: Initialized trust list for database 0x55731aa77c40 in 188 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:13.501: Initialized trust list for database 0x55731aa77c40 in 179 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:13.710: Initialized trust list for database 0x55731aa77c40 in 208 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:13.922: Initialized trust list for database 0x55731aa77c40 in 211 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:14.135: Initialized trust list for database 0x55731aa77c40 in 212 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:14.338: Initialized trust list for database 0x55731aa77c40 in 148 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:14.663: Initialized trust list for database 0x55731aa77c40 in 205 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:14.880: Initialized trust list for database 0x55731aa77c40 in 215 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:15.243: Initialized trust list for database 0x55731aa77c40 in 202 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:15.435: Initialized trust list for database 0x55731aa77c40 in 190 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:15.589: Initialized trust list for database 0x55731aa77c40 in 137 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:15.720: Initialized trust list for database 0x55731aa77c40 in 130 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:15.999: Initialized trust list for database 0x55731aa77c40 in 159 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:16.166: Initialized trust list for database 0x55731aa77c40 in 166 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:16.361: Initialized trust list for database 0x55731aa77c40 in 179 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:16.606: Initialized trust list for database 0x55731aa77c40 in 240 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:16.994: Initialized trust list for database 0x55731aa77c40 in 212 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:17.241: Initialized trust list for database 0x55731aa77c40 in 244 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:17.510: Initialized trust list for database 0x55731aa77c40 in 247 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:17.853: Initialized trust list for database 0x55731aa77c40 in 216 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:18.077: Initialized trust list for database 0x55731aa77c40 in 221 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:18.292: Initialized trust list for database 0x55731aa77c40 in 215 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:18.624: Initialized trust list for database 0x55731aa77c40 in 219 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:18.901: Initialized trust list for database 0x55731aa77c40 in 204 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:19.114: Initialized trust list for database 0x55731aa77c40 in 196 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:19.330: Initialized trust list for database 0x55731aa77c40 in 192 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:19.633: Initialized trust list for database 0x55731aa77c40 in 202 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:19.841: Initialized trust list for database 0x55731aa77c40 in 206 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:20.071: Initialized trust list for database 0x55731aa77c40 in 229 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:20.310: Initialized trust list for database 0x55731aa77c40 in 238 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:20.539: Initialized trust list for database 0x55731aa77c40 in 208 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:20.878: Initialized trust list for database 0x55731aa77c40 in 212 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:21.126: Initialized trust list for database 0x55731aa77c40 in 156 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:21.335: Initialized trust list for database 0x55731aa77c40 in 208 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:21.712: Initialized trust list for database 0x55731aa77c40 in 260 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:21.844: Initialized trust list for database 0x55731aa77c40 in 131 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:21.993: Initialized trust list for database 0x55731aa77c40 in 148 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.125: Initialized trust list for database 0x55731aa77c40 in 132 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.251: Initialized trust list for database 0x55731aa77c40 in 125 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.374: Initialized trust list for database 0x55731aa77c40 in 123 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.509: Initialized trust list for database 0x55731aa77c40 in 134 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.638: Initialized trust list for database 0x55731aa77c40 in 128 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.760: Initialized trust list for database 0x55731aa77c40 in 121 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:22.937: Initialized trust list for database 0x55731aa77c40 in 142 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.083: Initialized trust list for database 0x55731aa77c40 in 131 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.252: Initialized trust list for database 0x55731aa77c40 in 145 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.388: Initialized trust list for database 0x55731aa77c40 in 134 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.518: Initialized trust list for database 0x55731aa77c40 in 130 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.658: Initialized trust list for database 0x55731aa77c40 in 140 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.797: Initialized trust list for database 0x55731aa77c40 in 139 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:23.932: Initialized trust list for database 0x55731aa77c40 in 133 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:24.059: Initialized trust list for database 0x55731aa77c40 in 126 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:24.188: Initialized trust list for database 0x55731aa77c40 in 128 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:24.618: Initialized trust list for database 0x55731aa77c40 in 159 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:24.885: Initialized trust list for database 0x55731aa77c40 in 165 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:25.012: Initialized trust list for database 0x55731aa77c40 in 125 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:25.162: Initialized trust list for database 0x55731aa77c40 in 134 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:25.285: Initialized trust list for database 0x55731aa77c40 in 122 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:25.419: Initialized trust list for database 0x55731aa77c40 in 133 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:25.667: Initialized trust list for database 0x55731aa77c40 in 159 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:25.896: Initialized trust list for database 0x55731aa77c40 in 188 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:26.116: Initialized trust list for database 0x55731aa77c40 in 196 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:26.351: Initialized trust list for database 0x55731aa77c40 in 209 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:26.665: Initialized trust list for database 0x55731aa77c40 in 257 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:26.833: Initialized trust list for database 0x55731aa77c40 in 145 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:26.964: Initialized trust list for database 0x55731aa77c40 in 129 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:27.252: Initialized trust list for database 0x55731aa77c40 in 194 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:27.467: Initialized trust list for database 0x55731aa77c40 in 213 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:27.677: Initialized trust list for database 0x55731aa77c40 in 210 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:27.946: Initialized trust list for database 0x55731aa77c40 in 160 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:28.173: Initialized trust list for database 0x55731aa77c40 in 203 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:28.333: Initialized trust list for database 0x55731aa77c40 in 159 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:28.478: Initialized trust list for database 0x55731aa77c40 in 144 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:28.646: Initialized trust list for database 0x55731aa77c40 in 167 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:28.784: Initialized trust list for database 0x55731aa77c40 in 138 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:28.930: Initialized trust list for database 0x55731aa77c40 in 145 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:29.089: Initialized trust list for database 0x55731aa77c40 in 158 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:29.240: Initialized trust list for database 0x55731aa77c40 in 151 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:29.409: Initialized trust list for database 0x55731aa77c40 in 168 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:29.818: Initialized trust list for database 0x55731aa77c40 in 155 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:29.967: Initialized trust list for database 0x55731aa77c40 in 148 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:30.175: Initialized trust list for database 0x55731aa77c40 in 207 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:30.510: Initialized trust list for database 0x55731aa77c40 in 256 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:30.780: Initialized trust list for database 0x55731aa77c40 in 192 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:30.912: Initialized trust list for database 0x55731aa77c40 in 131 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:31.248: Initialized trust list for database 0x55731aa77c40 in 189 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:31.478: Initialized trust list for database 0x55731aa77c40 in 197 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:31.641: Initialized trust list for database 0x55731aa77c40 in 162 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:31.786: Initialized trust list for database 0x55731aa77c40 in 143 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:32.145: Initialized trust list for database 0x55731aa77c40 in 235 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:32.373: Initialized trust list for database 0x55731aa77c40 in 227 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:32.606: Initialized trust list for database 0x55731aa77c40 in 231 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:32.835: Initialized trust list for database 0x55731aa77c40 in 229 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:33.051: Initialized trust list for database 0x55731aa77c40 in 215 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:33.455: Initialized trust list for database 0x55731aa77c40 in 234 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:33.688: Initialized trust list for database 0x55731aa77c40 in 231 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:33.903: Initialized trust list for database 0x55731aa77c40 in 215 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:34.102: Initialized trust list for database 0x55731aa77c40 in 197 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:34.376: Initialized trust list for database 0x55731aa77c40 in 240 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:34.876: Initialized trust list for database 0x55731aa77c40 in 222 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:35.169: Initialized trust list for database 0x55731aa77c40 in 171 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:35.359: Initialized trust list for database 0x55731aa77c40 in 189 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:35.753: Initialized trust list for database 0x55731aa77c40 in 154 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:37.141: Initialized trust list for database 0x55731aa77c40 in 190 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:37.584: Initialized trust list for database 0x55731aa77c40 in 214 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:38.500: Initialized trust list for database 0x55731aa77c40 in 214 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:38.727: Initialized trust list for database 0x55731aa77c40 in 226 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:38.950: Initialized trust list for database 0x55731aa77c40 in 221 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:39.242: Initialized trust list for database 0x55731aa77c40 in 166 milliseconds
(process:334): GLib-Net-DEBUG: 08:29:39.394: Initialized trust list for database 0x55731aa77c40 in 151 milliseconds
[📦 org.gnome.Epiphany.Devel ~]$ (process:334): GLib-Net-DEBUG: 08:29:39.599: Initialized trust list for database 0x55731aa77c40 in 204 milliseconds

So we load the system trust store 165 times to display the page. Outside flatpak, it's only slow the first time and all subsequent times are cached and complete in 1-3 milliseconds. But under flatpak, every time is very slow as it waits for p11-kit-server. I will report a GnuTLS bug.

[Michael Catanzaro]

Also, this is blocking, so while it's happening the network process cannot do anything else: no other requests for this or any other web process will be processed. That's why WebKit slows to a crawl when loading more than one web page at the same time.

[Michael Catanzaro]

Reported https://gitlab.com/gnutls/gnutls/-/issues/1528 for the GnuTLS performance problem.

I also came up with a scheme to reduce the amount of trust list initialization and will create a merge request shortly. This should work around the problem such that it only occurs once per network process, so it won't be a big deal anymore.

I'm tempted to close this as MOVED because the issue will be fixed below the WebKit level. However:

(In reply to Jeff Fortin from comment #0)
> Created attachment 464747 [details]
> sysprof output
> 
> With Epiphany 44 "technology preview" flatpak (from GNOME Nightly) on a
> ThinkPad X220T (Intel Sandybridge graphics) in a Xorg/X11 GNOME session on
> Fedora 37, the following is noticeably slow:

Although you originally reported this bug against flatpak Epiphany, you've recently been complaining about it happening outside flatpak too. The issue I've resolved is definitely specific to flatpak. I think I've made things 95% faster for flatpak users, but it won't do anything to help you outside flatpak. So, I guess I'll leave this bug open for further analysis of the non-flatpak slowness. I'm not seeing it though; WebKit networking is slower than other browsers for me, but not by orders of magnitude.

[Michael Catanzaro]

(In reply to Michael Catanzaro from comment #22)
> I also came up with a scheme to reduce the amount of trust list
> initialization and will create a merge request shortly. This should work
> around the problem such that it only occurs once per network process, so it
> won't be a big deal anymore.

https://gitlab.gnome.org/GNOME/glib-networking/-/merge_requests/249

[Michael Catanzaro]

(In reply to Michael Catanzaro from comment #14)
> Try one:
> Michael's JHBuild: 8.83s
> Epiphany Tech Preview: 35.50s
> Firefox: 2.90s
> 
> Try two:
> Michael's JHBuild: 7.08s
> Epiphany Tech Preview: 31.33s
> Firefox: 1.98s

My change from glib-networking!249 has now landed in Tech Preview. I tested loading cnn.com twice in Tech Preview. The first time took 8 seconds, and the second time took 7 seconds. We are still about 4x slower than Firefox, but that's much more reasonable than 15x slower.

I also tested https://www.theglobeandmail.com/ and found it consistently takes about 4 seconds to load.

(In reply to Jeff Fortin from comment #18)
> While Michael only sees this with the flatpaked version, I do see this with
> the regular version from Fedora's RPMs, with the slow, sometimes
> multi-minutes or infinite loading. Here are additional bloated news websites
> where loading individual articles (not just the front page) can trigger the
> issue:
> 
> * https://theonion.com
> * https://deadspin.com
> * https://jalopnik.com
> * https://theroot.com
> * https://thetakeout.com
> * https://kotaku.com
> * … etc. (they are all part of the same media ownership network)

Checking the first two, they all look like the same underlying website. I tested https://theonion.com and found it takes about 7 seconds to load. So from my perspective, this all these issues seem to be fixed now. However, we unfortunately know that it's not actually fixed for Jeff, because Jeff is now testing without flatpak, and glib-networking!249 will make no difference for that can.

[Michael Catanzaro]

(In reply to Michael Catanzaro from comment #24)
> and glib-networking!249 will make no difference for that can.

I meant "for that case."

[Michael Catanzaro]

Closing as MOVED for "moved to glib-networking issue tracker."

For the problem that occurs outside flaptak, please report a new bug.