When sending a POST over http and SSL via a Proxy, The connection gets terminated by Firefox

UNCONFIRMED
Unassigned
(Needinfo from 2 people)

Status

()

Core
Layout: Form Controls
P3
normal
UNCONFIRMED
a month ago
8 days ago

People

(Reporter: Pascal Fleer, Unassigned, NeedInfo)

Tracking

56 Branch
x86_64
Windows 10
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(2 attachments)

(Reporter)

Description

a month ago
User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:56.0) Gecko/20100101 Firefox/56.0
Build ID: 20171002220106

Steps to reproduce:

When connecting from Firefox to an internal web server via a Proxy, a POST Request blocks Firefox.

Firefox 56 (but also Firefox 52 ESR or Firefox Firefox 45 ESR) connects to the web server https://xclc.viennaairport.com/ via a Squid Proxy server. In one of the business processes, a POST is sent to the web server via a squid proxy server.  

As the website is partly internal, reproduction by a Firefox developper is difficult. But we are willing to allow remote access. 


Actual results:

In the trace with have POST with following content (out of wireshark): 
HTML Form URL Encoded: application/x-www-form-urlencoded
    Form item: "flightOid" = "2137525"
    Form item: "flightNumber" = "OS806"
    Form item: "method" = "applyRA"
    Form item: "currentPantryCode" = "*C"
    Form item: "pantryOid" = "70420"
    Form item: "oldCrewCockpit" = "2"
    Form item: "oldCrewCabin" = "3"
    Form item: "crewCockpit" = "2"
    Form item: "crewCabin" = "3"
    Form item: "xcrPerClass[1]" = ""
    Form item: "xcrPerClass[2]" = ""
    Form item: "xcrPerSection[0]" = ""
    Form item: "xcrPerSection[1]" = ""
    Form item: "xcrPerSection[2]" = ""
    Form item: "xcrPerSection[3]" = ""
    Form item: "oldFlightTimeEstimatedString" = ""
    Form item: "flightTimeEstimatedString" = ""
    Form item: "oldFlightTimeMaxString" = ""
    Form item: "flightTimeMaxString" = ""
    Form item: "oldAlternateAirportCode" = ""
    Form item: "alternateAirportCode" = ""
    Form item: "oldCaptainName" = ""
    Form item: "captainName" = ""
    Form item: "maxZeroFuelWeight" = ""
    Form item: "maxTakeoffWeight" = ""
    Form item: "maxLandingWeight" = ""
    Form item: "airlinePhoneNumber" = "+431700729007"
    Form item: "supervisorPhoneNumber" = ""
    Form item: "oldTaxiFuel" = "120"
    Form item: "taxiFuel" = "120"
    Form item: "oldTripFuel" = ""
    Form item: "tripFuel" = ""
    Form item: "oldTakeoffFuel" = ""
    Form item: "takeoffFuel" = "1000"
    Form item: "editableCrewMembers.line[0].oid" = ""
    Form item: "editableCrewMembers.line[0].name" = ""
    Form item: "editableCrewMembers.line[0].function" = ""
    Form item: "editableCrewMembers.line[1].oid" = ""
    Form item: "editableCrewMembers.line[1].name" = ""
    Form item: "editableCrewMembers.line[1].function" = ""
    Form item: "editableCrewMembers.line[2].oid" = ""
    Form item: "editableCrewMembers.line[2].name" = ""
    Form item: "editableCrewMembers.line[2].function" = ""
    Form item: "editableCrewMembers.line[3].oid" = ""
    Form item: "editableCrewMembers.line[3].name" = ""
    Form item: "editableCrewMembers.line[3].function" = ""
    Form item: "editableCrewMembers.line[4].oid" = ""
    Form item: "editableCrewMembers.line[4].name" = ""
    Form item: "editableCrewMembers.line[4].function" = ""

The connection is terminated by Firefox (wireshark trace):
8944	2017-10-25 09:14:06.552130	WS673560-LHSYS.lic.fra.dlh.de	prx-fracute-integ01.inet.cns.fra.dlh.de	HTTP	575	POST /MACHwbclc/load/basicFlightData.vie HTTP/1.1  (application/x-www-form-urlencoded)
8945	2017-10-25 09:14:06.553717	prx-fracute-integ01.inet.cns.fra.dlh.de	WS673560-LHSYS.lic.fra.dlh.de	TCP	60	8080 → 65231 [ACK] Seq=233450 Ack=23786 Win=84224 Len=0
9137	2017-10-25 09:14:08.315083	prx-fracute-integ01.inet.cns.fra.dlh.de	WS673560-LHSYS.lic.fra.dlh.de	TCP	60	8080 → 65232 [FIN, ACK] Seq=1416 Ack=1662 Win=32768 Len=0
9138	2017-10-25 09:14:08.315172	WS673560-LHSYS.lic.fra.dlh.de	prx-fracute-integ01.inet.cns.fra.dlh.de	TCP	54	65232 → 8080 [ACK] Seq=1662 Ack=1417 Win=65280 Len=0
9140	2017-10-25 09:14:08.315480	WS673560-LHSYS.lic.fra.dlh.de	prx-fracute-integ01.inet.cns.fra.dlh.de	TLSv1.2	107	Alert (Level: Warning, Description: Close Notify)
9141	2017-10-25 09:14:08.315561	WS673560-LHSYS.lic.fra.dlh.de	prx-fracute-integ01.inet.cns.fra.dlh.de	TCP	54	65232 → 8080 [FIN, ACK] Seq=1715 Ack=1417 Win=65280 Len=0
9142	2017-10-25 09:14:08.317229	prx-fracute-integ01.inet.cns.fra.dlh.de	WS673560-LHSYS.lic.fra.dlh.de	TCP	60	8080 → 65232 [RST] Seq=1417 Win=0 Len=0
9143	2017-10-25 09:14:08.317230	prx-fracute-integ01.inet.cns.fra.dlh.de	WS673560-LHSYS.lic.fra.dlh.de	TCP	60	8080 → 65232 [RST] Seq=1417 Win=0 Len=0

