Closed Bug 1703369 Opened 4 years ago Closed 3 years ago

Firefox 87 broke enterprise redirect for proxy login

Categories

(Core :: Networking, defect)

Firefox 87
defect

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: serge_lalonde, Unassigned)

Details

Attachments

(4 files)

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

Steps to reproduce:

Our corporate settings involve using a proxy setup script that contains one function: FindProxyForURL(). It returns "DIRECT" for no proxy or "PROXY url here:2020" if a login proxy (to log in with out PKI smart card) is required.
I have no problems using my PKI card in Firefox 87 on other sites.
The URL for the proxy is http://proxyconf.XXXXXXX.com/ (the Xs are to preserve corporate confidentiality).
This is using the 64-bit versino of Firefox on Windows 10.
The same sites work with Chrome, Edge, IE and Firefox 86.

Actual results:

Since upgrading to Firefox 87, none of the sites that load using a PROXY fail with "Hmm. We’re having trouble finding that site. Can't connect..."
I have to use Chrome to log in to the sites where this fails. One of which is a site I use every day for work.
I looked at the changes in Firefox 87 and the only one that looks remotely possible is the change to the default HTTP referrer policy.
Is there any way to restore the Firefox 86 functionality?

Expected results:

I should be redirected to the page to log in using my smart card.

You could use https://mozilla.github.io/mozregression/ to prove whether your hunch is correct. Feel free to report the results here in a new comment.

Flags: needinfo?(serge_lalonde)

The Bugbug bot thinks this bug should belong to the 'Core::Networking' component, and is moving the bug to that component. Please revert this change in case you think the bot is wrong.

Component: Untriaged → Networking
Product: Firefox → Core
Attached file mozregression INFO log
I ran mozregression between releases v86 (good) and v88 (bad). In fact, the first time I ran it, I set v87 as the first bad version and all Firefox instances were good. I didn't know what that meant, so I changed the first bad to v88 and god some bad versions as well, which was comforting. Here is the build Info result: app_name: firefox build_date: 2021-03-08 14:49:15.347000 build_file: C:\Users\slalonde\.mozilla\mozregression\persist\48e48673b875-shippable--autoland--target.zip build_type: integration build_url: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BC_97eaQQs-jx2P6kRobPQ/runs/0/artifacts/public%2Fbuild%2Ftarget.zip changeset: 48e48673b875465cf58b570f0c0116ab019cb876 pushlog_url: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=48e48673b875465cf58b570f0c0116ab019cb876&tochange=ae94c83c78f43cb3cdeadab9ff940fafb23918ef repo_name: autoland repo_url: https://hg.mozilla.org/integration/autoland task_id: BC_97eaQQs-jx2P6kRobPQ Here is the INFO log result. It's greater than 1000 lines, so it's added as an attachment.
I ran mozregression between releases v86 (good) and v88 (bad). In fact, the first time I ran it, I set v87 as the first bad version and all Firefox instances were good. I didn't know what that meant, so I changed the first bad to v88 and god some bad versions as well, which was comforting. Here is the build Info result: app_name: firefox build_date: 2021-03-08 14:49:15.347000 build_file: C:\Users\slalonde\.mozilla\mozregression\persist\48e48673b875-shippable--autoland--target.zip build_type: integration build_url: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BC_97eaQQs-jx2P6kRobPQ/runs/0/artifacts/public%2Fbuild%2Ftarget.zip changeset: 48e48673b875465cf58b570f0c0116ab019cb876 pushlog_url: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=48e48673b875465cf58b570f0c0116ab019cb876&tochange=ae94c83c78f43cb3cdeadab9ff940fafb23918ef repo_name: autoland repo_url: https://hg.mozilla.org/integration/autoland task_id: BC_97eaQQs-jx2P6kRobPQ Here is the INFO log result. It's greater than 1000 lines, so it's added as an attachment. Here is the DEBUG log result.

I ran mozregression between releases v86 (good) and v88 (bad). In fact, the first time I ran it, I set v87 as the first bad version and all Firefox instances were good. I didn't know what that meant, so I changed the first bad to v88 and god some bad versions as well, which was comforting.

Here is the build Info result:
app_name: firefox
build_date: 2021-03-08 14:49:15.347000
build_file: C:\Users\slalonde.mozilla\mozregression\persist\48e48673b875-shippable--autoland--target.zip
build_type: integration
build_url: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BC_97eaQQs-jx2P6kRobPQ/runs/0/artifacts/public%2Fbuild%2Ftarget.zip
changeset: 48e48673b875465cf58b570f0c0116ab019cb876
pushlog_url: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=48e48673b875465cf58b570f0c0116ab019cb876&tochange=ae94c83c78f43cb3cdeadab9ff940fafb23918ef
repo_name: autoland
repo_url: https://hg.mozilla.org/integration/autoland
task_id: BC_97eaQQs-jx2P6kRobPQ

