Closed Bug 1869403 Opened 2 years ago Closed 5 months ago

incredibly slow page load with "use system proxy" enabled without a system proxy

Categories

(Core :: Networking: Proxy, defect, P1)

Firefox 120
Desktop
Windows
defect
Points:
2

Tracking

()

VERIFIED FIXED
150 Branch
Tracking Status
firefox150 --- verified

People

(Reporter: hoernchen, Assigned: kershaw, NeedInfo)

References

Details

(Keywords: perf, Whiteboard: [necko-triaged][necko-priority-queue])

Attachments

(5 files)

Attached image comaprison.png

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:120.0) Gecko/20100101 Firefox/120.0

Steps to reproduce:

I am not aware of any recently changed settings, but suddenly pages literally took 20+ seconds to load. I've tracked this down to the "use system proxy" setting, i'm running w11 2h23, and there is no system proxy configured.
Setting this to "no proxy" fixes the performance issues. This happens with new, pristine ff profiles (which default to "use system proxy"), and with the previous 120.0.0 release, too.

See attached pictures, only difference is "no proxy" vs "use system proxy", 1.37 minutes (!) compared to 2.5 seconds.
It looks like the connections are getting serialized instead of happening in parallel?

Expected results:

I expected that a fresh profile which defaults to "use system proxy" setting would work as expected...

Attached image w11noproxy.png

literally no proxy configured...

Component: Untriaged → Networking: HTTP
Keywords: perf
Product: Firefox → Core
Severity: -- → S3
Priority: -- → P2
Whiteboard: [necko-triaged][necko-priority-review]

Moving bug to Core/Networking: Proxy.

Component: Networking: HTTP → Networking: Proxy

Hi Reporter,

Could you try to get a http log when system proxy is used?
Please try to create a log file and send the file to necko@mozilla.com.

Thanks.

Flags: needinfo?(ericwild724)

(mail sent)

Flags: needinfo?(ericwild724)

NI myself to do a reproduction test

Flags: needinfo?(rjesup)

For some reason, the proxy resolution becomes really slow. As the log below shows, it took 4 seconds.

2024-02-26 12:02:07.372000 UTC - [Parent 28936: Main Thread]: D/nsHttp nsHttpChannel::ResolveProxy [this=1b7d063fc00]
2024-02-26 12:02:11.330000 UTC - [Parent 28936: Main Thread]: D/nsHttp nsHttpChannel::OnProxyAvailable [this=1b7d063fc00 pi=0 status=0 mStatus=0]
Whiteboard: [necko-triaged][necko-priority-review] → [necko-triaged][necko-priority-next]

Out of curiosity, is there a web-server or any application that listens to HTTP requests on your system?
That might be seen as a proxy server, resulting in the request being forward to it, and only after it times out, the request is sent directly.

Nope, nothing as far as I can tell, I checked netstat -anbo and disabled Steam, the AMD driver services, and everything else. Only dnscache and rpc services are left, and those can't be disabled. It is not realated to specific network adapter settings either, I gave a usb ethernet dongle a try, same issue. It's apparently not network related in general, my other windows devices using the same network do not have this problem. The issue still exists with the current FF version, and it survived a repair "in place" upgrade of windows.
It's a bit unfortunate that I can't "just build Firefox real quick" to debug this myself...

Is this still happening?

If so, do you have some antivirus installed (other than MS Defender)?

Flags: needinfo?(rjesup) → needinfo?(ericwild724)
Whiteboard: [necko-triaged][necko-priority-next] → [necko-triaged][necko-priority-review]

I just gave a new profile a try with FF 139.0.1 (64-bit), yes, it is still happening, no, I have never used anything else/more than the built in windows defender.

Flags: needinfo?(ericwild724)

Let me check this.

Flags: needinfo?(smayya)
Attached file ProxyResolutionLogs

Looks like the initial proxy resolution speed is fine. However, as we squeze lot of requests the resolution time increases upto 7 seconds!

2024-02-26 12:02:02.670000 UTC - [Parent 28936: Main Thread]: D/nsHttp nsHttpChannel::ResolveProxy [this=1b7e33a0400]
....
158 2024-02-26 12:02:09.720000 UTC - [Parent 28936: Main Thread]: D/nsHttp nsHttpChannel::OnProxyAvailable [this=1b7e33a0400 pi=0 status=0 mStatus=0]

I am not sure if this is due to the system proxy or anything that we do. I suspect the former, however we would need some profiler logs for this to confirm. I will try to reproduce this on the windows machine as well.

Dear reporter,
Could you please capture the profiler output related to the issue and non-issue case. It would be useful incase I cant reproduce this.

Flags: needinfo?(smayya) → needinfo?(ericwild724)
Flags: needinfo?(valentin.gosu)

Slow profile (sytem proxy): https://share.firefox.dev/45lfvdQ
Fast profile (no proxy): https://share.firefox.dev/4oGmiWZ

Turns out loading the profiler getting started page is another great example ;)

Flags: needinfo?(ericwild724)

This sounds a lot like bug 1937367.

Could you check if setting network.proxy.enable_wpad_over_dhcp to false in about:config fixes the issue?

Flags: needinfo?(valentin.gosu) → needinfo?(ericwild724)

