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.ow...@state.ma.us<mailto:stephen.ow...@state.ma.us>
