1883710 - Buffering on youtube (networking preset log attached)

Status: RESOLVED WORKSFORME

(Core :: Networking, defect)

Description

[Mayank Bansal]

I am seeing buffering on youtube today with Nightly only. I captured a log with networking preset:

https://share.firefox.dev/3TnUI3e

Comment 1

[Mayank Bansal]

Attachment: about:support

Comment 2

[Mayank Bansal]

And another that i started capturing about a second after clicking on a video and it buffering : https://share.firefox.dev/3TnbBes

Comment 3

[Mayank Bansal]

I cant repro anymore, so it must be something with my pathetic ISP. But curious why that affected Firefox only (or why it affected Firefox more).
I am keeping the ni for a few days in case there is anything to check here. If there is no response, I will close the bug :) .

Comment 4

[Valentin Gosu [:valentin] (he/him) {{ AFK in July }}]

https://share.firefox.dev/3wHYNGK
It seems Load 9242: https://rr2---sn-4g5lznez.googlevideo.com/videoplayback?expire=1709678368&ei=wErnZcntMZO09fwPw5SBwAg... doesn't load
Though the profile appears to show it being redirected to a different channel that does load

9242 is [this=244e2f27000]
LogMessages — (nsHttp) nsHttpChannel::SetupReplacementChannel [this=244e2f27000 newChannel=244e2f33640 preserveMethod=1]
LogMessages — (nsHttp) HttpBaseChannel::SetupReplacementChannel [this=244e2f33600 newChannel=244e2f20440 preserveMethod=1]
LogMessages — (nsHttp) HttpChannelParent::OnDataAvailable [this=244e6e52a80 aRequest=244e2f20440 offset=0 count=789]

The channel doesn't appear to do anything after that. I can't quite figure out why.
Kershaw, do you have time to also take a look?

Comment 5

[Kershaw Chang [:kershaw]]

This is what I found from the log.
The load 9242 is redirected to channel 244e2f20400, so the actual load is done with this request.

2024-03-05 16:53:28.549 UTC - [Parent Process 5284 GeckoMain] D/nsHttp nsHttpChannel::AsyncOpen [this=244e2f27000]
2024-03-05 16:53:28.554 UTC - [Parent Process 5284 GeckoMain] D/nsHttp nsHttpChannel::SetupReplacementChannel [this=244e2f27000 newChannel=244e2f33640 preserveMethod=1]
2024-03-05 16:53:28.556 UTC - [Parent Process 5284 GeckoMain] D/nsHttp HttpBaseChannel::SetupReplacementChannel [this=244e2f33600 newChannel=244e2f20440 preserveMethod=1]

The channel 244e2f20400 was opened at 2024-03-05 16:53:28.556, but OnStartRequest was called after 3s.

2024-03-05 16:53:28.556 UTC - [Parent Process 5284 GeckoMain] D/nsHttp nsHttpChannel::AsyncOpen [this=244e2f20400]
2024-03-05 16:53:31.748 UTC - [Parent Process 5284 GeckoMain] D/nsHttp nsHttpChannel::OnStartRequest [this=244e2f20400 request=244e8b8b4a0 status=0]

Looking into more details, the transaction 244e172f800 was created for channel 244e2f20400. The log below shows that we send the request header out at 2024-03-05 16:53:28.561 and got the response back at 2024-03-05 16:53:31.747.
Unfortunately, the log doesn't show why the response is delayed.

2024-03-05 16:53:28.559 UTC - [Parent Process 5284 GeckoMain] D/nsHttp Creating nsHttpTransaction @244e172f800
2024-03-05 16:53:28.559 UTC - [Parent Process 5284 GeckoMain] D/nsHttp nsHttpChannel 244e2f20400 created nsHttpTransaction 244e172f810

2024-03-05 16:53:28.560 UTC - [Parent Process 5284 Socket Thread] D/nsHttp Http3Session::AddStream 244e2e0b400 atrans=244e172f800.

2024-03-05 16:53:28.561 UTC - [Parent Process 5284 Socket Thread] D/nsHttp Http3Session::ProcessOutput sending packet with 1269 bytes to 2a00:1450:4001:11::7 port=443 [this=244e2e0b400].

2024-03-05 16:53:31.747 UTC - [Parent Process 5284 Socket Thread] D/nsHttp Http3Session::ProcessEvents [this=244e2e0b400]
2024-03-05 16:53:31.747 UTC - [Parent Process 5284 Socket Thread] D/nsHttp Http3Session::ProcessInput received=1337
2024-03-05 16:53:31.747 UTC - [Parent Process 5284 Socket Thread] D/nsHttp Http3Session::ProcessInput writer=244e76b9600 [this=244e2e0b400 state=2]

Comment 6

[Mayank Bansal]

Valentin, should this bug be closed as INACTIVE or WORKSFORME now?

Comment 7

[Valentin Gosu [:valentin] (he/him) {{ AFK in July }}]

WORKSFORME or INCOMPLETE.
If it happens again, please do capture another profile. Thanks for everything.