1492228 - Many times I can't load the pages of 20minutos.es in new tabs

Status: NEW

(Core :: DOM: Navigation, defect, P2)

Description

[Eduardo Medina]

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

Steps to reproduce:

Hi, many times, when I try to load a news from 20minutos.es in a new tab in Firefox (since many versions ago) the webpage doesn't load, I have to refresh it to get the content.

I see that on Windows the bug is harder to reproduce, but I could do it. I see the issue is in the Linux version too.

My host computer:
-Ubuntu 18.04.1
-CPU: AMD Ryzen 7 1700.
-RAM: 32GB 3.200 from Corsair.
-GPU: AMD RX 580 with Open Source stack.
-The app, took from official Ubuntu's repositories, are installed in a M.2 SSD and the user config in the mechanical hard disk.

Windows 10 VirtualBox guest:
-RAM assigned: 8GB.
-CPU assigned: 2.
-The virtual machine is located in the M.2 SSD.


Actual results:

Sometimes the tab keeps trying to load the webpage of a news from 20minutos.es unsuccessfully when it's opened in a new tab.

-Bug in Ubuntu: https://drive.google.com/file/d/1TwRipMv73jdrkubN7I3WuRkHvYjlihi2/view?usp=sharing
-Bug in Windows 10: https://drive.google.com/file/d/1kgKm9nfzUP6H3Z4_ffZVSWqCKkr45bSZ/view?usp=sharing


Expected results:

I hope a clean experience with the webpage correctly loaded.

Comment 1

[Matthias Versen [:Matti]]

I can confirm the reported bug with Firefox 62+63 on Windows 10 and Firefox 62+trunk on Linux.

STR:
1) open https://https://www.20minutos.es/
2) open many links to different articles on that page in a new tab with a mouse middle click and as fast (!) as you can
3) some tabs will never finish loading

It was much easier to reproduce on my slower Ubuntu Box over vnc than on my fast Windows system.
I could not reproduce this with chromium on windows+linux.

Moving to networking as first guess.

Comment 2

[Honza Bambas (:mayhemer)]

It's pretty much questionable if this is actually a necko bug.  

Matti, thanks for trying to reproduce this.  Can you please turn on logging using command line args or env vars according [1][2] and retry?  This could well be a chrome/UI/docnav problem.

[1] https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging#Start_logging_using_command_line_arguments
[2] https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging#Logging_HTTP_activity_by_manually_setting_environment_variables

Comment 3

[Matthias Versen [:Matti]]

This is quite unfunny !

It seems that with logging enabled this is much harder to reproduce.  
I had more than one tab fail to load in nearly every try without enabled logging. After I enabled logging every tab finished loading in more than 15 tries and even when I finally had a failed tab it was only one.

Note to the log: 
I waited a longer time to let the tab finish loading and after that I did a reload on the tab to compare the page and there was a good part missing from the content that didn't load.

https://mversen.de/temp/20minutos.zip

Comment 4

[Honza Bambas (:mayhemer)]

Thanks for trying, yes, this can happen.  But it could also indicate it's something in the net core that is the cause.

Just in case you find time again, can you try only with:
MOZ_LOG=timestamp,nsHttp:5,cache2:5

and if still irreproducible then only with:
MOZ_LOG=timestamp,nsHttp:5

I'll try to look at the log, but not sure I will be able to see something.  It would also be useful to at least say which page load (which top level url) has failed.

Comment 5

[Matthias Versen [:Matti]]

It was much easier to reproduce the loading issue without the SocketTransport and Resolver logging.

I included the top level URL in a seprate txt file.
http://mversen.de/temp/http.zip (3 Tabs failed to laod completly) )
https://mversen.de/temp/http+cache.zip (1 Tab failed to load completly)

Comment 6

[Honza Bambas (:mayhemer)]

Thanks Matti!  

I only looked at the 3 tabs failed log.

So far I can confirm this is not a networking issue, as all http channels (HttpChannelChild and nsHttpChannel) that have been opened have also finished loading and notify their listeners up until OnStopRequest, which also means to remove them from their respective load groups (only reason for the indicator to spin when not).

There are few channel that are only created, but never opened (never added to load groups), some of those are for the pages failing to load, but not for all of them (I can only see the first URI you list as failed, then few channel in this weird state for different pages you don't list as failed).  Hard to say if these are related to the problem or not, likely not.  These channel are leaked, a significant number of others as well, but that may not necessarily be a bug or the cause of this bug.

I will ask you for one more attempt if you find time with following modules:

timestamp,nsHttp:5,LoadGroup:5

Hopefully that will tell us something.

Comment 7

[Matthias Versen [:Matti]]

http://mversen.de/temp/http+loadgroup.zip
I have included a screenshot from the tab that only loaded a little bit of content.

Comment 8

[Honza Bambas (:mayhemer)]

The load group for https://www.20minutos.es/noticia/3445087/0/entrevista-malu-oxigeno-necesito-que-me-abracen/ is added an on-load-blocker that is hanging around for ever.  I can see it being removed when you cancel the load at the end of the log.

for the log exploration, go to : https://www.janbambas.cz/moz/logan/?https%3A//www.janbambas.cz/moz/logs/1492228-log.txt.child-3#%7B%22show%22%3A%5B%7B%22name%22%3A%22nsLoadGroup%22%2C%22on%22%3A1%2C%22clr%22%3A%22%23ffffb3%22%7D%2C%7B%22name%22%3A%22unknown%20request%22%2C%22on%22%3A1%2C%22clr%22%3A%22%23bebada%22%7D%5D%7D

Added at:
2018-09-25 00:31:33.925156 UTC - [Child 26440: Main Thread]: D/LoadGroup LOADGROUP [0x7fd17ae80f20]: Adding request 0x7fd163083180 about:document-onload-blocker (count=1).

Removed at cancellation at the bottom of the log (you have to scroll and scroll..):
2018-09-25 00:36:08.983083 UTC - [Child 26440: Main Thread]: D/LoadGroup LOADGROUP [0x7fd17ae80f20]: Canceling request 0x7fd163083180 about:document-onload-blocker.
2018-09-25 00:36:08.983094 UTC - [Child 26440: Main Thread]: D/LoadGroup LOADGROUP [0x7fd17ae80f20]: Removing request 0x7fd163083180 about:document-onload-blocker status 804b0002 (count=0).

Comment 9

[Andrew Overholt [:overholt]]

(In reply to Honza Bambas (:mayhemer) from comment #8)
> The load group for
> https://www.20minutos.es/noticia/3445087/0/entrevista-malu-oxigeno-necesito-
> que-me-abracen/ is added an on-load-blocker that is hanging around for ever.
> I can see it being removed when you cancel the load at the end of the log.

Andreas, please take a look here and see what's up.

Comment 10

[Andreas Farre [:farre]]

I really struggle reproducing this, but with regard to the on load blocker; the purpose of that is to not fire onload too soon, and the fact that we apparently don't finish loading would explain why it's dangling.

Matthias, could you perhaps try a couple of things out for me?

First, try setting dom.timeout.enable_budget_timer_throttling to false in about:config (and probably restart the browser) and see if that helps?

If it's still there, you could try setting dom.timeout.throttling_delay to -1 and try again.

Comment 11

[Matthias Versen [:Matti]]

It looks like both settings didn't fix the bug :-(

For your info: I do my test on a older Intel NUC with a slow Intel i3 and Ubuntu 18.04.1