Nope, does not change anything: https://share.firefox.dev/3HqOPPL - arstechnica.com with enable_wpad_over_dhcp=false, a fairly impressive 40s delay until anything happens.
Another observation: the slow loading version does not terminate properly, FF keeps running instead of quitting for ~30s.

Flags: needinfo?(ericwild724)

Can you try this with chrome?

Chrome only supports system proxys (no manual config). They may only check for proxies on startup or somehow hook into notifications if the system settings for proxies change.

Thanks

Flags: needinfo?(ericwild724)

Oh I already am using Chrome at times, absolutely no issues, neither right now nor during the past few years. Microsoft Chrome (Edge) is working fine, too.

Flags: needinfo?(ericwild724)

My thought is that this can be resolved or at least seriously mitigated by rate-limiting ResolveProxy requests. We don't need to check it 100 times a second or even every second, if we've previously gotten a failure to get proxy info.
We should rate-limit requests to every 5, 10, 30, 60? seconds
Valentin - how common would we fail to have an mProxyInfo? https://searchfox.org/firefox-main/source/netwerk/protocol/http/nsHttpChannel.cpp#7150-7158 implies it's very common

Points: --- → 2
Rank: 3
Flags: needinfo?(valentin.gosu)
Whiteboard: [necko-triaged][necko-priority-review] → [necko-triaged][necko-priority-next]

The comment goes back at least to the point where we made proxy resolution async, 13 years ago. So I have to assume we're doing this A Lot. Or the comment is (mostly) wrong

Flags: needinfo?(rjesup)

So, in bug 1937367 we saw the issue was that after resume from suspend the call to DhcpRequestParams would hang.
As mentioned in comment 16, that doesn't seem to be the issue.
My guess is that the calls to ReadInternetOption nsWindowsSystemProxySettings::GetProxyForURI are slow, for "windows reasons". I assume that's why it's blocking shutdown too.

But Randell is probably right. As far as I can tell there's no reason to keep calling ReadInternetOption with the same parameters.
I think it should be possible to register a listener for WM_SETTINGCHANGE here when lparam equals "Software\Microsoft\Windows\CurrentVersion\Internet Settings" we should InternetSetOption(NULL, INTERNET_OPTION_REFRESH, NULL, 0); and refresh the proxy info.

Rank: 3 → 1
Flags: needinfo?(valentin.gosu)
See Also: → 1937367
Priority: P2 → P1
Whiteboard: [necko-triaged][necko-priority-next] → [necko-triaged][necko-priority-queue]
Assignee: nobody → kershaw
Pushed by kjang@mozilla.com: https://github.com/mozilla-firefox/firefox/commit/a38cb07e3c4a https://hg.mozilla.org/integration/autoland/rev/2dbc8d0bcd8e Refactor nsWindowsSystemProxySettings to use WindowsInternetFunctionsWrapper, r=necko-reviewers,jesup https://github.com/mozilla-firefox/firefox/commit/99fc6b53e423 https://hg.mozilla.org/integration/autoland/rev/09ca2ebc7075 Optimize Windows proxy detection by observing network link and registry changes, r=necko-reviewers,jesup
Pushed by smolnar@mozilla.com: https://github.com/mozilla-firefox/firefox/commit/083fa44bd5b5 https://hg.mozilla.org/integration/autoland/rev/7eece62e944f Revert "Bug 1869403 - Optimize Windows proxy detection by observing network link and registry changes, r=necko-reviewers,jesup" for causing leakcheck failures
Flags: needinfo?(kershaw)
Pushed by kjang@mozilla.com: https://github.com/mozilla-firefox/firefox/commit/641dee910f88 https://hg.mozilla.org/integration/autoland/rev/bd58e2c19cf6 Refactor nsWindowsSystemProxySettings to use WindowsInternetFunctionsWrapper, r=necko-reviewers,jesup https://github.com/mozilla-firefox/firefox/commit/fd129a8908de https://hg.mozilla.org/integration/autoland/rev/31608319f0d3 Optimize Windows proxy detection by observing network link and registry changes, r=necko-reviewers,jesup
Status: UNCONFIRMED → RESOLVED
Closed: 5 months ago
Resolution: --- → FIXED
Target Milestone: --- → 150 Branch

Hi Reporter,

Since we recently fixed this issue, could you try downloading Firefox Nightly and see if you can still reproduce it?

Thanks.

Flags: needinfo?(ericwild724)

At least with 150.a1 (2026-02-28) this appears to be fixed, there is no obvious difference between the proxy settings, the network inspector tab timings all look pretty similar with no massive delays. Thanks!

Flags: needinfo?(ericwild724)

Testing completed on Win10 (22H2 ( OS Build 19045.6466) and Win11 (25H2 Build 26200.7840) with Firefox Nightly 150.0a1, test execution details here.

QA Whiteboard: [qa-ver-needed-c150/b149]
Regressions: 2024951

Beta 150 Spot check completed on Windows 10 and Windows 11, results available here.

Status: RESOLVED → VERIFIED
QA Whiteboard: [qa-ver-needed-c150/b149] → [qa-ver-done-c150/b149]
OS: Unspecified → Windows
Hardware: Unspecified → Desktop
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: