NullPointerException in RequestLogCollection Jetty 9.3.9

Question

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?

Sure the code is here - https://github.com/adamretter/exist/blob/jetty-9/src/org/exist/jetty/JettyStart.java#L190 — adamretter, Jun 19 '16 at 21:31
The list of jetty config files to load is read from here - https://github.com/adamretter/exist/blob/jetty-9/tools/jetty/etc/enabled-jetty-config and the actual config file which configures `RequestLog` is here - https://github.com/adamretter/exist/blob/jetty-9/tools/jetty/etc/jetty-requestlog.xml — adamretter, Jun 20 '16 at 21:54

score 0 · Accepted Answer · edited May 23 '17 at 12:22

0

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.

edited May 23 '17 at 12:22

Community

1
1

answered Jun 20 '16 at 22:05

Joakim Erdfelt

46,896
7
86
136

I appreciate what you are saying, but jetty-distribution does not really fit our project need. jetty-embedded is much closer to what we need, however I really like the idea of the modular XML config, as it allows our users to reconfigure jetty just how they like it. Perhaps however I should ditch modular and just have a single XML file with all the config in? – adamretter Jun 20 '16 at 22:36
If I change the order to that that you suggest then I get problems with both jetty-jaas.xml and jetty-gzip.xml. `java.lang.IllegalStateException: No LoginService for org.eclipse.jetty.security.authentication.FormAuthenticator@57545c3f in org.eclipse.jetty.security.ConstraintSecurityHandler@58fa5769 at org.eclipse.jetty.security.authentication.LoginAuthenticator.setConfiguration(LoginAuthenticator.java:76)` and `java.lang.ClassCastException: org.eclipse.jetty.server.handler.gzip.GzipHandler cannot be cast to org.eclipse.jetty.server.handler.HandlerCollection` – adamretter Jun 20 '16 at 22:37
You have 2 new questions then. (BTW, Your hybrid approach is what's causing you problems. Your `embedded-jetty` is making assumptions that your `jetty-distribution` based XMLs don't conform to) – Joakim Erdfelt Jun 20 '16 at 23:40
So are you agreeing that my only reasonable option then when using jetty-embedded and wanting an external config file, is to just go for a single XML config file, with all the stuff in it? – adamretter Jun 21 '16 at 13:23
The decision between single vs multiple XMLs is irrelevant (both choices are equally as valid). The decision should be about control, consistency, and understanding the nature of the setup between your XML and the code you have after the XML setup in your embedded-jetty logic (right now, you are just tossing jetty-distribution XML at it, not understanding the XML requirements, what the XML is actually doing, and getting frustrated that the embedded-jetty side isn't working) – Joakim Erdfelt Jun 21 '16 at 14:30
There is a reason that jetty itself doesn't read/walk/modify the Jetty Server instance it creates via its jetty-distribution XML and XmlConfiguration. Its complicated to get right, and you'll wind up creating more lines of code just to interrogate the created Server properly, vs just defining the server directly in embedded-jetty (see [LikeJettyXml example](https://github.com/eclipse/jetty.project/blob/jetty-9.3.x/examples/embedded/src/main/java/org/eclipse/jetty/embedded/LikeJettyXml.java)) – Joakim Erdfelt Jun 21 '16 at 14:34
Joakim, if you check you will see my XML files have some small changes from the Jetty distribution. I want embedded-jetty and an external config file, so that my application users can tweak jetty settings... so what do you suggest? Hardcoding the jetty config in Java is really not a reasonable answer for this project. – adamretter Jun 21 '16 at 16:19
You also provide an embedded-jetty example configured from a single XML file in the Jetty GitHub - https://github.com/eclipse/jetty.project/blob/jetty-9.3.x/examples/embedded/src/main/java/org/eclipse/jetty/embedded/ExampleServerXml.java So what is wrong with using a single XML file then if you are promoting that? – adamretter Jun 21 '16 at 16:22
I don't feel like I have a definitive answer that resolves my question or that really any progress has been made on the technical issue, I do appreciate the comments on the architecture but sometimes not all square pegs can be forced into round holes. I don't want to award the bounty for this answer as it is incomplete, however I may disappointingly accept it as the best I have received so far. – adamretter Jun 24 '16 at 22:44
Ask more questions. the `ClassCastException` and `ISE: No LoginService` are separate issues, both related to how your XML and embedded-jetty are interacting with each other. The desire for flexible configuration means you have a lot of work ahead of you in your embedded-jetty to compensate for every possible variable that can be accomplished in the XML. – Joakim Erdfelt Jun 24 '16 at 22:49
Okay thanks, I appreciate your comments on my code on GitHub too. Seems only fair that you get the bounty after that work. – adamretter Jun 25 '16 at 00:27

NullPointerException in RequestLogCollection Jetty 9.3.9

1 Answers1