Summary: | Bogus access log entries with status 503 and date in year 1970 (the epoch) when pausing NIO connector | ||
---|---|---|---|
Product: | Tomcat 8 | Reporter: | Konstantin Kolinko <knst.kolinko> |
Component: | Catalina | Assignee: | Tomcat Developers Mailing List <dev> |
Status: | RESOLVED FIXED | ||
Severity: | minor | ||
Priority: | P2 | ||
Version: | 8.0.8 | ||
Target Milestone: | ---- | ||
Hardware: | PC | ||
OS: | All | ||
Attachments: |
2014-06-13_tc8_56620_debug.patch
access_log.2014-06-13 TEST-org.apache.jasper.compiler.TestGenerator.NIO.txt |
Description
Konstantin Kolinko
2014-06-13 12:37:17 UTC
Created attachment 31711 [details]
2014-06-13_tc8_56620_debug.patch
Debug logging statement for AbstractAccessLogValve, as mentioned in description.
Not for production.
Created attachment 31712 [details]
access_log.2014-06-13
Access log file from the test run, demonstrating the issue
Created attachment 31713 [details]
TEST-org.apache.jasper.compiler.TestGenerator.NIO.txt
Test log file from the test run, demonstrating the issue
Testing org.apache.coyote.http11.TestInternalInputBuffer + test.accesslog=true Its "testNewLinesExcessive" test generates an error 400 entry with bogus date. 127.0.0.1 - - [01/Jan/1970:02:59:59 +0300] "-" 400 - null 0 I was just about to close this when you posted the additional issue. I've modified the fix so it is more general and should fix all cases of request start times back in the 1970's. This is fixed in 8.0.x for 8.0.9 onwards and in 7.0.x for 7.0.55 onwards. Looks good. For a record: Processing time for HTTP connectors is now measured starting from when the first byte of the next request is read. (r1602956) The old implementation measured it starting from when the whole HTTP request line was read. I think the new implementation is the correct one. I am just noting it here, as sometimes people ask on the users mailing list about how the timing is measured. In any case I expect that for usual requests the difference between the two implementations is rather small. |