Hello everyone,
our server is running a Lucee instance started from CommandBox, the application running on Lucee receives no more than 300 connections per minute (avg load is below 200) and we are sure that at least 1-2 connections per minutes receive this error:
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)
We have IIS connected to Lucee through BonCode. In BonCode’s log I see this kind of errors but timestamps don’t match those of failed connections (failed connections logs are from a different server, we checked system clocks and they are in sync).
2021-11-04 14:09:11 warning Stream reading problem (4)chunked read, we stopped waiting on Tomcat response. You may have shutdown Tomcat unexpectedly
2021-11-04 14:09:11 warning Stream reading problem (1). Null packet received in stream.
2021-11-04 14:09:11 1.0.41 ERROR
Thread was being aborted.
at BonCodeAJP13.BonCodeAJP13ServerConnection.ReadStream(Byte[]& receivedPacketBuffer, String readOrigin)
at BonCodeAJP13.BonCodeAJP13ServerConnection.ComunicateWithTomcat()
2021-11-04 14:09:11 1.0.41 ERROR
TCP Client level – Server/Port:127.0.0.1/8060
Thread was being aborted.
at BonCodeAJP13.BonCodeAJP13ServerConnection.ComunicateWithTomcat()
at BonCodeAJP13.BonCodeAJP13ServerConnection.HandleConnection()
at BonCodeAJP13.BonCodeAJP13ServerConnection.p_CreateConnection(BonCodeAJP13PacketCollection packetsToSend)
I don’t know if it’s related but in server.out.txt, in server’s consolelogpath, there only entries identical to: [ERROR] io.undertow.request: UT005011: Ignoring AJP request with prefix 18
Could you help me to pinpoint what’s causing the issue?
System specs:
Intel XEON E5-2673 v4, usage around 20-30%
8GB Ram, usage around 65%
CommandBox: 5.4.2+00453
Lucee: 5.3.7+48
BonCode: 1.3
OS: Windows server 2016 Datacenter
IIS: 10.0.14393.0
It would appear Boncode is sending an invalid request to CommandBox and that request is getting ignored. I am not the developer of BonCode, not Undertow (which is the library rejecting the request) so I’m not entirely sure what Ignoring AJP request with prefix 18 means, but I’ll have a look in the Undertow source code to see when this error is thrown.
While Brad pursues that possible undertow path of exploration, I notice that you say a couple of times that you can’t tell if the log lines you find are all coincident with the problem you are seeing. That of course makes it hard to know if they have anything to do with the problem.
I would wonder instead: couldn’t the first issue (Generic Connector Communication Error, and its suggestion about timeouts) be an indication simply that requests are at times slow to process within Lucee, perhaps even piling up?
To that, do you have any sort of tool tracking processing within Lucee, whether FusionReactor, SeeFusion, or any generic Java monitoring tool? You’d want one that tracks request processing (how many are running, how long are they taking), which many java monitors don’t do (they focus on “threads”, and there are often hundreds of thread of various types. We care most about threads that process CFML page requests–and since Lucee/CF/Tomcat reuse such threads over and over for different requests, that’s why we need to monitor them less as “threads” and more as “requests”.)
Of course, that follow-on message talked about changing timeouts in boncode…and sure, sometimes raising various timeouts will mask/put a bandaid on slow requests that are piling up. But usually the better solution is to confirm if requests ARE piling up, then if so find out WHY they are. Again, tools like FR and SF can help, such as to see if the requests are slow due to query processing, or perhaps a cfhttp call in your code to some 3rd party, etc.
But if Brad or Bilal (author of Boncode) or anyone else would say they know that that error is NOT due to something as simple as that, I’ll leave it at this. I don’t work often enough with Commandbox, let alone Commandbox integrated with Boncode, to readily recognize the specific error. I just wondered if it might have a different root cause than the log messages convey.
Ok, this error comes from here in the Undertow source code:
It happens when the web server proxy (Boncode, in this case) sends an AJP packet with a prefix code that is unexpected (not FORWARD_REQUEST, CPING or CPONG)
Here in the AJP documentation, I can’t find any reference to a valid prefix byte of 18
I would recommend creating a ticket for Bilal and ask him why Boncode is sending an prefix of 18 and what it is supposed to mean? It appears to not match the spec.
On this note, I do know there is a flag in Boncode called EnableAdobeMode which activates some special behaviors that only Adobe’s version of Tomcat knows how to understand. I don’t really know what this setting does, but I would check that it is NOT enabled in your boncode settings XML file. http://www.boncode.net/connector/webdocs/Tomcat_Connector.htm#_Toc38268635
Thank you both. We don’t have EnableAdobeMode param in our BonCode settings file, I’ll check with Bilal.
I forgot to mention that FusionReactor is running on the server, failed connections are not present. I checked both Metrics → Archived Metrics → Request.log and Requests → Error History, I found no trace of the request that received the “502 Bad Gateway” response (first error in OP).
I see no spikes at the time the request was rejected in Queued or Running Requests nor in Average Requests Runtime.
Paolo, just to round off your reply to me, I was not proposing you’d see anything indicating an “error” in FR. And while you don’t see “spikes”, that only would happen if there were many requests. (Even slowness in ONE request may not raise the avg req runtime much, if many other requests were running fast.)
Instead, look at requests>slow requests (the top 100 most recent requests that were slower than 8 seconds, by default). Or you could look at requests>longest requests, but that’s the 100 slowest requests since Lucee/CF came up, which may go back days (or may be filled with much slower requests than these you are looking for.)
Glad you found a workaround, but honestly I wouldn’t have closed the Boncode ticket if the issue still exists. It needs to be solved at some point or it will just continue to bite more people.
