You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Robert Tupelo-Schneck <sc...@cnri.reston.va.us> on 2015/08/19 17:21:27 UTC
Errors at INFO level despite "Note: further occurrences of ... errors will be logged at DEBUG level."
I'm running Tomcat 8.0.24. I see lots of errors in catalina.out with lines like
Note: further occurrences of Cookie errors will be logged at DEBUG level.
Note: further occurrences of Parameter errors will be logged at DEBUG level.
Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
But, the errors keep showing up at INFO level!
I get these many many times a day, but I do not get user complaints, and I have not been able to cause the errors myself.
I would like to either
(1) Make these errors go away (such as by really having them logged at DEBUG level), or
(2) Get detailed information on the client request that caused the error so I can figure out how to make them less frequent.
Can anyone advise on how I could accomplish either of those goals?
For completeness, here are the kinds of errors:
org.apache.tomcat.util.http.LegacyCookieProcessor.processCookieHeader Cookies: Invalid cookie. Value not a token or quoted value
org.apache.coyote.http11.AbstractHttp11Processor.process Error parsing HTTP request header
org.apache.tomcat.util.http.Parameters.processParameters Invalid chunk starting at byte [242] and ending at byte [244] with a value of [=1] ignored
I also see a lot of this one, at SEVERE level; I'd like to deal with it the same way as the others:
org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request
java.lang.IllegalArgumentException: Control character in cookie value or attribute.
Thanks,
Robert
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Errors at INFO level despite "Note: further occurrences of ... errors will be logged at DEBUG level."
Posted by Robert Tupelo-Schneck <sc...@cnri.reston.va.us>.
Thanks. I will investigate the logging and cookie processor configuration.
The SEVERE cookie error does come with a stack trace:
17-Aug-2015 01:13:23.051 SEVERE [catalina-exec-942] org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request
java.lang.IllegalArgumentException: Control character in cookie value or attribute.
at org.apache.tomcat.util.http.LegacyCookieProcessor.isHttpSeparator(LegacyCookieProcessor.java:732)
at org.apache.tomcat.util.http.LegacyCookieProcessor.getTokenEndPosition(LegacyCookieProcessor.java:714)
at org.apache.tomcat.util.http.LegacyCookieProcessor.processCookieHeader(LegacyCookieProcessor.java:554)
at org.apache.tomcat.util.http.LegacyCookieProcessor.parseCookieHeader(LegacyCookieProcessor.java:273)
at org.apache.catalina.connector.Request.parseCookies(Request.java:2949)
at org.apache.catalina.connector.Request.getServerCookies(Request.java:2004)
at org.apache.catalina.connector.CoyoteAdapter.parseSessionCookiesId(CoyoteAdapter.java:1205)
at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:916)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:513)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1527)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1484)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
I use an HTTP connector with default configuration (which I think for Tomcat 8 means NIO).
Robert
> On 2015-08-20, at 06:03, Konstantin Kolinko <kn...@gmail.com> wrote:
>
> 2015-08-19 18:21 GMT+03:00 Robert Tupelo-Schneck <sc...@cnri.reston.va.us>:
>> I'm running Tomcat 8.0.24. I see lots of errors in catalina.out with lines like
>>
>> Note: further occurrences of Cookie errors will be logged at DEBUG level.
>> Note: further occurrences of Parameter errors will be logged at DEBUG level.
>> Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
>>
>> But, the errors keep showing up at INFO level!
>>
>> I get these many many times a day, but I do not get user complaints, and I have not been able to cause the errors myself.
>>
>> I would like to either
>> (1) Make these errors go away (such as by really having them logged at DEBUG level), or
>> (2) Get detailed information on the client request that caused the error so I can figure out how to make them less frequent.
>
> 1. Both logging level and silencing interval are configurable with
> system properties. See properties with "UserDataHelper" in their name
> on the following page:
>
> http://tomcat.apache.org/tomcat-8.0-doc/config/systemprops.html#Logging
>
> By default suppression period is one day. For performance reasons,
> suppression period may be not effective immediately (so that several
> simultaneous messages can be logged at info level).
>
> 2. There is a way to match log message to a line in access log, by
> using id of the current thread.
>
> At the event logging side, org.apache.juli.OneLineFormatter does
> include thread name in its log message.
>
> At access logging side the AccessLogValve can be configured to log
> thread name (as well as some other detailed information).
>
> 3. If some more detailed information is needed, one need to change
> specific error messages (it is doable, if there is an interest in it,
> but it depends on whether additional information is available in those
> places).
>
>> Can anyone advise on how I could accomplish either of those goals?
>>
>> For completeness, here are the kinds of errors:
>>
>> org.apache.tomcat.util.http.LegacyCookieProcessor.processCookieHeader Cookies: Invalid cookie. Value not a token or quoted value
>
> Some client has a broken cookie, uses a broken browser. E.g. if a
> client is sending 8-bit characters where only 7-bit (aka US-ASCII) are
> allowed.
>
> It is possible to change cookie handling by configuring a different
> CookieProcessor,
> http://tomcat.apache.org/tomcat-8.0-doc/config/cookie-processor.html
>
>
> If client browser has a broken cookie, it will continue sending it
> until the cookie expires or cookies are cleared by user, or server
> sends set-cookie header that clears that cookie.
>
>> org.apache.coyote.http11.AbstractHttp11Processor.process Error parsing HTTP request header
>> org.apache.tomcat.util.http.Parameters.processParameters Invalid chunk starting at byte [242] and ending at byte [244] with a value of [=1] ignored
>>
>> I also see a lot of this one, at SEVERE level; I'd like to deal with it the same way as the others:
>>
>> org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request
>> java.lang.IllegalArgumentException: Control character in cookie value or attribute.
>
>
> No stacktrace here? It is odd for a cookie error to be popping up to
> a request processor.
>
> What is your connector configuration:
> protocol (HTTP / AJP),
> implementation (BIO / NIO / NIO2 / APR) ?
>
>
> BTW, Tomcat 8.0.26 is currently being tested and voted. You would like
> to test it, you can find details on dev@ mailing list.
>
> Best regards,
> Konstantin Kolinko
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Errors at INFO level despite "Note: further occurrences of ... errors will be logged at DEBUG level."
Posted by Robert Tupelo-Schneck <sc...@cnri.reston.va.us>.
> On 2015-08-20, at 06:03, Konstantin Kolinko <kn...@gmail.com> wrote:
> 2015-08-19 18:21 GMT+03:00 Robert Tupelo-Schneck <sc...@cnri.reston.va.us>:
>> I'm running Tomcat 8.0.24. I see lots of errors in catalina.out with lines like
>>
>> Note: further occurrences of Cookie errors will be logged at DEBUG level.
>> Note: further occurrences of Parameter errors will be logged at DEBUG level.
>> Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
>>
>> But, the errors keep showing up at INFO level!
>>
>> I get these many many times a day, but I do not get user complaints, and I have not been able to cause the errors myself.
>>
>> I would like to either
>> (1) Make these errors go away (such as by really having them logged at DEBUG level), or
>> (2) Get detailed information on the client request that caused the error so I can figure out how to make them less frequent.
>
> 1. Both logging level and silencing interval are configurable with
> system properties. See properties with "UserDataHelper" in their name
> on the following page:
>
> http://tomcat.apache.org/tomcat-8.0-doc/config/systemprops.html#Logging
[...]
> It is possible to change cookie handling by configuring a different
> CookieProcessor,
> http://tomcat.apache.org/tomcat-8.0-doc/config/cookie-processor.html
In case others experience similar issues, I wanted to record that what worked for me was to add this line to conf/catalina.properties:
org.apache.juli.logging.UserDataHelper.CONFIG=DEBUG_ALL
and this line to conf/context.xml:
<CookieProcessor className="org.apache.tomcat.util.http.Rfc6265CookieProcessor" />
Now my logs are free from these unwanted messages.
Thanks,
Robert
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Errors at INFO level despite "Note: further occurrences of ...
errors will be logged at DEBUG level."
Posted by Konstantin Kolinko <kn...@gmail.com>.
2015-08-19 18:21 GMT+03:00 Robert Tupelo-Schneck <sc...@cnri.reston.va.us>:
> I'm running Tomcat 8.0.24. I see lots of errors in catalina.out with lines like
>
> Note: further occurrences of Cookie errors will be logged at DEBUG level.
> Note: further occurrences of Parameter errors will be logged at DEBUG level.
> Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
>
> But, the errors keep showing up at INFO level!
>
> I get these many many times a day, but I do not get user complaints, and I have not been able to cause the errors myself.
>
> I would like to either
> (1) Make these errors go away (such as by really having them logged at DEBUG level), or
> (2) Get detailed information on the client request that caused the error so I can figure out how to make them less frequent.
1. Both logging level and silencing interval are configurable with
system properties. See properties with "UserDataHelper" in their name
on the following page:
http://tomcat.apache.org/tomcat-8.0-doc/config/systemprops.html#Logging
By default suppression period is one day. For performance reasons,
suppression period may be not effective immediately (so that several
simultaneous messages can be logged at info level).
2. There is a way to match log message to a line in access log, by
using id of the current thread.
At the event logging side, org.apache.juli.OneLineFormatter does
include thread name in its log message.
At access logging side the AccessLogValve can be configured to log
thread name (as well as some other detailed information).
3. If some more detailed information is needed, one need to change
specific error messages (it is doable, if there is an interest in it,
but it depends on whether additional information is available in those
places).
> Can anyone advise on how I could accomplish either of those goals?
>
> For completeness, here are the kinds of errors:
>
> org.apache.tomcat.util.http.LegacyCookieProcessor.processCookieHeader Cookies: Invalid cookie. Value not a token or quoted value
Some client has a broken cookie, uses a broken browser. E.g. if a
client is sending 8-bit characters where only 7-bit (aka US-ASCII) are
allowed.
It is possible to change cookie handling by configuring a different
CookieProcessor,
http://tomcat.apache.org/tomcat-8.0-doc/config/cookie-processor.html
If client browser has a broken cookie, it will continue sending it
until the cookie expires or cookies are cleared by user, or server
sends set-cookie header that clears that cookie.
> org.apache.coyote.http11.AbstractHttp11Processor.process Error parsing HTTP request header
> org.apache.tomcat.util.http.Parameters.processParameters Invalid chunk starting at byte [242] and ending at byte [244] with a value of [=1] ignored
>
> I also see a lot of this one, at SEVERE level; I'd like to deal with it the same way as the others:
>
> org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request
> java.lang.IllegalArgumentException: Control character in cookie value or attribute.
No stacktrace here? It is odd for a cookie error to be popping up to
a request processor.
What is your connector configuration:
protocol (HTTP / AJP),
implementation (BIO / NIO / NIO2 / APR) ?
BTW, Tomcat 8.0.26 is currently being tested and voted. You would like
to test it, you can find details on dev@ mailing list.
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org