Access request logging fails on bad path in Dropwizard 5 #9773
Description
When running with access request logging (via logback-access), a request such as this:
GET /..;/manager/html
results in no access request log entry and this stacktrace in the logs:
java.lang.IllegalStateException: Expecting request to be an instance of ServletContextRequest
at io.dropwizard.request.logging.LogbackAccessRequestLog.log(LogbackAccessRequestLog.java:34)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.completeStream(HttpChannelState.java:751)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.failed(HttpChannelState.java:738)
at org.eclipse.jetty.server.internal.HttpChannelState.failed(HttpChannelState.java:1960)
at org.eclipse.jetty.server.internal.HttpChannelState$ErrorCallback.succeeded(HttpChannelState.java:1750)
at org.eclipse.jetty.util.ExceptionUtil.callAndThen(ExceptionUtil.java:442)
at org.eclipse.jetty.server.handler.ErrorHandler$WriteErrorCallback.succeeded(ErrorHandler.java:630)
at org.eclipse.jetty.util.thread.SerializedInvoker$Link.run(SerializedInvoker.java:268)
at org.eclipse.jetty.util.thread.SerializedInvoker.run(SerializedInvoker.java:168)
at org.eclipse.jetty.server.internal.HttpChannelState$ChannelResponse.succeeded(HttpChannelState.java:1325)
at org.eclipse.jetty.server.internal.HttpConnection$SendCallback.onCompleteSuccess(HttpConnection.java:916)
at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:354)
at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:243)
at org.eclipse.jetty.server.internal.HttpConnection$HttpStreamOverHTTP1.send(HttpConnection.java:1427)
at org.eclipse.jetty.server.internal.HttpChannelState$ChannelResponse.write(HttpChannelState.java:1300)
at org.eclipse.jetty.server.handler.ErrorHandler.generateAcceptableResponse(ErrorHandler.java:257)
at org.eclipse.jetty.server.handler.ErrorHandler.generateResponse(ErrorHandler.java:163)
at org.eclipse.jetty.server.handler.ErrorHandler.handle(ErrorHandler.java:118)
at org.eclipse.jetty.server.Response.writeError(Response.java:605)
at org.eclipse.jetty.server.Response.writeError(Response.java:520)
at org.eclipse.jetty.server.internal.HttpChannelState$ChannelCallback.failed(HttpChannelState.java:1607)
at org.eclipse.jetty.server.internal.HttpChannelState.lambda$onFailure$1(HttpChannelState.java:444)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:311)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:979)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1209)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1164)
at java.base/java.lang.Thread.run(Thread.java:1575)
Suppressed: java.lang.IllegalArgumentException: Bad URI
at org.eclipse.jetty.http.HttpURI$Mutable.parse(HttpURI.java:1637)
at org.eclipse.jetty.http.HttpURI$Mutable.pathQuery(HttpURI.java:1031)
at org.eclipse.jetty.http.HttpURI.build(HttpURI.java:122)
at org.eclipse.jetty.server.internal.HttpConnection$HttpStreamOverHTTP1.<init>(HttpConnection.java:1106)
at org.eclipse.jetty.server.internal.HttpConnection.newHttpStream(HttpConnection.java:195)
at org.eclipse.jetty.server.internal.HttpConnection$RequestHandler.startRequest(HttpConnection.java:945)
at org.eclipse.jetty.http.HttpParser.parseLine(HttpParser.java:935)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1654)
... 9 common frames omitted
Wrapped by: org.eclipse.jetty.http.BadMessageException: 400: Bad Request
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1779)
at org.eclipse.jetty.server.internal.HttpConnection.parseRequestBuffer(HttpConnection.java:579)
at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:386)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:99)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
... 4 common frames omitted
This is because io.dropwizard.request.logging.LogbackAccessRequestLog fails to cast org.eclipse.jetty.server.Request to an org.eclipse.jetty.ee10.servlet.ServletContextRequest because it is actually an org.eclipse.jetty.server.internal.HttpChannelState.ChannelRequest.