ERROR : No module found to provide logback-impl for logback-access{enabled}

[chiralsoftware]

A fresh installation of Jetty 10.0.1:

$ wget --quiet https://repo1.maven.org/maven2/org/eclipse/jetty/jetty-home/10.0.1/jetty-home-10.0.1.tar.gz
$ md5sum jetty-home-10.0.1.tar.gz 
97d4dae7ca641d81852551251b58469a  jetty-home-10.0.1.tar.gz
$ tar xf jetty-home-10.0.1.tar.gz 
$ mkdir jetty-base
$ cd jetty-base/
$ java -jar ../jetty-home-10.0.1/start.jar --add-modules=server,http,logback-access
ERROR : No module found to provide logback-impl for logback-access{enabled}
....
$ echo ../jetty-home-10.0.1/modules/logback*
../jetty-home-10.0.1/modules/logback-access ../jetty-home-10.0.1/modules/logback-access.mod
$ cat ../jetty-home-10.0.1/modules/logback-access.mod
....
[depend]
server
logback-impl
resources

Any ideas on this? If logback-access is no longer supported it shouldn't be there, but if it is there, it seems like it needs a logback-impl module. It's possible I'm skipping a step somewhere but it seems like something is missing.

[janbartel]

@joakime any idea? Seems like logback-impl.mod was removed.

[joakime]

I'm surprised that we have a module for logback-access at all.

logback-access was created to provide a customizable output for RequestLog that is managed by slf4j.
This is an old-school concept that has been superseded by the built-in CustomRequestLog and Slf4jRequestLogWriter facilities in Jetty itself.

I'm not sure the old logback-access will even work on Jetty 10+.
It needs to be tested.

[joakime]

Opened PR #6002
It allows logback-access to be used now, but this exposed a curious transitive dependency quirk in start.jar that needs to be addressed in a different PR.

You can enable it with --add-module=logback-access, but only after you have --add-module=logging-logback enabled first.

[joakime]

Also of note, logback-access does not work with Jetty 10.

11:28:27.585 [WARN] :qtp1899223686-34: (org.eclipse.jetty.server.HttpChannel) - /foo
java.lang.NoSuchMethodError: 'org.eclipse.jetty.http.HttpFields org.eclipse.jetty.server.Response.getHttpFields()'
	at ch.qos.logback.access.jetty.JettyServerAdapter.buildResponseHeaderMap(JettyServerAdapter.java:60)
	at ch.qos.logback.access.spi.AccessEvent.buildResponseHeaderMap(AccessEvent.java:585)
	at ch.qos.logback.access.spi.AccessEvent.getResponseHeaderMap(AccessEvent.java:590)
	at ch.qos.logback.access.spi.AccessEvent.prepareForDeferredProcessing(AccessEvent.java:602)
	at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:223)
	at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
	at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:102)
	at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
	at ch.qos.logback.access.jetty.RequestLogImpl.log(RequestLogImpl.java:137)
	at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:857)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:379)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:284)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:319)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
	at org.eclipse.jetty.io.SocketChannelEndPoint$1.run(SocketChannelEndPoint.java:101)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:132)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:791)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:913)
	at java.base/java.lang.Thread.run(Thread.java:834)

[joakime]

I'm keen to just remove logback-access.mod entirely until such time when logback fixes that jar.

[joakime]

PR #6002 now just removes logback-access.mod entirely

[chiralsoftware]

So what's the recommended way to configure request logging in Jetty 10? Request logging is a critical feature for any production web server. If logback-access is no longer the way, maybe the documentation needs to be updated? It's very confusing to figure out what's the preferred way of access logging in Jetty 10.

[joakime]

The --add-module=requestlog is the first step.
That will create a ${jetty.base}/start.d/requestlog.ini
Then just run Jetty, that's the default request log behavior (see ${jetty.base}/logs/access.log).

If you want to customize the output, then you'll need set the format on the CustomRequestLog.
Edit the above ini, and customize the jetty.requestlog.formatString property.
See javadoc about the format here ...
https://www.eclipse.org/jetty/javadoc/jetty-10/org/eclipse/jetty/server/CustomRequestLog.html

If you want the request log to output to slf4j (so you can customize the rolling / etc), then you'll want to use the Slf4jRequestLogWriter at the named logger of your choice.

