Friday, June 24, 2016

NullPointerException in RequestLogCollection Jetty 9.3.9

Leave a Comment

I am using Jetty 9.3.9.v20160517 in my embedded application, and I have configured the logging using jetty-requestlog.xml like so:

<?xml version="1.0"?> <!DOCTYPE Configure PUBLIC "-//Jetty//Configure//EN" "http://www.eclipse.org/jetty/configure_9_3.dtd">  <!-- =============================================================== --> <!-- Configure the Jetty Request Log                                 --> <!-- =============================================================== --> <Configure id="Server" class="org.eclipse.jetty.server.Server">    <!-- =========================================================== -->   <!-- Configure Request Log for Server                            -->   <!-- (Use RequestLogHandler for a context specific RequestLog    -->   <!-- =========================================================== -->   <Set name="RequestLog">     <New id="RequestLog" class="org.eclipse.jetty.server.AsyncNCSARequestLog">       <Set name="filename"><Property name="jetty.base" default="." /><Property>           <Name>jetty.requestlog.filePath</Name>           <Deprecated>requestlog.filename</Deprecated>           <Default><Property name="jetty.requestlog.dir" default="/logs"/>/yyyy_mm_dd.request.log</Default>         </Property>       </Set>       <Set name="filenameDateFormat"><Property name="jetty.requestlog.filenameDateFormat" deprecated="requestlog.filenameDateFormat" default="yyyy_MM_dd"/></Set>       <Set name="retainDays"><Property name="jetty.requestlog.retainDays" deprecated="requestlog.retain" default="90"/></Set>       <Set name="append"><Property name="jetty.requestlog.append" deprecated="requestlog.append" default="true"/></Set>       <Set name="extended"><Property name="jetty.requestlog.extended" deprecated="requestlog.extended" default="false"/></Set>       <Set name="logCookies"><Property name="jetty.requestlog.cookies" deprecated="requestlog.cookies" default="false"/></Set>       <Set name="LogTimeZone"><Property name="jetty.requestlog.timezone" deprecated="requestlog.timezone" default="GMT"/></Set>     </New>   </Set> </Configure> 

However, at runtime when Jetty actually tries to log anything I get the following NPE each time I make a request to the server, even though the logs do seem to be written to $jetty.base/logs/2016_06_15.request.log.

2016-06-15 22:19:23,302 [eXistThread-29] WARN  (HttpChannel.java [handle]:479) - //localhost:8080/exist/apps/dashboard/modules/get-icon.xql?package=http://exist-db.org/apps/eXide  java.lang.NullPointerException     at org.eclipse.jetty.server.RequestLogCollection.log(RequestLogCollection.java:44) ~[jetty-server-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:620) ~[jetty-server-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:453) [jetty-server-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:253) [jetty-server-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [jetty-io-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [jetty-io-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [jetty-io-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [jetty-util-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [jetty-util-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [jetty-util-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [jetty-util-9.3.9.v20160517.jar:9.3.9.v20160517]     at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [jetty-util-9.3.9.v20160517.jar:9.3.9.v20160517]     at java.lang.Thread.run(Thread.java:745) [?:1.8.0_92] 

So... What is causing these NPE's and how do I fix them please?

1 Answers

Answers 1

Your XML load order is bad (see etc/enabled-jetty-config in your source)

I mentioned this in an earlier answer.

Here's a way you can see how this order works.

Use the jetty-distribution :-)

# Use a new empty base $ cd /path/to/mybase  # Lets add the modules into this base $ java -jar /path/to/jetty-dist/start.jar --add-to-start=annotations,deploy,https,gzip,jmx,requestlog INFO: server          initialised (transitively) in ${jetty.base}/start.ini INFO: gzip            initialised in ${jetty.base}/start.ini INFO: jmx             initialised in ${jetty.base}/start.ini INFO: requestlog      initialised in ${jetty.base}/start.ini INFO: ssl             initialised (transitively) in ${jetty.base}/start.ini INFO: https           initialised in ${jetty.base}/start.ini INFO: deploy          initialised in ${jetty.base}/start.ini INFO: annotations     initialised in ${jetty.base}/start.ini MKDIR: ${jetty.base}/logs DOWNLOAD: https://raw.githubusercontent.com/eclipse/jetty.project/master/jetty-server/src/test/config/etc/keystore?id=master to ${jetty.base}/etc/keystore MKDIR: ${jetty.base}/webapps INFO: Base directory was modified  # Lets ask the jetty-distribution what its XML load order is java -jar /path/to/jetty-dist/start.jar --list-config ...(snip lots of output)... Jetty Active XMLs: ------------------  ${jetty.home}/etc/jetty.xml  ${jetty.home}/etc/jetty-gzip.xml  ${jetty.home}/etc/jetty-jmx.xml  ${jetty.home}/etc/jetty-requestlog.xml  ${jetty.home}/etc/jetty-ssl.xml  ${jetty.home}/etc/jetty-ssl-context.xml  ${jetty.home}/etc/jetty-https.xml  ${jetty.home}/etc/jetty-deploy.xml  ${jetty.home}/etc/jetty-plus.xml  ${jetty.home}/etc/jetty-annotations.xml 

Note: this load order can (and does!) change between releases of Jetty. Don't rely on this being the one true load order for all versions of Jetty going forward. You'll either have to implement the same start.jar module logic, or redo this jetty-distribution/start.jar --list-config with each upgrade of your project.

WARNING: Don't do this, don't mix jetty-distribution and embedded-jetty, you are just creating lots of extra work for yourself, increasing your maintenance tasks, etc. Use embedded-jetty *or* jetty-distribution directly.

If You Enjoyed This, Take 5 Seconds To Share It

0 comments:

Post a Comment