1503578 - Ctrl + F5 doesn't load all the resources of the web

Status: RESOLVED WORKSFORME

(Core :: Networking: HTTP, defect, P2)

Description

[fsanchez]

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/69.0.3497.100 Safari/537.36 OPR/56.0.3051.52

Steps to reproduce:

1 - Go to: https://www.topbarcos.com/barcos-alquiler
2 - Press Ctrl + F5


Actual results:

Some resources (CSS, JS) don't load correctly and the page appears in raw html.
In some cases the files won't download completely.

If I delete the cache and I load the page again all works perfectly.
The problem remains only with Ctrl + f5 or Cmd+shift+r in mac.
With Firefox v60 works ok.

Comment 1

[Alice0775 White]

I can also reproduce the issue on Nightly65.0a1 Windows10 x64.

Comment 2

[Alice0775 White]

Regression window:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=b5ebdb085efaf31a4f00159334c2d23679e5fa27&tochange=4a4b97e9087ca8ebed570bbc8591e4515eebee93

Regressed by: 4a4b97e9087c	Kai Engert — Bug 1470914, NSS_3_39_BETA2, r=me

@:kaie
Your patch seems to cause the regression. Could you please look into this?

Comment 3

[J.C. Jones [:jcj] (he/they)]

The actual changeset in that patch is:

https://hg.mozilla.org/projects/nss/log?rev=5bc69334e84f%3ANSS_3_39_BETA2

The possible bugs are Bug 1483128, Bug 1483416, or Bug 1483129.

Franziskus, can you take a look at this?

Comment 4

[Franziskus Kiefer [:franziskus]]

This appears to be the same as issue as bug 1503564 and is unrelated to NSS 3.39.
Session resumption with TLS 1.3 enabled fails but I couldn't figure out yet why that is.

Comment 5

[Franziskus Kiefer [:franziskus]]

Attachment: topbarcos.pcapng

After figuring out bug 1503564 this is different after all.
But it also doesn't seem like a TLS issue. This looks like a necko issue. I attached a pcap from a failed load. The TLS 1.3 handshake finishes without issues but the following H2 session gets closed by Firefox without receiving all data.

Comment 7

[Selena Deckelmann :selenamarie :selena]

Michal -- please have a look.

Comment 8

[Michal Novotny [:michal]]

Attachment: log, pcap and ssl.key

I was able to reproduce the problem and the simplest STR are:

1) Load https://static.topbarcos.com/css/ploneCustom.css?v=1310
2) Do shift-reload

In devtools you can see that almost half of the requests are incomplete. I don't understand why it's reproducible only with shift-reload, but it's definitely not caused by the cache. It can be reproduced even when disk and memory cache are disabled. I can reproduce it only when using HTTP/2 and TLS 1.3. Very strange is that if I disable cache using the checkbox in devtools then exactly the same request is sent but the bug is not reproducible.

Franziskus, AFAICS the server closes the connection for some reason, see packet no. 147 in the attached pcap file. I don't see anything wrong in necko code. Since this bug is reproducible only using TLS 1.3, I guess this is either server side bug or a bug in our TLS implementation. Could you please check that nothing wrong happens in NSS code?

Nick, can you please check the attached log and confirm that I'm reading it correctly and that HTTP/2 is not responsible for the closed connection? Search for:
  nsHttpChannel 0x7f88906f4000
  nsHttpTransaction 0x7f8890a2cc00
  nsSocketInputStream 0x7f8890a2ea90
  Http2Session 0x7f8890a65000

Comment 9

[u408661]

So I have a theory as to why this only happens with shift-reload - there's 0rtt involved here, and the easiest way to get 0rtt is to force a new connection to a server you already have talked to this browsing session (which is exactly what shift-reload does). 0rtt also requires TLS1.3 (which is why this only happens with TLS 1.3). However, I will point out - this bug manifests after 0rtt is successfully completed, so either this is some state (likely at TLS or lower level) getting out of wack and isn't noticed until a few more packets have flown by, or 0rtt isn't required for this bug to happen (it's just a red herring).

Anyway, I don't see any problems on our end in the logs. Here's what I see happening - we start 0rtt http/2, and in the 0rtt data we send the usual stuff - client preamble, settings, priority tree, first request. 0rtt comes back and is accepted, and we get the server preamble  (settings, settings acknowledgement, window update, the usual). All's good. We get the HEADERS for the response, and one DATA frame that's 8192 bytes long. Then things start to go a bit off the rails - we get the frame header for another 8192 byte-long DATA frame, and proceed to read 8174 bytes of it (that's all that PR_Read gives us when we go to get data from the socket). We try to read the final 18 bytes of the frame, and PR_Read gives us nothing, along with a socket in status of NS_ERROR_BASE_STREAM_CLOSED. Once that happens, we tell the h2 session to shut down (because the socket is apparently closed), and discard what data we got on that second frame (since the frame is incomplete).

So, that all jives with either something at a lower layer failing, or a server-side issue.

Comment 10

[Michal Novotny [:michal]]

I can't reproduce the bug if I set security.tls.enable_0rtt_data to false.

Comment 11

[Franziskus Kiefer [:franziskus]]

My suspicion was that 0rtt might have something to do with this. But no 0rtt data is sent (at least in the sessions I've seen).
But I'll investigate again to see if there's any relation. (Leaving the ni? until I figured out what's going on.)

Comment 12

[Franziskus Kiefer [:franziskus]]

I notified the CDN about the issue and will continue to investigate.

Comment 13

[Franziskus Kiefer [:franziskus]]

CDN77 investigated and found the issue in openssl [1]. They also disabled 0-rtt until the issue is fixed.
I can confirm that the issue described here is resolved. Closing the bug now. Please re-open if the issue occurs again (possibly when CDN77 enables 0-rtt again).

[1] https://github.com/openssl/openssl/issues/7757