Here is the INFO log result. It's greater than 1000 lines, so it's added as an attachment.
Here is the DEBUG log result. It's greater than 1000 lines, so it's added as an attachment.

Flags: needinfo?(serge_lalonde)

Could this be caused by bug 1683761? Assuming the regression range is valid.

Flags: needinfo?(dkeeler)

Seems unlikely - all that patch does it turn on the EV bit for a particular root. If comment 0 is accurate, https isn't even in play here.

Flags: needinfo?(dkeeler)

Is there anything else that I can do to narrow down the problem?

I should be redirected to the page to log in using my smart card.

This sounded like it's related to certificates.

Serge, could you capture some HTTP logs to help us figure out what's going on?
Use this list of logging modules: timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5,cookie:5,proxy:5
It's best to use a new profile to reproduce, as the logs may contain some private info.
Archive the logs and send them via email.

Thanks!

Flags: needinfo?(serge_lalonde)

(In reply to Valentin Gosu [:valentin] (he/him) from comment #9)

I should be redirected to the page to log in using my smart card.

This sounded like it's related to certificates.

Serge, could you capture some HTTP logs to help us figure out what's going on?
Use this list of logging modules: timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5,cookie:5,proxy:5
It's best to use a new profile to reproduce, as the logs may contain some private info.
Archive the logs and send them via email.

Thanks!

I've attached the log file as log.txt-main.12264.moz_log.
I hope that it helps!

Flags: needinfo?(serge_lalonde)

I don't see anything in the logs that may indicate the cause of this, except that the proxy isn't being used.

2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy pac not available, use DIRECT
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters 000001847A83CD40
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters::AsyncProcess 000001847A83CD40 for req 0000018478798F00
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters::ProcessNextFilter 000001847A83CD40 ENTER pi=0000018478798500
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters::Finish 000001847A83CD40 pi=0000018478798500
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy nsProtocolProxyService::PruneProxyInfo ENTER list=0000018478798500
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy All proxies are disabled, so trying all again
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy nsProtocolProxyService::PruneProxyInfo LEAVE list=0000000000000000
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy DoCallback::consumeFiltersResult this=0000018478798F00, pi=0000000000000000, async=0
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy ~AsyncApplyFilters 000001847A83CD40

The PAC script will also log things to the browser console. (Ctrl-Shift-J)
Could you check if it says anything?

(In reply to Valentin Gosu [:valentin] (he/him) from comment #12)

I don't see anything in the logs that may indicate the cause of this, except that the proxy isn't being used.

2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy pac not available, use DIRECT
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters 000001847A83CD40
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters::AsyncProcess 000001847A83CD40 for req 0000018478798F00
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters::ProcessNextFilter 000001847A83CD40 ENTER pi=0000018478798500
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy AsyncApplyFilters::Finish 000001847A83CD40 pi=0000018478798500
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy nsProtocolProxyService::PruneProxyInfo ENTER list=0000018478798500
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy All proxies are disabled, so trying all again
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy nsProtocolProxyService::PruneProxyInfo LEAVE list=0000000000000000
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy DoCallback::consumeFiltersResult this=0000018478798F00, pi=0000000000000000, async=0
2021-04-15 13:45:16.180000 UTC - [Parent 12264: Main Thread]: D/proxy ~AsyncApplyFilters 000001847A83CD40

The PAC script will also log things to the browser console. (Ctrl-Shift-J)
Could you check if it says anything?

Here's the output of the Browser Console with everything on.

GEThttps://scp.siemens.com/

GET
https://scp.siemens.com/
Transferred0 B (0 B size)

Accept
	text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Encoding
	gzip, deflate, br
Accept-Language
	en-US,en;q=0.5
Connection
	keep-alive
Cookie
	s_fid=5B7A7FE1AA759155-2F9D851FB2ABBC8D; ste_vi=vi_fv%3A1607024951346%7Cvi%3Ae9496726bc5dc711926df7c6362817e1; AMCV_EFB35E09512D2A530A490D4D%40AdobeOrg=1099438348%7CMCMID%7C00091699579472537981558797789583965080%7CvVersion%7C2.1.0; ajs_anonymous_id=%22abf4038c-ba53-4e79-95bd-fe50b8fc0caf%22; _fbp=fb.1.1610983871853.723724562; _hjid=f184d1d5-bd6b-4bf0-b040-9eab24bfac6e; VISITOR_ID=753268b969a7213f9ee9563c6fd84dbac7fb866316252432bb7d24ed6f82c8f4; _ga=GA1.2.1164574411.1613744098; s_vi=[CS]v1|3017E439704E5D63-4000080126291438[CE]; OptanonConsent=isIABGlobal=false&datestamp=Tue+Apr+06+2021+16%3A23%3A23+GMT-0400+(Eastern+Daylight+Time)&version=6.5.0&hosts=&consentId=1e2726f0-da37-4f3b-a9fc-2efb5839369a&interactionCount=1&landingPath=NotLandingPage&groups=C0001%3A1%2CC0002%3A0%2CC0003%3A0%2CC0004%3A0&AwaitingReconsent=false; ste_pr=tcs%3Awwiia420000%253C1619700265
Host
	scp.siemens.com
Upgrade-Insecure-Requests
	1
User-Agent
	Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0

sendRemoveListener on closed conduit {bee6eb20-01e0-ebd1-da83-080329fb9a3a}.1099511628084 ConduitsChild.jsm:108
_send resource://gre/modules/ConduitsChild.jsm:108
_send self-hosted:1277
removeListener resource://gre/modules/ExtensionChild.jsm:663
removeListener resource://gre/modules/ExtensionChild.jsm:886
onChanged chrome://extensions/content/child/ext-storage.js:337
removeListener resource://gre/modules/ExtensionCommon.jsm:2522
revoke resource://gre/modules/ExtensionCommon.jsm:2544
close resource://gre/modules/ExtensionCommon.jsm:2549
unload resource://gre/modules/ExtensionCommon.jsm:912
close resource://gre/modules/ExtensionContent.jsm:930
destroyed resource://gre/modules/ExtensionContent.jsm:1008
observe resource://gre/modules/ExtensionContent.jsm:1026
GEThttps://www.google.com/gen_204?atyp=i&bb=1&ei=0V54YIrLNIeua7ykptgK&ct=slh&v=t1&pv=0.6225168164241364&me=11:1618501411471,V,0,0,0,0:521,h,1,1,i:22,h,1,1,o:7684,V,0,0,1694,913:231,e,H&zx=1618501419931
[HTTP/2 204 No Content 137ms]

GET
https://www.google.com/gen_204?atyp=i&bb=1&ei=0V54YIrLNIeua7ykptgK&ct=slh&v=t1&pv=0.6225168164241364&me=11:1618501411471,V,0,0,0,0:521,h,1,1,i:22,h,1,1,o:7684,V,0,0,1694,913:231,e,H&zx=1618501419931
Status204
No Content
VersionHTTP/2
Transferred382 B (0 B size)
Referrer Policyorigin

alt-svc
	h3-29=":443"; ma=2592000,h3-T051=":443"; ma=2592000,h3-Q050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"
content-length
	0
content-type
	text/html; charset=UTF-8
date
	Thu, 15 Apr 2021 15:43:40 GMT
server
	gws
X-Firefox-Spdy
	h2
x-frame-options
	SAMEORIGIN
x-xss-protection
	0
	
Accept
	image/webp,*/*
Accept-Encoding
	gzip, deflate, br
Accept-Language
	en-US,en;q=0.5
Connection
	keep-alive
Cookie
	1P_JAR=2021-03-29-16; NID=213=DkFdrA25AJ3pmyhJhJMPuZshVfqY7ssvqXsLhRiwfVUvYWKgaRjpgmqKrv6iNOJnnQmNERypVinz1X-RK7qioCvGGAHN_Ck1OxuoGLSwYHff5_Gd82F4ehUq5gVAKbXtXxsu4Ke84u76wUIvdteD5Pe78jteMohQO1ngZptXfP8kV8zXsGuB15stL7Eu5RRsKUK6Z2b1uJrZzjSJv5ZdSJSEXDQt5A5R7A18QivobK1D4WyGItBdCA; SID=7gfJmkjSTTDOAFx03WkjOSQ7keTwhaStvaSijh5Uzs01xBKtNGXc0tic-cnlzOkd4jI3-A.; __Secure-3PSID=7gfJmkjSTTDOAFx03WkjOSQ7keTwhaStvaSijh5Uzs01xBKt2ws36IM4rcygWEU0JRhIxw.; HSID=A7EPSM8pFm272ukAX; SSID=Ae8l2qlSRT1O3s7xI; APISID=0f-NHogGKp7f9c-q/AR2SE7Q0VWsuTa-xT; SAPISID=0o5bF0y6K8QiaXZj/AH_Dzi8oVzxJURSKr; __Secure-3PAPISID=0o5bF0y6K8QiaXZj/AH_Dzi8oVzxJURSKr; SIDCC=AJi4QfF6JvyAYqtnuVJrq-adoRXNJk7qdIBsWJi7bzD56GwXMZrUycnfMSGjGgYYUOmKPTB-Ww; __Secure-3PSIDCC=AJi4QfG4oMVfM75VZrEuxcT9dTbr4_QPz58O5mMNZ3337ouPNdBsnq1LSZ5UNKO2T_4xAbVhIko; SEARCH_SAMESITE=CgQIq5IB
Host
	www.google.com
Referer
	https://www.google.com/
TE
	Trailers
User-Agent
	Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0

TypeError: (destructured parameter) is undefined Grammarly-bg.js:2:1311909

Unfortunately I don't see any relevant messages in the console 🙁

Is there anything more I can do with mozregression to narrow down the change that introduced the problem?
Thanks.

The problem with that regression range is that the commits it contains are unlikely to be the cause.
If you could redo the mozregression it would be quite helpful actually - start with a slightly larger range and see if it gives you the same result.
Thanks!

In the mozregression-gui, there's different build types: shippable (the default), opt, pgo, debug.
I can't find any documentation on these.
The mozregression docs only mention nightly and inbound. It seems to me that testing the nightly builds might be a good way to really narrow down the change(s).
If you know how to do that, please let me know.
In the meantime, I'll test the shippable builds again with a larger date range.

I re-ran mozregression using a date range of 2020-01-01 (good) to 2021-04-16 (bad). I got the same result that points to the same pushlog_url. app_name: firefox build_date: 2021-03-08 14:49:15.347000 build_file: C:\Users\slalonde\.mozilla\mozregression\persist\48e48673b875-shippable--autoland--target.zip build_type: integration build_url: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BC_97eaQQs-jx2P6kRobPQ/runs/0/artifacts/public%2Fbuild%2Ftarget.zip changeset: 48e48673b875465cf58b570f0c0116ab019cb876 pushlog_url: https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=48e48673b875465cf58b570f0c0116ab019cb876&tochange=ae94c83c78f43cb3cdeadab9ff940fafb23918ef repo_name: autoland repo_url: https://hg.mozilla.org/integration/autoland task_id: BC_97eaQQs-jx2P6kRobPQ I looked at the pushlog, and the one that stands out as slightly suspicious is this one: 0501cc077bc2f462b1c2edbe2bbe7ba5e6740a9c Antonio Sartori — Bug 1691880 [wpt PR 27563] - Do not change referrer policy on document.open, a=testonly https://bugzilla.mozilla.org/show_bug.cgi?id=1691880 I've attached the output log of the mozregression.

(In reply to serge_lalonde from comment #18)

I looked at the pushlog, and the one that stands out as slightly suspicious
is this one:
0501cc077bc2f462b1c2edbe2bbe7ba5e6740a9c Antonio Sartori — Bug 1691880 [wpt
PR 27563] - Do not change referrer policy on document.open, a=testonly
https://bugzilla.mozilla.org/show_bug.cgi?id=1691880

That one only imports a test from another repo. It doesn't change anything about how Firefox behaves.

I just updated to Firefox 88.0. The problem persists. :-(

need-info myself to take a look

Flags: needinfo?(dd.mozilla)

Me to take a look at recent proxy changes.

Flags: needinfo?(dd.mozilla) → needinfo?(valentin.gosu)

@Serge,

Can you still reproduce this?
Could you try with the latest Nightly and capture a fresh log? Thanks!

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

No, unfortunately, I can no longer reproduce this. But then again, I was happy when it started working! :-)
Sometime in June or July, I tried it and it was suddenly working. I don't know if our enterprise IT changed something to support Firefox or if Firefox changed to fix it.
Should it be marked as resolved in that case, even if we don't know why?

Flags: needinfo?(serge_lalonde)

You could possibly try using mozregression --find-fix -g 96 -b 87 to find which commit fixed the issue - that's if it was a bug in Firefox, and if it's consistently reproducible (judging by comment 18 it's probably not)
We did make some changes to the PAC code recently, so it's possible some of this fixed it. Or maybe it was a change your IT department made.
In any case, thank you for your assistance. I'm happy it works now. Please let us know if you encounter any other problems.

Status: UNCONFIRMED → RESOLVED
Closed: 3 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: