Bilal-S / iis2tomcat

AJP Connector between Internet Information Services (IIS) and Apache Tomcat
http://www.boncode.net/boncode-connector
49 stars 32 forks source link

Generic Connector Communication Error only in IE, works in Chrome #91

Closed JohanFiske closed 4 years ago

JohanFiske commented 4 years ago

Hi,

I hope this is the right forum for this issue.

I have a server running Lucee with pretty much only default settings. There's a couple of sites in IIS7 with different bindings. The problem we're facing is that a lot of requests from IE gives the following error message:

Generic Connector Communication Error: Please check and adjust your setup: Ensure that Tomcat is running on given host and port. If this is a timeout error consider adjusting IIS timeout by changing executionTimeout attribute in web.config (see manual).

The error occurs for all of the sites and even if we use the server's host name.

Under two circumstances the sites does actually work:

I looked around the web but didn't find anyone with this particular problem. Any ideas where to look for configuration mistakes would be greatly appreciated.

Thanks, Johan

Bilal-S commented 4 years ago

Johan At first glace we need to exclude that this is a WINS vs DNS issue. Is this a public site? Can you access from internet without authentication? Do you get the same behavior?

JohanFiske commented 4 years ago

No, these are all internal applications. For me all URLs works, but my requests are probably not entirely applicable since I'm RDP:ing to an internal server and browsing from that environment. The users all have a client environments and I guess that there are differences in group policys and stuff. I instructed them to do a ping-request to the domain but from the results it looks identical to mine. Is there something particular that I should be looking (or instructing the users to look) at in IE to get a clue what settings could cause this behavior?

Thanks a lot for your feedback!

Bilal-S commented 4 years ago

Ok. This makes it a little more more to diagnose. It still looks like your IE is using a different resolution for the server than chrome unless you force the IP. Are you using mod_cfml or to create server contexts automatically or did you set them up manually?

JohanFiske commented 4 years ago

That was a good question. I was rather sure about setting up mod_cfml but when looking around now I'm not that sure anymore. What should I be looking for in order to figure this out? Maybe this is the root for the problem, but still, how could it work in Chrome with the different domains if the setup isn't entirely finished?

Bilal-S commented 4 years ago

We have to ensure that both the NetBios (WINS) base resolution is not interfering with DNS. Did you turn on any type of HTTP logging to see which requests are being handled by IIS.

You can also try to bypass IIS and connect directly to tomcat on port 8888. What results do you get when you do?

JohanFiske commented 4 years ago

Hi, I haven't been able to try out bypassing IIS yet. Will give it a try as soon as possible.

However, I enabled some more logging through the BonCodeAJO13.settings-file and the http://localhost/a.jsp?BonCodeEventLogPrep=true command and got some results:

Looking in the log files created I see a couple of successes (I assume) looking like: BonCodeAJP13.ServerPackets.BonCodeAJP13ForwardRequest GET /index.cfm 1428 bytes and a list of header parameters

But I also see a lot of: Closing Connection ID: 6 [T-5580] (with different ID:s and T-numbers)

In Event Viewer I have a lot of BonCodeConnector errors like this:

Connection error 2: Connection between Tomcat and IIS experienced error. If you restarted Tomcat this is expected.     at BonCodeAJP13.BonCodeAJP13ServerConnection.ConnectionError()
   at BonCodeAJP13.BonCodeAJP13ServerConnection.p_CreateConnection(BonCodeAJP13PacketCollection packetsToSend)
   at BonCodeIIS.BonCodeCallHandler.ProcessRequest(HttpContext context)

These errors does however not sync with the errors in the log files.

Does this give you any guidance? Thanks a lot for helping me troubleshooting.

Bilal-S commented 4 years ago

Can you provide the AJP line from server.xml for Tomcat and the Boncode settings file in use? To get location of the Boncode file run this from the server: http://localhost/a.cfm?BonCodeConnectorVersion=true You can remove the reqeust keys.

JohanFiske commented 4 years ago

Certainly,

Here's the line from D:\lucee\tomcat\conf <Connector port="8009" protocol="AJP/1.3" tomcatAuthentication="false" connectionTimeout="120000" redirectPort="8443" />

Here's the contents of the Boncode settings file (with logging enabled as latest update, these two lines were missing before but the error occurred both before and after this change)

<Settings>
<Server>localhost</Server>
<Port>8009</Port>
<EnableRemoteAdmin>True</EnableRemoteAdmin>
<EnableHeaderDataSupport>True</EnableHeaderDataSupport>
<ForceSecureSession>False</ForceSecureSession>
<AllowEmptyHeaders>False</AllowEmptyHeaders>
<ModCFMLSecret>[Removed]</ModCFMLSecret>
<LogLevel>3</LogLevel>
<LogDir>c:\temp</LogDir>
</Settings>

The connector version I'm receiving when running the url is 1.0.36

Bilal-S commented 4 years ago

Johan, you might have unsynchronized timeout issue. connectionTimeout="120000" This will close the TCP channel after 120s but on IIS the same timeout is 20min by default. If so you will run into scenarios where IIS thinks the channel is open and push traffic through it which will then throw errors.

I would change the server.xml AJP timeout to connectionTimeout="121000" and set the IIS idle timeout to 2mins for the site for now. This way both sides use the similar time limits with IIS timing out before tomcat.

Not sure how this would impact IE but let's start there.

image

JohanFiske commented 4 years ago

Thanks for the suggestions! I have updated this value in the Application Pool and recycled it. Also updated the server.xml-file. Do I need to restart anything more in order to have the settings deployed? Best would be if a restart could be made for a particular application/site only, is that doable?

Bilal-S commented 4 years ago

You can recycle the Application Pool. This will only impact that site. You need to restart Tomcat.

JohanFiske commented 4 years ago

This was done yesterday and there are some new findings from the users. Apparently they can get the applications to load in IE by triggering a new load by clicking Enter in the address field. There seems to be two types of scenarios.

-or-

If they then selects the URL and clicks enter the application loads correctly and they can browse the application as usual, but the it seems like the moment an F5 is made the error occurs again.


Another strange thing is that the BonCodeAJP-logs isn't completely in sync (time-wise) with the IIS logs. But only for the error posts, all the success posts are all in sync. For instance:

BonCodeAJP-log:

2020-04-08 07:07:27 Closing Connection ID: 1 [T-1988]
2020-04-08 07:46:47 New Connection 2 of 0 to tomcat: [::1]:8009 ID: 1 [T-9608]
2020-04-08 07:46:47 BonCodeAJP13.ServerPackets.BonCodeAJP13ForwardRequest GET /index.cfm 1297 bytes
2020-04-08 07:46:47 BonCodeAJP13.TomcatPackets.TomcatSendHeaders 325 bytes
2020-04-08 07:46:47 BonCodeAJP13.TomcatPackets.TomcatSendBodyChunk  8188 bytes
2020-04-08 07:46:47 BonCodeAJP13.TomcatPackets.TomcatSendBodyChunk  7398 bytes
2020-04-08 07:46:47 BonCodeAJP13.TomcatPackets.TomcatSendBodyChunk  4 bytes
2020-04-08 07:46:47 BonCodeAJP13.TomcatPackets.TomcatEndResponse  2 bytes

IIS-log (hours are adjusted since GMT+2):

2020-04-08 07:46:45 ... GET / ... **502** ...
2020-04-08 07:46:48 ... GET /index.cfm ... **200** ...

I assume that the two timestamps 07:46:47 and 07:46:48 are the same request. But the closed connection at 07:07:27 isn't to find in the IIS-log and the 502 error at 07:46:45 isn't to find in the BonCodeAJP-log. Does this indicate anything strange?


One last finding for now is that the Application event log now gives a lot of these types of errors. This one is logged at 07:46:45 which seems to be connected to the IIS-log entry at the same time:

