You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by Konstantin Kolinko <kn...@gmail.com> on 2011/07/08 05:41:28 UTC
Blank extra access log entries with AJP connector in 7.0.18
Running 7.0.18 behind Apache HTTPD,
using Ajp connector (Bio),
for every actual request there are two records in the access log,
one "true" record, followed by a blank one.
E.g.:
ipaddress - username [08/Jul/11:07:16:05 +0400] "GET /manager/html
HTTP/1.1" 200 24854
ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
ipaddress - username [08/Jul/11:07:16:05 +0400] "GET
/manager/images/asf-logo.gif HTTP/1.1" 304 -
ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
ipaddress - username [08/Jul/11:07:16:06 +0400] "GET
/manager/images/tomcat.gif HTTP/1.1" 304 -
ipaddress - - [08/июл/11:07:16:06 +0400] "-" 400 -
These extra log entries are absent in Apache HTTPD logs.
This issue is specific to AJP. When I tested with HTTP x Bio/Nio/Apr
the logs were operating correctly.
It is not pretty, but it does not look like a show stopper.
This issue is observed with 7.0.17 as well. I have not tested 7.0.16
in this configuration.
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Blank extra access log entries with AJP connector in 7.0.18
Posted by Mark Thomas <ma...@apache.org>.
On 08/07/2011 09:59, Rainer Jung wrote:
> On 08.07.2011 10:50, Mark Thomas wrote:
>> On 08/07/2011 09:47, Rainer Jung wrote:
>>> No without wild guessing:
>>>
>>> AjpProcessor.recycle() now nulls input. On the next loop through
>>> processing the connection, trying to read from the nulled input will
>>> lead to an NPE, producing the 400 log entry.
>>>
>>> In 7.0.16 recycle was implemented in AbstractAjpProcessor.java and did
>>> not null input.
>>
>> Looks like another refactoring problem. I'll take a look.
>
> Index: java/org/apache/coyote/ajp/AjpProcessor.java
> ===================================================================
> @@ -242,13 +242,6 @@
>
> }
>
> - @Override
> - public void recycle() {
> - super.recycle();
> - input = null;
> - output = null;
> - }
> -
> // ----------------------------------------------------- ActionHook
> Methods
>
> might do it. recycle() is only called once and at that place we don't
> want to null input (and output) except we break out from the loop.
We also set those to null if the socket is closed in asyncDispatch().
That is what triggered that code appearing in the recycle method.
Removing those calls will fix the issue but I need to think about what
it might do to asyncDispatch(). We don't null out the socket when it is
closed so I wonder if we really need to null these out.
Looking at this has raised some more subtle differences between the AJP
implementations. I'll work on this today. Hopefully, I'll fix this and
further reduce the duplicate code at the same time.
Mark
> Directly below the loop we null input and output, except when we still
> need it. At least my interpretation of the code.
>
> The change fixes the issue, but I didn't extensively test it.
>
> Regards,
>
> Rainer
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: dev-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Blank extra access log entries with AJP connector in 7.0.18
Posted by Rainer Jung <ra...@kippdata.de>.
On 08.07.2011 10:50, Mark Thomas wrote:
> On 08/07/2011 09:47, Rainer Jung wrote:
>> No without wild guessing:
>>
>> AjpProcessor.recycle() now nulls input. On the next loop through
>> processing the connection, trying to read from the nulled input will
>> lead to an NPE, producing the 400 log entry.
>>
>> In 7.0.16 recycle was implemented in AbstractAjpProcessor.java and did
>> not null input.
>
> Looks like another refactoring problem. I'll take a look.
Index: java/org/apache/coyote/ajp/AjpProcessor.java
===================================================================
@@ -242,13 +242,6 @@
}
- @Override
- public void recycle() {
- super.recycle();
- input = null;
- output = null;
- }
-
// ----------------------------------------------------- ActionHook
Methods
might do it. recycle() is only called once and at that place we don't
want to null input (and output) except we break out from the loop.
Directly below the loop we null input and output, except when we still
need it. At least my interpretation of the code.
The change fixes the issue, but I didn't extensively test it.
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Blank extra access log entries with AJP connector in 7.0.18
Posted by Mark Thomas <ma...@apache.org>.
On 08/07/2011 09:47, Rainer Jung wrote:
> No without wild guessing:
>
> AjpProcessor.recycle() now nulls input. On the next loop through
> processing the connection, trying to read from the nulled input will
> lead to an NPE, producing the 400 log entry.
>
> In 7.0.16 recycle was implemented in AbstractAjpProcessor.java and did
> not null input.
Looks like another refactoring problem. I'll take a look.
Mark
>
> Regards,
>
> Rainer
>
> On 08.07.2011 05:41, Konstantin Kolinko wrote:
>> Running 7.0.18 behind Apache HTTPD,
>> using Ajp connector (Bio),
>>
>> for every actual request there are two records in the access log,
>> one "true" record, followed by a blank one.
>>
>> E.g.:
>> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET /manager/html
>> HTTP/1.1" 200 24854
>> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
>> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET
>> /manager/images/asf-logo.gif HTTP/1.1" 304 -
>> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
>> ipaddress - username [08/Jul/11:07:16:06 +0400] "GET
>> /manager/images/tomcat.gif HTTP/1.1" 304 -
>> ipaddress - - [08/июл/11:07:16:06 +0400] "-" 400 -
>>
>> These extra log entries are absent in Apache HTTPD logs.
>>
>>
>> This issue is specific to AJP. When I tested with HTTP x Bio/Nio/Apr
>> the logs were operating correctly.
>>
>> It is not pretty, but it does not look like a show stopper.
>>
>>
>> This issue is observed with 7.0.17 as well. I have not tested 7.0.16
>> in this configuration.
>>
>> Best regards,
>> Konstantin Kolinko
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: dev-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Blank extra access log entries with AJP connector in 7.0.18
Posted by Rainer Jung <ra...@kippdata.de>.
No without wild guessing:
AjpProcessor.recycle() now nulls input. On the next loop through
processing the connection, trying to read from the nulled input will
lead to an NPE, producing the 400 log entry.
In 7.0.16 recycle was implemented in AbstractAjpProcessor.java and did
not null input.
Regards,
Rainer
On 08.07.2011 05:41, Konstantin Kolinko wrote:
> Running 7.0.18 behind Apache HTTPD,
> using Ajp connector (Bio),
>
> for every actual request there are two records in the access log,
> one "true" record, followed by a blank one.
>
> E.g.:
> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET /manager/html
> HTTP/1.1" 200 24854
> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET
> /manager/images/asf-logo.gif HTTP/1.1" 304 -
> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
> ipaddress - username [08/Jul/11:07:16:06 +0400] "GET
> /manager/images/tomcat.gif HTTP/1.1" 304 -
> ipaddress - - [08/июл/11:07:16:06 +0400] "-" 400 -
>
> These extra log entries are absent in Apache HTTPD logs.
>
>
> This issue is specific to AJP. When I tested with HTTP x Bio/Nio/Apr
> the logs were operating correctly.
>
> It is not pretty, but it does not look like a show stopper.
>
>
> This issue is observed with 7.0.17 as well. I have not tested 7.0.16
> in this configuration.
>
> Best regards,
> Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Blank extra access log entries with AJP connector in 7.0.18
Posted by Rainer Jung <ra...@kippdata.de>.
On 08.07.2011 09:18, Rainer Jung wrote:
> <wild-guess>
> Could it be the cping/cpong?
> </wild-guess>
Hmmm, doesn't make much sense, the additional line seems to be after the
original request.
Rainer
> On 08.07.2011 05:41, Konstantin Kolinko wrote:
>> Running 7.0.18 behind Apache HTTPD,
>> using Ajp connector (Bio),
>>
>> for every actual request there are two records in the access log,
>> one "true" record, followed by a blank one.
>>
>> E.g.:
>> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET /manager/html
>> HTTP/1.1" 200 24854
>> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
>> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET
>> /manager/images/asf-logo.gif HTTP/1.1" 304 -
>> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
>> ipaddress - username [08/Jul/11:07:16:06 +0400] "GET
>> /manager/images/tomcat.gif HTTP/1.1" 304 -
>> ipaddress - - [08/июл/11:07:16:06 +0400] "-" 400 -
>>
>> These extra log entries are absent in Apache HTTPD logs.
>>
>>
>> This issue is specific to AJP. When I tested with HTTP x Bio/Nio/Apr
>> the logs were operating correctly.
>>
>> It is not pretty, but it does not look like a show stopper.
>>
>>
>> This issue is observed with 7.0.17 as well. I have not tested 7.0.16
>> in this configuration.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Blank extra access log entries with AJP connector in 7.0.18
Posted by Rainer Jung <ra...@kippdata.de>.
<wild-guess>
Could it be the cping/cpong?
</wild-guess>
On 08.07.2011 05:41, Konstantin Kolinko wrote:
> Running 7.0.18 behind Apache HTTPD,
> using Ajp connector (Bio),
>
> for every actual request there are two records in the access log,
> one "true" record, followed by a blank one.
>
> E.g.:
> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET /manager/html
> HTTP/1.1" 200 24854
> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
> ipaddress - username [08/Jul/11:07:16:05 +0400] "GET
> /manager/images/asf-logo.gif HTTP/1.1" 304 -
> ipaddress - - [08/июл/11:07:16:05 +0400] "-" 400 -
> ipaddress - username [08/Jul/11:07:16:06 +0400] "GET
> /manager/images/tomcat.gif HTTP/1.1" 304 -
> ipaddress - - [08/июл/11:07:16:06 +0400] "-" 400 -
>
> These extra log entries are absent in Apache HTTPD logs.
>
>
> This issue is specific to AJP. When I tested with HTTP x Bio/Nio/Apr
> the logs were operating correctly.
>
> It is not pretty, but it does not look like a show stopper.
>
>
> This issue is observed with 7.0.17 as well. I have not tested 7.0.16
> in this configuration.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org