You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by "Owens, Stephen (ITD)" <st...@state.ma.us> on 2015/03/05 20:59:08 UTC
Question on Http11AprProcessor Error parsing HTTP request header
error messages
Hi,
I'm testing Tomcat 8.0.20 on Red Hat Enterprise Linux Server release 6.6.
Tomcat 8.0.20 was compiled with jdk1.8.0_31, openssl-1.0.2, apr-1.5.1, and apr-util-1.5.4.
The relevant portions of the server.xml file are:
<Server port="-1">
...
<!--APR library loader. Documentation at /docs/apr.html -->
...
<Service name="Catalina">
<Executor name="tomcatThreadPool" namePrefix="catalina-exec-" maxThreads="150" minSpareThreads="4"/>
...
<Connector port="50880" protocol="org.apache.coyote.http11.Http11AprProtocol"
scheme="http"
secure="false"
connectionTimeout="3600000"
maxHttpHeaderSize="32768"
enableLookups="false"
redirectPort="50881" />
...
<Connector port="50881" protocol="org.apache.coyote.http11.Http11AprProtocol"
maxThreads="200" scheme="https" secure="true"
connectionTimeout="3600000"
maxHttpHeaderSize="32768"
enableLookups="false"
SSLEnabled="true"
SSLProtocol="TLSv1.2"
SSLCertificateFile="${catalina.home}/keys/xxx"
SSLCertificateKeyFile="${catalina.home}/keys/xxx"
SSLCipherSuite="TLSv1.2:!aNULL:!eNULL:+RSA:+aDH"
SSLVerifyClient="none"
SSLHonorCipherOrder="true" />
...
<Engine name="Catalina" defaultHost="localhost">
...
<Host name="localhost" appBase="webapps" unpackWARs="false" autoDeploy="false">
...
</Host>
</Engine>
</Service>
</Server>
Tomcat was run under the jsvc daemon process with the below options
export JAVA_HOME="/app/java"
export CATALINA_HOME="/app/tomcat"
export OPENSSL_CONF="${CATALINA_HOME}/etc/ssl/openssl.cnf"
export CATALINA_BASE="${CATALINA_HOME}"
export CATALINA_OUT="${CATALINA_BASE}/logs/catalina.out"
export CATALINA_TMP="${CATALINA_BASE}/temp"
export CATALINA_ERR="${CATALINA_BASE}/logs/catalina.err"
export JAVA_OPTS="-Xms1g -Xmx1g -XX:+HeapDumpOnOutOfMemoryError -XX:-UsePerfData -DLog4j.debug=true"
export CATALINA_PID="${CATALINA_BASE}/logs/tomcat.pid"
export LOGGING_CONFIG="-DLog4j.debug=true -Dlog4j.configuration=log4j.properties"
export LOGGING_MANAGER="-Dorg.apache.juli.logging.impl.Log4JLogger"
TOMCAT_USER="tomcat"
CLASSPATH=${CATALINA_HOME}/bin/commons-daemon.jar:\
${JAVA_HOME}/lib/tools.jar:\
${CATALINA_HOME}/bin/bootstrap.jar:\
${CATALINA_HOME}/bin/tomcat-juli.jar:\
${CATALINA_HOME}/lib/tomcat-juli-adapters.jar:\
${CATALINA_HOME}/lib/commons-logging-1.1.3.jar:\
${CATALINA_HOME}/lib/commons-logging-adapters-1.1.3.jar:\
${CATALINA_HOME}/lib/avalon-framework-4.1.5.jar:\
${CATALINA_HOME}/lib/logkit-1.0.1.jar:\
${CATALINA_HOME}/lib/log4j-1.2.17.jar:\
${CATALINA_HOME}/xsd:\
${CATALINA_HOME}/lib
${CATALINA_HOME}/bin/jsvc \
-java-home "${JAVA_HOME}" \
-jvm ${JVM} \
-cwd ${CATALINA_HOME}/bin \
-user ${TOMCAT_USER} \
-Dcatalina.home=${CATALINA_HOME} \
-Dcatalina.base=${CATALINA_BASE} \
-Djava.io.tmpdir=${CATALINA_TMP} \
${LOGGING_MANAGER} \
${LOGGING_CONFIG} \
-wait ${WAIT_TO_START} \
-pidfile ${CATALINA_PID} \
-outfile ${CATALINA_OUT} \
-errfile ${CATALINA_ERR} \
${JAVA_OPTS} \
${CATALINA_OPTS} \
-classpath ${CLASSPATH} \
-debug \
org.apache.catalina.startup.Bootstrap
The tomcat webapps directory has only the tomcat default applications
host-manager
manager
ROOT
The Tomcat server is using Log4j.
Excerpts from log4j.properties file are below:
log4j.rootLogger = DEBUG, CATALINA
# Define all the appenders
log4j.appender.CATALINA = org.apache.log4j.DailyRollingFileAppender
log4j.appender.CATALINA.File = ${catalina.base}/logs/catalina.log
log4j.appender.CATALINA.Append = true
log4j.appender.CATALINA.Encoding = UTF-8
# Roll-over the log once per day
log4j.appender.CATALINA.DatePattern = '.'yyyy-MM-dd'.log'
log4j.appender.CATALINA.layout = org.apache.log4j.PatternLayout
log4j.appender.CATALINA.layout.ConversionPattern = %d{ISO8601} [%t] %-5p %c- %m%n
...
# Configure which loggers log to which appenders
log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost] = DEBUG, LOCALHOST
log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager] = DEBUG, MANAGER
log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/host-manager] = DEBUG, HOST-MANAGER
log4j.logger.org.apache.catalina.session=INFO
log4j.logger.org.apache.catalina.loader=INFO
log4j.logger.org.apache.catalina.startup=INFO
log4j.logger.org.apache.catalina.util=INFO
log4j.logger.org.apache.catalina.connector=INFO
log4j.logger.org.apache.commons=INFO
log4j.logger.org.apache.jasper=INFO
log4j.logger.org.apache.tomcat.util=INFO
Using chrome Version 41.0.2272.76 m, I connected to the default tomcat web app and in the logs (the request-dumper filter is setup in web.xml) I see:
2015-03-05 13:41:20,412 [http-apr-50881-exec-10] DEBUG org.apache.coyote.http11.Http11AprProtocol- Socket: [org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@451eda77:43325392], Status in: [OPEN_READ], State out: [CLOSED]
2015-03-05 13:41:20,560 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 START TIME =05-Mar-2015 13:41:20
2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 requestURI=/
2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 authType=null
2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 characterEncoding=null
2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contentLength=-1
2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contentType=null
2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contextPath=
2015-03-05 13:41:20,565 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 cookie=_ga=GA1.3.1837063901.1395922286
2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=host=xxx:50881
2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=connection=keep-alive
2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=accept=text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=user-agent=Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.76 Safari/537.36
2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=accept-encoding=gzip, deflate, sdch
2015-03-05 13:41:20,572 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=accept-language=en-US,en;q=0.8
2015-03-05 13:41:20,572 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=cookie=_ga=GA1.3.1837063901.1395922286
2015-03-05 13:41:20,575 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 locale=en_US
2015-03-05 13:41:20,575 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 method=GET
2015-03-05 13:41:20,576 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 pathInfo=null
2015-03-05 13:41:20,576 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 protocol=HTTP/1.1
2015-03-05 13:41:20,576 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 queryString=null
2015-03-05 13:41:20,580 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteAddr=xxx
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteHost=xxx
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteUser=null
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 requestedSessionId=null
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 scheme=https
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 serverName=xxx
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 serverPort=50881
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 servletPath=/index.jsp
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 isSecure=true
2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 ------------------=--------------------------------------------
2015-03-05 13:41:20,768 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 ------------------=--------------------------------------------
2015-03-05 13:41:20,768 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 authType=null
2015-03-05 13:41:20,768 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contentType=text/html;charset=UTF-8
2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteUser=null
2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 status=200
2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 END TIME =05-Mar-2015 13:41:20
2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 ===============================================================
2015-03-05 13:41:20,781 [http-apr-50881-exec-8] DEBUG org.apache.coyote.http11.Http11AprProtocol- Socket: [org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@1ce9af7:41253648], Status in: [OPEN_READ], State out: [OPEN]
2015-03-05 13:41:20,977 [http-apr-50881-exec-6] DEBUG org.apache.coyote.http11.Http11AprProcessor- Error parsing HTTP request header
java.io.EOFException: Unexpected EOF read on the socket
at org.apache.coyote.http11.InternalAprInputBuffer.parseRequestLine(InternalAprInputBuffer.java:141)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1000)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:659)
at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:285)
at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2376)
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)
2015-03-05 13:41:20,977 [http-apr-50881-exec-6] DEBUG org.apache.coyote.http11.Http11AprProtocol- Socket: [org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@3ef766eb:37493472], Status in: [OPEN_READ], State out: [CLOSED]
Are the DEBUG org.apache.coyote.http11.Http11AprProcessor- Error parsing HTTP request header signs of a problem or just messages popping up because the log4j level is DEBUG?
Thanks,
Stephen R. Owens
Senior Software Engineer
Massachusetts Office of Information Technology
Commonwealth of Massachusetts
One Ashburton Place, Room 1601
Boston, MA 02108
Tel: 617-626-4513
Email: Stephen.Owens@state.ma.us<ma...@state.ma.us>
Re: Question on Http11AprProcessor Error parsing HTTP request header
error messages
Posted by André Warnier <aw...@ice-sa.com>.
Owens, Stephen (ITD) wrote:
> Hi,
>
> I'm testing Tomcat 8.0.20 on Red Hat Enterprise Linux Server release 6.6.
> Tomcat 8.0.20 was compiled with jdk1.8.0_31, openssl-1.0.2, apr-1.5.1, and apr-util-1.5.4.
>
> The relevant portions of the server.xml file are:
> <Server port="-1">
> ...
> <!--APR library loader. Documentation at /docs/apr.html -->
> ...
> <Service name="Catalina">
> <Executor name="tomcatThreadPool" namePrefix="catalina-exec-" maxThreads="150" minSpareThreads="4"/>
> ...
> <Connector port="50880" protocol="org.apache.coyote.http11.Http11AprProtocol"
> scheme="http"
> secure="false"
> connectionTimeout="3600000"
> maxHttpHeaderSize="32768"
> enableLookups="false"
> redirectPort="50881" />
> ...
> <Connector port="50881" protocol="org.apache.coyote.http11.Http11AprProtocol"
> maxThreads="200" scheme="https" secure="true"
> connectionTimeout="3600000"
> maxHttpHeaderSize="32768"
> enableLookups="false"
> SSLEnabled="true"
> SSLProtocol="TLSv1.2"
> SSLCertificateFile="${catalina.home}/keys/xxx"
> SSLCertificateKeyFile="${catalina.home}/keys/xxx"
> SSLCipherSuite="TLSv1.2:!aNULL:!eNULL:+RSA:+aDH"
> SSLVerifyClient="none"
> SSLHonorCipherOrder="true" />
> ...
> <Engine name="Catalina" defaultHost="localhost">
> ...
> <Host name="localhost" appBase="webapps" unpackWARs="false" autoDeploy="false">
> ...
> </Host>
> </Engine>
> </Service>
> </Server>
>
> Tomcat was run under the jsvc daemon process with the below options
> export JAVA_HOME="/app/java"
> export CATALINA_HOME="/app/tomcat"
> export OPENSSL_CONF="${CATALINA_HOME}/etc/ssl/openssl.cnf"
> export CATALINA_BASE="${CATALINA_HOME}"
> export CATALINA_OUT="${CATALINA_BASE}/logs/catalina.out"
> export CATALINA_TMP="${CATALINA_BASE}/temp"
> export CATALINA_ERR="${CATALINA_BASE}/logs/catalina.err"
> export JAVA_OPTS="-Xms1g -Xmx1g -XX:+HeapDumpOnOutOfMemoryError -XX:-UsePerfData -DLog4j.debug=true"
> export CATALINA_PID="${CATALINA_BASE}/logs/tomcat.pid"
> export LOGGING_CONFIG="-DLog4j.debug=true -Dlog4j.configuration=log4j.properties"
> export LOGGING_MANAGER="-Dorg.apache.juli.logging.impl.Log4JLogger"
> TOMCAT_USER="tomcat"
>
> CLASSPATH=${CATALINA_HOME}/bin/commons-daemon.jar:\
> ${JAVA_HOME}/lib/tools.jar:\
> ${CATALINA_HOME}/bin/bootstrap.jar:\
> ${CATALINA_HOME}/bin/tomcat-juli.jar:\
> ${CATALINA_HOME}/lib/tomcat-juli-adapters.jar:\
> ${CATALINA_HOME}/lib/commons-logging-1.1.3.jar:\
> ${CATALINA_HOME}/lib/commons-logging-adapters-1.1.3.jar:\
> ${CATALINA_HOME}/lib/avalon-framework-4.1.5.jar:\
> ${CATALINA_HOME}/lib/logkit-1.0.1.jar:\
> ${CATALINA_HOME}/lib/log4j-1.2.17.jar:\
> ${CATALINA_HOME}/xsd:\
> ${CATALINA_HOME}/lib
>
> ${CATALINA_HOME}/bin/jsvc \
> -java-home "${JAVA_HOME}" \
> -jvm ${JVM} \
> -cwd ${CATALINA_HOME}/bin \
> -user ${TOMCAT_USER} \
> -Dcatalina.home=${CATALINA_HOME} \
> -Dcatalina.base=${CATALINA_BASE} \
> -Djava.io.tmpdir=${CATALINA_TMP} \
> ${LOGGING_MANAGER} \
> ${LOGGING_CONFIG} \
> -wait ${WAIT_TO_START} \
> -pidfile ${CATALINA_PID} \
> -outfile ${CATALINA_OUT} \
> -errfile ${CATALINA_ERR} \
> ${JAVA_OPTS} \
> ${CATALINA_OPTS} \
> -classpath ${CLASSPATH} \
> -debug \
> org.apache.catalina.startup.Bootstrap
>
> The tomcat webapps directory has only the tomcat default applications
> host-manager
> manager
> ROOT
>
> The Tomcat server is using Log4j.
> Excerpts from log4j.properties file are below:
> log4j.rootLogger = DEBUG, CATALINA
>
> # Define all the appenders
> log4j.appender.CATALINA = org.apache.log4j.DailyRollingFileAppender
> log4j.appender.CATALINA.File = ${catalina.base}/logs/catalina.log
> log4j.appender.CATALINA.Append = true
> log4j.appender.CATALINA.Encoding = UTF-8
> # Roll-over the log once per day
> log4j.appender.CATALINA.DatePattern = '.'yyyy-MM-dd'.log'
> log4j.appender.CATALINA.layout = org.apache.log4j.PatternLayout
> log4j.appender.CATALINA.layout.ConversionPattern = %d{ISO8601} [%t] %-5p %c- %m%n
> ...
> # Configure which loggers log to which appenders
> log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost] = DEBUG, LOCALHOST
> log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager] = DEBUG, MANAGER
> log4j.logger.org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/host-manager] = DEBUG, HOST-MANAGER
>
> log4j.logger.org.apache.catalina.session=INFO
> log4j.logger.org.apache.catalina.loader=INFO
> log4j.logger.org.apache.catalina.startup=INFO
> log4j.logger.org.apache.catalina.util=INFO
> log4j.logger.org.apache.catalina.connector=INFO
> log4j.logger.org.apache.commons=INFO
> log4j.logger.org.apache.jasper=INFO
> log4j.logger.org.apache.tomcat.util=INFO
>
>
>
> Using chrome Version 41.0.2272.76 m, I connected to the default tomcat web app and in the logs (the request-dumper filter is setup in web.xml) I see:
> 2015-03-05 13:41:20,412 [http-apr-50881-exec-10] DEBUG org.apache.coyote.http11.Http11AprProtocol- Socket: [org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@451eda77:43325392], Status in: [OPEN_READ], State out: [CLOSED]
> 2015-03-05 13:41:20,560 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 START TIME =05-Mar-2015 13:41:20
> 2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 requestURI=/
> 2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 authType=null
> 2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 characterEncoding=null
> 2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contentLength=-1
> 2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contentType=null
> 2015-03-05 13:41:20,562 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contextPath=
> 2015-03-05 13:41:20,565 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 cookie=_ga=GA1.3.1837063901.1395922286
> 2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=host=xxx:50881
> 2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=connection=keep-alive
> 2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=accept=text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
> 2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=user-agent=Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.76 Safari/537.36
> 2015-03-05 13:41:20,569 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=accept-encoding=gzip, deflate, sdch
> 2015-03-05 13:41:20,572 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=accept-language=en-US,en;q=0.8
> 2015-03-05 13:41:20,572 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 header=cookie=_ga=GA1.3.1837063901.1395922286
> 2015-03-05 13:41:20,575 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 locale=en_US
> 2015-03-05 13:41:20,575 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 method=GET
> 2015-03-05 13:41:20,576 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 pathInfo=null
> 2015-03-05 13:41:20,576 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 protocol=HTTP/1.1
> 2015-03-05 13:41:20,576 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 queryString=null
> 2015-03-05 13:41:20,580 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteAddr=xxx
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteHost=xxx
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteUser=null
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 requestedSessionId=null
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 scheme=https
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 serverName=xxx
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 serverPort=50881
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 servletPath=/index.jsp
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 isSecure=true
> 2015-03-05 13:41:20,583 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 ------------------=--------------------------------------------
> 2015-03-05 13:41:20,768 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 ------------------=--------------------------------------------
> 2015-03-05 13:41:20,768 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 authType=null
> 2015-03-05 13:41:20,768 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 contentType=text/html;charset=UTF-8
> 2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 remoteUser=null
> 2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 status=200
> 2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 END TIME =05-Mar-2015 13:41:20
> 2015-03-05 13:41:20,769 [http-apr-50881-exec-8] INFO org.apache.catalina.filters.RequestDumperFilter- http-apr-50881-exec-8 ===============================================================
> 2015-03-05 13:41:20,781 [http-apr-50881-exec-8] DEBUG org.apache.coyote.http11.Http11AprProtocol- Socket: [org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@1ce9af7:41253648], Status in: [OPEN_READ], State out: [OPEN]
> 2015-03-05 13:41:20,977 [http-apr-50881-exec-6] DEBUG org.apache.coyote.http11.Http11AprProcessor- Error parsing HTTP request header
> java.io.EOFException: Unexpected EOF read on the socket
> at org.apache.coyote.http11.InternalAprInputBuffer.parseRequestLine(InternalAprInputBuffer.java:141)
> at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1000)
> at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:659)
> at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:285)
> at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:2376)
> 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)
> 2015-03-05 13:41:20,977 [http-apr-50881-exec-6] DEBUG org.apache.coyote.http11.Http11AprProtocol- Socket: [org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@3ef766eb:37493472], Status in: [OPEN_READ], State out: [CLOSED]
>
> Are the DEBUG org.apache.coyote.http11.Http11AprProcessor- Error parsing HTTP request header signs of a problem or just messages popping up because the log4j level is DEBUG?
>
If it happened once, the latter.
If it happens all the time, you may want to investigate why the client(s) is/are sending
incomplete requests.
And thanks for the very complete info.
This being said, it is not usual nor recommended to run with a loglevel DEBUG unless you
are trying to track down some real issue.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: Question on Http11AprProcessor Error parsing HTTP request
header error messages
Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: Owens, Stephen (ITD) [mailto:stephen.owens@state.ma.us]
> Subject: Question on Http11AprProcessor Error parsing HTTP request header error messages
> 2015-03-05 13:41:20,977 [http-apr-50881-exec-6] DEBUG org.apache.coyote.http11.Http11AprProcessor-
> Error parsing HTTP request header
> java.io.EOFException: Unexpected EOF read on the socket
> at org.apache.coyote.http11.InternalAprInputBuffer.parseRequestLine(InternalAprInputBuffer.java:141)
> at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1000)
> Are the DEBUG org.apache.coyote.http11.Http11AprProcessor- Error parsing HTTP request header signs
> of a problem or just messages popping up because the log4j level is DEBUG?
Just because of the log level. The relevant code in AbstractHttp11Processor is this:
} catch (IOException e) {
if (getLog().isDebugEnabled()) {
getLog().debug(
sm.getString("http11processor.header.parse"), e);
}
setErrorState(ErrorState.CLOSE_NOW, e);
break;
}
If the log level were not DEBUG, the EOF would have been silently swallowed. It's unfortunate that the message says "Unexpected EOF" since in this case it's normal.
- Chuck
THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org