ProcessRequest: Invalid content length. Last header processed [HTTP_AUTHORIZATION]. Please reconfigure BonCode Connector and Apache Tomcat to allow larger transfer packets. Your max allowed content length is 8186 bytes. Provided content length would be at least 12761 bytes. Clearing cookies may allow you proceed.    at BonCodeAJP13.ServerPackets.BonCodeAJP13ForwardRequest.WritePacket(Byte method, String protocol, String req_uri, String remote_addr, String remote_host, String server_name, UInt16 server_port, Boolean is_ssl, Int32 num_headers, NameValueCollection httpHeaders, String realPathInfo, Int32 sourcePort, String vDirs)
   at BonCodeAJP13.ServerPackets.BonCodeAJP13ForwardRequest.WritePacket(NameValueCollection httpHeaders, String pathInfo, Int32 sourcePort, String vDirs)
   at BonCodeIIS.BonCodeCallHandler.ProcessRequest(HttpContext context)
Bilal-S commented 4 years ago

Johan Thanks for the detailed info. The timing of AJP connection is not always identical to HTTP connections especially after the connection os already established. There is high correlation though. We maybe chasing a few ghosts as well.
You mentioned that you are using 1.0.36 version of connector. Can you move to latest version please. We have fixed quite a few things since 1.0.36

http://www.boncode.net/boncode-connector/upgrading-railo-or-lucee-connector

JohanFiske commented 4 years ago

Hi, I have updated the connector and it's running with version 1.0.41 now. Unfortunately no change for the users.

The log files still behaves the same, with a pattern of a 401 being followed by a 502 - given that the browser is IE or maybe Edge, but not with Chrome, there a 200 occurs after the 401 instead.

The event log message stating that [HTTP_AUTHORIZATION] has an Invalid content length, could that be a clue of something?

Thanks again for helping out with this, much appreciated!

Bilal-S commented 4 years ago

A 401 is normally issued as authentication challenge by IIS. Could be connected to NTLM / Kerberos auth which only IE would participate in automatically. Do users need to authenticate to get to this website?

The authentication should prompt for user/pass or in IE cases integrated response. The challenge response should not be transmitted to tomcat or connector. Not certain that is happening.

I would start the investigation from resolving 401 errors, the 502 is a generic catch all.

You can enable Windows Application logging to see whether anything more is available. http://www.boncode.net/connector/webdocs/Tomcat_Connector.htm#_Toc520189761

JohanFiske commented 4 years ago

Yes, the 401 seems to be the root cause for this case. What do you think of the following error that occurs in Event Viewer?

ProcessRequest: Invalid content length. Last header processed [HTTP_AUTHORIZATION]. Please reconfigure BonCode Connector and Apache Tomcat to allow larger transfer packets. Your max allowed content length is 8186 bytes. Provided content length would be at least 10767 bytes. Clearing cookies may allow you proceed.    at BonCodeAJP13.ServerPackets.BonCodeAJP13ForwardRequest.WritePacket(Byte method, String protocol, String req_uri, String remote_addr, String remote_host, String server_name, UInt16 server_port, Boolean is_ssl, Int32 num_headers, NameValueCollection httpHeaders, String realPathInfo, Int32 sourcePort, String vDirs)
   at BonCodeAJP13.ServerPackets.BonCodeAJP13ForwardRequest.WritePacket(NameValueCollection httpHeaders, String pathInfo, Int32 sourcePort, String vDirs)
   at BonCodeIIS.BonCodeCallHandler.ProcessRequest(HttpContext context)

Is it worth trying to change the setting for "Max allowed content length", and if so, where do I find this setting?

Bilal-S commented 4 years ago

That is a good error message it highlights your problem. With the authentication headers your package length exceeds protocol settings.

You will need to make corresponding changes in tomcat and connector. See docs (only do packetSize for now): http://www.boncode.net/connector/webdocs/Tomcat_Connector.htm#_Toc520189773

JohanFiske commented 4 years ago

It seems like we finally found the cause for this! After changing (increasing) the packetSize in both TomCat and the Connector everything now works as expected. Been monitoring this during the weekend and no 401:s from the users.

The question why this only occurred in IE still remains though, but I think that we can live with that :)

Many many thanks for all your help Bilal, it has been truly valuable!

Regards, Johan

Bilal-S commented 4 years ago

Glad to hear it worked out for you. Keep safe.