See the attached log file at line 
2017-10-25 07:56:55.333000 UTC - [Main Thread]: I/nsHttp   POST /MACHwbclc/load/basicFlightData.vie HTTP/1.1

If desired, additionnal logs with different options can be generated.
Active logging settings: SET MOZ_LOG=timestamp,sync,rotate:200,nsHttp:5,nsSocketTransport:5,nsStreamPump:5,nsHostResolver:5




Expected results:

Firefox should not terminate the connection. At the moment, the web site hangs.

A workaround has been implemented for Firefox. Other browsers (Chrome, Edge) do not have this symptom
Component: General → Untriaged
OS: Unspecified → Windows 10
Product: Mozilla Developer Network → Firefox
Hardware: Unspecified → x86_64
Version: unspecified → 56 Branch

Updated

a month ago
Component: Untriaged → Networking: HTTP
Product: Firefox → Core
Hi Pascal, it sounds like you already capture a MOZ_LOG from your bug description. Can you help upload it to bugzilla so that we can do the first hand analysis? Thanks!
Flags: needinfo?(pascal.fleer)
(Reporter)

Comment 2

a month ago
Created attachment 8922278 [details]
MOZ_LOG.zip

Hello,
This is the MOZ_LOG zipped as requested.
Cheers, Pascal
Flags: needinfo?(pascal.fleer)
In the log I see that something is canceling the http channel:

2017-10-26 07:35:57.214000 UTC - [Main Thread]: D/nsHttp HttpChannelChild::Cancel [this=000001AE730EC000]

 do not know that is canceling it, it is out of necko so it is not captured by this log.

Can you tell me how this request is made? is it a form, xhr?
Flags: needinfo?(pascal.fleer)
(Reporter)

Comment 4

21 days ago
Hello,

As I have full control of the logging options and can recreate the issue at will, could suggest additionnal flags for logging?

At the moment I start tracing and logging as follows:

REM SSL Key Capture for wireshark decoding
SET SSLKEYLOGFILE=.\SSLKEY.LOG

REM NSPR logging options and location
SET NSPR_LOG_MODULES=timestamp,sync,all:5
SET NSPR_LOG_FILE=.\NSPRLOGFILE.TXT

REM MOZLOG logging options and location
SET MOZ_LOG=timestamp,sync,rotate:200,nsHttp:5,nsSocketTransport:5,nsStreamPump:5,nsHostResolver:5
SET MOZ_LOG_FILE=.\MOZLOGFILE.TXT

REM Start options - no remote for distinct setup, show console, 
"C:\Program Files (x86)\Mozilla Firefox\firefox.exe" -no-remote -console -profile "D:\DATA\cfdev\CF\FIREFOX\PROFILE" https://xclc.viennaairport.com/

As for the procedure:
A bit of background : The web application is a aircraft load control application, with a business process "fuel and crew".
A mask with entry fields collects information from the operator, and the operator pushes a button which triggers the http POST due to the use of a HTML Form.

Out of the integrated debugger I copied the following data:

