Firefox forcing HTTPS on non-HSTS enabled domains

UNCONFIRMED
Unassigned

Status

()

P3
normal
UNCONFIRMED
a year ago
6 months ago

People

(Reporter: Patrick.Schultz1, Unassigned)

Tracking

54 Branch
x86_64
Windows 10
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [necko-backlog])

Attachments

(3 attachments)

(Reporter)

Description

a year ago
Created attachment 8889962 [details]
Network analysis output

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:54.0) Gecko/20100101 Firefox/54.0
Build ID: 20170628075643

Steps to reproduce:

1. Visit affected website (no HSTS header) and subdirectories multiple times
2. Try to visit a subdirectory which is only reachable via HTTP (https redirects to http)


Actual results:

Firefox tries to redirect the client to the HTTPS version and runs into a redirection loop because the webserver redirects the request to HTTP


Expected results:

Firefox should load the HTTP page normally
(Reporter)

Updated

a year ago
tracking-firefox54: --- → ?
tracking-firefox55: --- → ?
tracking-firefox56: --- → ?
tracking-firefox57: --- → ?
OS: Unspecified → Windows 10
Hardware: Unspecified → x86_64
Component: Untriaged → Networking: HTTP
Product: Firefox → Core
Hi Patrick,
May I know if you enable the HSTS preference, like setting security.mixed_content.send_hsts_priming & security.mixed_content.use_hsts to true?
Flags: needinfo?(Patrick.Schultz1)
(Reporter)

Comment 2