Create a ${jetty.base}/etc/jetty-requestlog.xml file with the following contents.

<?xml version="1.0"?>
<!DOCTYPE Configure PUBLIC "-//Jetty//Configure//EN" "https://www.eclipse.org/jetty/configure_10_0.dtd">

<Configure id="Server" class="org.eclipse.jetty.server.Server">

  <Set name="RequestLog">
    <New id="RequestLog" class="org.eclipse.jetty.server.CustomRequestLog">
      <!-- Writer -->
      <Arg>
        <New class="org.eclipse.jetty.server.Slf4jRequestLogWriter">
          <Arg>accesslog</Arg>
        </New>
      </Arg>

      <!-- Format String -->
      <Arg>
        <Property name="jetty.requestlog.formatString">
          <Default>
            <Get class="org.eclipse.jetty.server.CustomRequestLog" name="EXTENDED_NCSA_FORMAT"/>
          </Default>
        </Property>
      </Arg>
    </New>
  </Set>
</Configure>

This will output request log events to the logger named "accesslog".

From there you can use a tool like logback and it's ch.qos.logback.classic.sift.SiftingAppender configuration to split/slice the logging events based on logger names.
Regular logs to the normal location such as ${jetty.base}/logs/jetty.log, and "accesslog" named events to a special location such as ${jetty.base}/logs/access.log. (or both, it's up to you and your chosen configuration).
See http://logback.qos.ch/manual/loggingSeparation.html

[chiralsoftware]

Thanks Joakime, but that one isn't working. The constructor of Slf4jRequestLogWriter doesn't take any arguments. I ran it without an argument and it runs but doesn't write logs anywhere.

I changed it to:

  <!-- Writer -->
  <Arg>
    <New class="org.eclipse.jetty.server.RequestLogWriter">
      <Arg>/tmp/accesslog</Arg>
    </New>
  </Arg>

and now a log file show up in /tmp/accesslog as expected. This is major progress! Still would be nice to have features like log rotation. I'm looking into how to do that.

I also figured out how to get the application logging working. This is still using the logging-logback module, just as before.

I'm going to wipe out my configuration and re-install it from scratch to make sure I have it documented properly.

Maybe there should be a documentation bug on this whole situation, to give an easier setup for ordinary logging needs.

[lachlan-roberts]

@chiralsoftware you should not need to override the default jetty-requestlog.xml file unless you want some alternate configuration like using the Slf4jRequestLogWriter.

By enabling the requestlog module, it will set up a CustomRequestLog with an AsyncRequestLogWriter. The logs will be put in the directory $JETTY_BASE/logs directory by default.

java -jar ../jetty-home/start.jar --add-modules=requestlog
INFO  : requestlog      initialized in ${jetty.base}/start.d/requestlog.ini
INFO  : mkdir ${jetty.base}/logs
INFO  : Base directory was modified

Then you can further configure the settings in in your start.ini file or your start.d/requestlog.ini file.

## Format string
# jetty.requestlog.formatString=%a - %u %{dd/MMM/yyyy:HH:mm:ss ZZZ|GMT}t "%r" %s %B "%{Referer}i" "%{User-Agent}i" "%C"

## Logging directory (relative to $jetty.base)
# jetty.requestlog.dir=logs

## File path
# jetty.requestlog.filePath=${jetty.requestlog.dir}/yyyy_mm_dd.request.log

## Date format for rollovered files (uses SimpleDateFormat syntax)
# jetty.requestlog.filenameDateFormat=yyyy_MM_dd

## How many days to retain old log files
# jetty.requestlog.retainDays=90

## Whether to append to existing file
# jetty.requestlog.append=false

## Timezone of the log file rollover
# jetty.requestlog.timezone=GMT

This is described in the Jetty-9 documentation in the configuring-jetty-request-logs section. I don't think this section exists in the Jetty-10 documentation yet, which is still a work in progress and is being re-written.

[chiralsoftware]

Thanks Lachlan. I had that going before, but for a production system you almost always would want the logs to be in /var or some other directory. I guess I could symlink it. But it would be nice if it were a little more "works out of the box".

[lachlan-roberts]

@chiralsoftware if you want to use an absolute path for the logs like /var you will need to copy over the $JETTY_HOME/etc/jetty-requestlog.xml file and manually put the path in. Or you could only remove the <Property name="jetty.base" default="." />/ part which would make the existing jetty.requestlog.dir property work as the absolute path instead.

Maybe we could do something similar to what was done for the keystore path in issue #5689. This could introduce a new property to set the absolute path of the requestlog directory without having to override the xml file.

[chiralsoftware]

Thanks Lachlan. I fully support making it easy to have absolute paths. Log files usually live in /var/log, which is never inside JETTY_BASE. I will try your suggestion to move the modules over into JETTY_BASE.

[gregw]

@lachlan-roberts @chiralsoftware Does the module suggest we can set the directory of the log with properties???

## File path
# jetty.requestlog.filePath=${jetty.requestlog.dir}/yyyy_mm_dd.request.log

So can't the jetty.requestlog.dir property be set in an ini file to a directory in var, and thus avoid the need to copy/modify the XML? If we can't change logging directory without XML mods then we need to fix that.

I'm also -1 on removing support for logback-access

[joakime]

I'm also -1 on removing support for logback-access

logback-access is broken, the jar itself.
It hasn't been updated to support the changes for immutable/mutable HttpFields Jetty 10. (see stacktrace above)
Once a new version of logback-access exists with support for Jetty 10+ we can add it back.

[chiralsoftware]

@lachlan-roberts thank you for the suggestion. I just copied jetty-requestlog.xml into JETTY-BASE/etc and modified it like:

<New class="org.eclipse.jetty.server.AsyncRequestLogWriter">
          <Arg>/var/log/jetty/yyyy_mm_dd.request.log</Arg>

and it works as expected. That's nice! Maybe the documentation should mention that, or there should be an easy way to achieve it using the .ini file.

I will also see about the same thing for the keystore, as I also don't really want the keystore in JETTY_BASE.

[sbordet]

I will also see about the same thing for the keystore, as I also don't really want the keystore in JETTY_BASE.

We have introduced an absolute path for the KeyStore so it can now be saved anywhere in the file system.

[sbordet]

@lachlan-roberts can you introduce an absolute path for the log file path like we have done in jetty-ssl-context.xml?
May be open another issue to track that change.

[gregw]

@joakime oh! Well we broke it then, so I think we need to help them out with a PR to fix it.
Rather than remove it entirely, can we replace it with a module/xml that says it currently not available, but coming soon.

[lachlan-roberts]

I have opened new issue #6008 for this with PR #6009 to fix it.

[olamy]

@joakime oh! Well we broke it then, so I think we need to help them out with a PR to fix it.
Rather than remove it entirely, can we replace it with a module/xml that says it currently not available, but coming soon.

logback looks almost dead project...
https://github.com/qos-ch/logback/graphs/contributors
only 3 commits in 2020.
So I would not expect any change in logback....

[chiralsoftware]

@olamy If it's dead or almost dead it shouldn't be supported. My perspective, as a user, is that Jetty already has a confusingly large number of different logging options and modules. It would be better for users like me to have fewer, and also to have clear documentation giving a good default setup that will work reasonably for most users.

[olamy]

@chiralsoftware I mean I do not hope to see logback code being fixed with the changes done in 10.
If you really want to use logback I would recommend using Slf4jRequestLogWriter which log to slf4j-api so you can setup logback as a slf4j impl

[chiralsoftware]

@olamy What I would really like is for Jetty to tell me which log configuration to use. I don't have any preferences and it's confusing that there are so many choices. It should just be, "Use this specific module for request logs, this specific module for application logs. If you really need to customize it in some way, then you have these options."

[gregw]

@chiralsoftware Thanks for your input... very timely as we are reworking the documentation and logging is literally the next section to be done.

We do have many different logging options, unfortunately because we are integrated in many different projects with many different logging preferences, so we don't get to assert our own preferences.

If just enable the requestlog we will log requests to a file without asking for more info. Yes you have to do a bit more if you want logging to go to a different directory, but then we often see the whole jetty-base directory created within /var (with jetty-home in /opt or /local) so often it is not necessary to check the directory.

The server logging if left unconfigured will go to stderr. If you want that in a file then use the console-capture module to put stderr and stdout to a file, again avoiding any specific logging system configuration.

@olamy logback just logs requests... I wouldn't expect a lot of activity in such a project.