---- Request Header ---- : 
Host	
xclc.viennaairport.com
User-Agent	
Mozilla/5.0 (Windows NT 10.0; …) Gecko/20100101 Firefox/56.0
Accept	
text/html,application/xhtml+xm…plication/xml;q=0.9,*/*;q=0.8
Accept-Language	
en-US,en;q=0.5
Accept-Encoding	
gzip, deflate, br
Referer	
https://xclc.viennaairport.com…ghtData.vie?flightOid=2142402
Content-Type	
application/x-www-form-urlencoded
Content-Length	
1234
Cookie	
JSESSIONID=B293882E6973B4C19CA…D1311A7B41DCFF86E808FD29E0C43
Connection	
keep-alive
Upgrade-Insecure-Requests	
1
----------------

---- Params ---- :
flightOid=2142402
flightNumber=OS800
method=applyRA
currentPantryCode=*C
pantryOid=70420
oldCrewCockpit=2
oldCrewCabin=3
crewCockpit=2
crewCabin=3
xcrPerClass[1]
xcrPerClass[2]
xcrPerSection[0]
xcrPerSection[1]
xcrPerSection[2]
xcrPerSection[3]
oldFlightTimeEstimatedString
flightTimeEstimatedString
oldFlightTimeMaxString
flightTimeMaxString
oldAlternateAirportCode
alternateAirportCode
oldCaptainName
captainName
maxZeroFuelWeight
maxTakeoffWeight
maxLandingWeight
airlinePhoneNumber=00431700724365
supervisorPhoneNumber
oldTaxiFuel=120
taxiFuel=120
oldTripFuel
tripFuel
oldTakeoffFuel
takeoffFuel=1000
editableCrewMembers.line[0].oid
editableCrewMembers.line[0].name
editableCrewMembers.line[0].function
editableCrewMembers.line[1].oid
editableCrewMembers.line[1].name
editableCrewMembers.line[1].function
editableCrewMembers.line[2].oid
editableCrewMembers.line[2].name
editableCrewMembers.line[2].function
editableCrewMembers.line[3].oid
editableCrewMembers.line[3].name
editableCrewMembers.line[3].function
editableCrewMembers.line[4].oid
editableCrewMembers.line[4].name
editableCrewMembers.line[4].function
----------------

the POST is initiated directly by Firefox due to the HTML Form.

When the web application developer takes out the array elements of the POST, the POST works. But he doesn't want to change his code at the moment due to the argument that the other browsers (Edge, Chrome) work. 

This situation only happens in conjunction with a Proxy. If the proxy is left out of the communication chain, Firefox works as charm.

If you need to access my test setup, I can provide access through a remote access (teamviewer for example)
Flags: needinfo?(pascal.fleer)
(Reporter)

Comment 5

21 days ago
Additionnal information: 
The issues exists also with the 45ESR branch and the 52ESR branch.
Cheers, Pascal
Can you make a http log without proxy as well?

From log I have seen that something on the page is canceling the load. I do not see that the TCP connection is failing. I do not know how the behavior is different with or without proxy.

A remote access would be good.
Daniel, you have looked at the proxy code recently. Do you know why the proxy makes a difference here? Can you look at the code.
Flags: needinfo?(daniel)
(Reporter)

Comment 8

21 days ago
Created attachment 8925237 [details]
MOZ LOG for connection without proxy, where the post is successfull

As requested by Dragana
(Reporter)

Comment 9

15 days ago
Additionnal Information:

When reducing the size of the POST payload, for example:
---- Params ---- :
flightOid=2142402
flightNumber=OS800
method=applyRA
currentPantryCode=*C
pantryOid=70420
oldCrewCockpit=2
oldCrewCabin=3
crewCockpit=2
crewCabin=3
airlinePhoneNumber=00431700724365
oldTaxiFuel=120
taxiFuel=120
takeoffFuel=1000
----------------

The POST goes through. But this workaround implies to rework the html form and replace it with a XHR based request. 

And I would renew my offer for a remote session where I make the system available for testing.
(Reporter)

Comment 10

10 days ago
I redid the test with the newest Firefox 57.0 and Firefox 52.3.0esr - (no surprise) the issue persists.
Can you setup a remote access?
(Reporter)

Comment 12

10 days ago
(In reply to Dragana Damjanovic [:dragana] from comment #11)
> Can you setup a remote access?

Yes I can. Is using teamviewer as software (https://www.teamviewer.com/) Ok with you? If yes, I would setup a virtual machine with a fresh install of Windows and Firefox. I would then assist you with the access to the application.

What would be the preferred time? Which time zone are you?
Actually thinking of it , my comment #3 suggested that the channel is canceled from outside necko. I head another look and I think this is not a networking problem.

It would be better that someone from the Form team take a look at this.
Component: Networking: HTTP → Layout: Form Controls
(Reporter)

Comment 14

8 days ago
(In reply to Dragana Damjanovic [:dragana] from comment #13)
> Actually thinking of it , my comment #3 suggested that the channel is
> canceled from outside necko. I head another look and I think this is not a
> networking problem.
> 
> It would be better that someone from the Form team take a look at this.

Remote access setup is ready. The test can be done with either FF 52.5.0esr as well as FF 57.0
Due to confidentiality, I would not post the access details here. How should we proceed?
(In reply to Dragana Damjanovic [:dragana] from comment #13)
> Actually thinking of it , my comment #3 suggested that the channel is
> canceled from outside necko. I head another look and I think this is not a
> networking problem.
> 
> It would be better that someone from the Form team take a look at this.

Jonathan: can you have a look and see if we close channels from within Form Layout? I don't know of any proxy-dependent behavior in our rendering code. Perhaps this proxy cancels connections that match these parameters? Thx!
Flags: needinfo?(jwatt)

Updated

8 days ago
Priority: -- → P3
You need to log in before you can comment on or make changes to this bug.