a year ago
(In reply to Gerry Chang [:gchang] from comment #1)
> May I know if you enable the HSTS preference, like setting
> security.mixed_content.send_hsts_priming & security.mixed_content.use_hsts
> to true?

Hi Gerry,
Both preferences are set to false (default).
Flags: needinfo?(Patrick.Schultz1)
Can you give us a uri that I can try to reproduce?

Or you can give me a http log and if you do not what it uploaded here you can send it to me directly:

https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging
Flags: needinfo?(Patrick.Schultz1)
(Reporter)

Comment 4

a year ago
Created attachment 8890694 [details]
log.txt-main.16913

HTTP log
Flags: needinfo?(Patrick.Schultz1) → needinfo?(dd.mozilla)
tracking-firefox54: ? → ---
tracking-firefox55: ? → ---
tracking-firefox56: ? → ---
tracking-firefox57: ? → ---
Thank you for the log. I will try to get to it soon.
I do not see anything strange in the log.

Can you tell me exactly which uri have you visited before the loop started?

Can you run the log not using about:networking but using the description under:
"Logging HTTP activity by manually setting environment variables" (at https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging)

Also instead of "set MOZ_LOG=timestamp,rotate:200,nsHttp:5,nsSocketTransport:5,nsStreamPump:5,nsHostResolver:5" please use

set MOZ_LOG=timestamp,nsHttp:5,nsSocketTransport:5,nsSSService:5
Flags: needinfo?(dd.mozilla)
Can you help provide log by following comment #6?
Flags: needinfo?(Patrick.Schultz1)
(Reporter)

Comment 8

a year ago
Created attachment 8892911 [details]
log.txt-main.1890
Flags: needinfo?(Patrick.Schultz1)
(Reporter)

Comment 9

a year ago
(In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment #7)
> Can you help provide log by following comment #6?

The variable method didn't quite work (empty file), so I attached a second about:networking log.
One of the URIs is https://www.hs-owl.de/fb1/ (301 to http version)
From the latest log, I didn't find any log that www.hs-owl.de carries HSTS header but suddenly we decided to redirect to HTTPS URL. @dragana might want to double check the log.

>2017-07-31 12:36:33.650573 UTC - [Main Thread]: V/nsHttp Creating HttpChannelParent [this=7f29f2057230]
>2017-07-31 12:36:33.650581 UTC - [Main Thread]: V/nsHttp HttpChannelParent::Init [this=7f29f2057230]
>2017-07-31 12:36:33.650590 UTC - [Main Thread]: V/nsHttp HttpChannelParent RecvAsyncOpen [this=7f29f2057230 uri=http://www.hs-owl.de/fb1/]
>2017-07-31 12:36:33.650602 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NewProxiedChannel [proxyInfo=0]
>2017-07-31 12:36:33.650606 UTC - [Main Thread]: V/nsHttp Creating HttpBaseChannel @cf3a0000
>2017-07-31 12:36:33.650608 UTC - [Main Thread]: D/nsHttp Creating nsHttpChannel [this=7f29cf3a0000]
>2017-07-31 12:36:33.650612 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::Init [this=7f29cf3a0000]
>2017-07-31 12:36:33.650614 UTC - [Main Thread]: V/nsHttp host=www.hs-owl.de port=-1
>2017-07-31 12:36:33.650615 UTC - [Main Thread]: V/nsHttp uri=http://www.hs-owl.de/fb1/
>2017-07-31 12:36:33.650621 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Init [this=7f29cf3a0000]
>2017-07-31 12:36:33.650626 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::SetRequestHeader [this=7f29cf3a0000 header="Cookie" value="" merge=0]
>2017-07-31 12:36:33.650636 UTC - [Main Thread]: D/nsHttp nsHttpChannel::SetCacheKey [this=7f29cf3a0000 key=7f2a01254740]
>2017-07-31 12:36:33.650638 UTC - [Main Thread]: D/nsHttp nsHttpChannel::SetAllowStaleCacheContent [this=7f29cf3a0000, allow=0]
>2017-07-31 12:36:33.650666 UTC - [Main Thread]: D/nsHttp nsHttpChannel::AsyncOpen [this=7f29cf3a0000]
>2017-07-31 12:36:33.650682 UTC - [Main Thread]: D/nsHttp NS_CompareLoadInfoAndLoadContext - loadInfo: 0, 0, 0, 0; loadContext: 0 0, 0, 0. [channel=7f29cf3a0048]
>2017-07-31 12:36:33.650711 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::SetRequestHeader [this=7f29cf3a0000 header="Cookie" value="X-HS-OWL=2876616385.20480.0000; PHPSESSID=13a0d919e1fd023b3256555fc4351d7d" merge=0]
>2017-07-31 12:36:33.650714 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=cf3a0048 event="http-on-opening-request"]
>2017-07-31 12:36:33.650718 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ResolveProxy [this=7f29cf3a0000]
>2017-07-31 12:36:33.650731 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnProxyAvailable [this=7f29cf3a0000 pi=7f29dec04e20 status=0 mStatus=0]
>2017-07-31 12:36:33.650732 UTC - [Main Thread]: D/nsHttp nsHttpChannel::BeginConnect [this=7f29cf3a0000]
>2017-07-31 12:36:33.650734 UTC - [Main Thread]: D/nsHttp host=www.hs-owl.de port=-1
>2017-07-31 12:36:33.650735 UTC - [Main Thread]: D/nsHttp uri=http://www.hs-owl.de/fb1/
>2017-07-31 12:36:33.650741 UTC - [Main Thread]: D/nsHttp nsHttpChannel 7f29cf3a0000 Using default connection info
>2017-07-31 12:36:33.650743 UTC - [Main Thread]: V/nsHttp Init nsHttpConnectionInfo @7f29daa9f690
>2017-07-31 12:36:33.650753 UTC - [Main Thread]: D/nsHttp nsHttpChannelAuthProvider::AddAuthorizationHeaders? [this=7f29b39593e0 channel=7f29cf3a0510]
>2017-07-31 12:36:33.650757 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::GetAuthEntryForPath [key=http://www.hs-owl.de:-1 path=/fb1/]
>2017-07-31 12:36:33.650760 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=cf3a0048 event="http-on-modify-request"]
>2017-07-31 12:36:33.650974 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=cf3a0048 event="http-on-useragent-request"]
>2017-07-31 12:36:33.650984 UTC - [Main Thread]: D/nsHttp nsHttpChannel::BeginConnect [this=7f29cf3a0000] prefetching
>2017-07-31 12:36:33.650990 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ContinueBeginConnectWithResult [this=7f29cf3a0000]
>2017-07-31 12:36:33.651023 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Connect [this=7f29cf3a0000]
>2017-07-31 12:36:33.651026 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::SetRequestHeader [this=7f29cf3a0000 header="Upgrade-Insecure-Requests" value="1" merge=0]
>2017-07-31 12:36:33.651041 UTC - [Main Thread]: D/nsSSService Found entry for www.hs-owl.de
>2017-07-31 12:36:33.651043 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Connect() STS permissions found
>2017-07-31 12:36:33.651049 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ContinueBeginConnectWithResult result [this=7f29cf3a0000 rv=0 mCanceled=0]
>2017-07-31 12:36:33.651051 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Starting nsChannelClassifier 7f2a0166b640 [this=7f29cf3a0000]
>2017-07-31 12:36:33.651078 UTC - [Main Thread]: D/nsHttp nsHttpChannel::SuspendInternal [this=7f29cf3a0000]
>2017-07-31 12:36:33.651231 UTC - [Main Thread]: D/nsHttp Waiting until resume to do async redirect to https [this=7f29cf3a0000]
>2017-07-31 12:36:33.651243 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ResumeInternal [this=7f29cf3a0000]
>2017-07-31 12:36:33.651257 UTC - [Main Thread]: D/nsHttp nsHttpChannel::HandleAsyncRedirectChannelToHttps() [STS]
>2017-07-31 12:36:33.651262 UTC - [Main Thread]: D/nsHttp nsHttpChannel::StartRedirectChannelToURI()
>2017-07-31 12:36:33.651265 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NewProxiedChannel [proxyInfo=0]
>2017-07-31 12:36:33.651270 UTC - [Main Thread]: V/nsHttp Creating HttpBaseChannel @d754a000
Flags: needinfo?(dd.mozilla)
The log is not long enough. Something is adding this entry into the table

2017-07-31 12:36:33.651041 UTC - [Main Thread]: D/nsSSService Found entry for www.hs-owl.de

The log is not long enough to see what is adding it.

Can you make a log that starts before you access uri=http://www.hs-owl.de/fb1/ the first time when it is working just fine until it fails.

You can also send the log directly to me via e-mail if you do not want to make it public.


Thank you
Flags: needinfo?(dd.mozilla) → needinfo?(Patrick.Schultz1)
(tempted to close this, but we have some URLs to test with, so when someone finds time later, we can resurrect from backlog)
Whiteboard: [necko-backlog]
What are the contents of SiteSecurityServiceState.txt in your profile? It's fine if you don't want to share the whole thing (it essentially contains part of your browsing history), but please copy the entire lines for any line that has hs-owl.de in it. If there are other sites redirecting in your logs please include lines with the parent domains of those sites also.
(Reporter)

Comment 16

11 months ago
(In reply to Daniel Veditz [:dveditz] from comment #15)
> What are the contents of SiteSecurityServiceState.txt in your profile? 

uc.hs-owl.de:HSTS	6	17389	1533991204834,1,1
#www.hs-owl.de:HSTS	13	17389	1516405735109,1,0
Flags: needinfo?(Patrick.Schultz1)

Comment 17

6 months ago
I am seeing behavior that looks like this problem on a local dev domain as well.

Steps:
1. Attempt to load http://tantek.dev/ in the FF addressbar (local via /etc/hosts entry: 127.0.0.1 tantek.dev)
2. Firefox (59.0.2) incorrectly redirects to https://tantek.dev/ and fails

No idea why FF is attempting an HTTPS connection - I have never set up tantek.dev locally with HTTPS.

Possibly relevant lines from HTTP log:

2018-04-03 17:45:49.724444 UTC - [11521:Main Thread]: V/nsHttp host=tantek.dev port=-1
2018-04-03 17:45:49.724447 UTC - [11521:Main Thread]: V/nsHttp uri=http://tantek.dev/
2018-04-03 17:45:49.724456 UTC - [11521:Main Thread]: D/nsHttp nsHttpChannel::Init [this=0x1d1d48000]
2018-04-03 17:45:49.724521 UTC - [11521:Main Thread]: V/nsHttp Init nsHttpConnectionInfo @0x1625b8d00
2018-04-03 17:45:49.724529 UTC - [11521:Main Thread]: V/nsHttp nsHttpConnectionMgr::SpeculativeConnect [ci=.S.....[tlsflags0x00000000]tantek.dev:443]
2018-04-03 17:45:49.724537 UTC - [11521:Main Thread]: D/nsHttp NulHttpTransaction::NullHttpTransaction() mActivityDistributor is active [this=0x14acdcca0, tantek.dev]
...
2018-04-03 17:45:49.725695 UTC - [11521:Socket Thread]: D/nsHostResolver Checking blacklist for host [tantek.dev], host record [0x1f2576500].
2018-04-03 17:45:49.725704 UTC - [11521:Socket Thread]: D/nsHostResolver Address [127.0.0.1] is blacklisted for host [tantek.dev].
2018-04-03 17:45:49.725708 UTC - [11521:Socket Thread]: D/nsHostResolver Resetting blacklist for host [tantek.dev], host record [0x1f2576500].
...
2018-04-03 17:45:49.725870 UTC - [11521:Socket Thread]: D/nsHostResolver Checking blacklist for host [tantek.dev], host record [0x1f2576500].
2018-04-03 17:45:49.725882 UTC - [11521:Socket Thread]: V/nsHttp nsHttpConnectionMgr::nsHalfOpenSocket::OnTransportStatus STATUS_CONNECTING_TO Established New Coalescing Key # 0 for host tantek.dev [127.0.0.1~.:443/[]viaDNS]
2018-04-03 17:45:49.725905 UTC - [11521:Socket Thread]: V/nsHttp FindCoalescableConnection .S.....[tlsflags0x00000000]tantek.dev:443
2018-04-03 17:45:49.725915 UTC - [11521:Socket Thread]: V/nsHttp FindCoalescableConnection(.S.....[tlsflags0x00000000]tantek.dev:443) no matching conn
the "dev" tld is included in the hsts preload list by its owner.
And I should have included a link to https://hstspreload.org/?domain=dev in comment 18

Comment 20

6 months ago
Thanks Julien, I had checked https://hstspreload.org/?domain=tantek.dev which had no entry and forgot to just check the TLD.

Comment 21

6 months ago
Hi Tantek, if you can neither change away from .dev nor secure it with HTTPS, there is a preference that allows disabling the preloaded list (at least for now): network.stricttransportsecurity.preloadlist
You need to log in before you can comment on or make changes to this bug.