javalin Cleaner stacktraces?

Cleaner stacktraces?

Open grzegorzbor opened this issue 1 year ago • 7 comments

I noticed that in the recent versions of javalin the stacktraces started to be really long (3x longer than before, from ~50 frames to ~150 frames) and polluted with "CompletableFuture.xxx()". Don't know if anything can be done to improve it. It's not a really big issue, but it is quite annoying; so maybe it can be simplifired?

For example, in version 4.4.0, the stacktrace looked like this: at com.example.MyLogic.foo() at io.javalin.core.security.SecurityUtil.noopAccessManager(SecurityUtil.kt:20) at io.javalin.http.JavalinServlet.addHandler$lambda-5(JavalinServlet.kt:115) at io.javalin.http.JavalinServlet$service$tryBeforeAndEndpointHandlers$1.invoke(JavalinServlet.kt:44) at io.javalin.http.JavalinServlet$service$tryBeforeAndEndpointHandlers$1.invoke(JavalinServlet.kt:39) at io.javalin.http.JavalinServlet.service$tryWithExceptionMapper(JavalinServlet.kt:131) at io.javalin.http.JavalinServlet.service$tryBeforeAndEndpointHandlers(JavalinServlet.kt:39) at io.javalin.http.JavalinServlet.service(JavalinServlet.kt:87) at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) at io.javalin.jetty.JavalinJettyServlet.service(JavalinJettyServlet.kt:58) at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:569) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) at io.javalin.jetty.JettyServer$start$wsAndHttpHandler$1.doHandle(JettyServer.kt:52) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:507) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1292) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173) at io.micrometer.core.instrument.binder.jetty.TimedHandler.handle(TimedHandler.java:120) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.eclipse.jetty.server.Server.handle(Server.java:501) at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) at java.base/java.lang.Thread.run(Thread.java:833)

While in version 4.6.4 looks like this: at com.example.MyLogic.foo() at io.javalin.core.security.SecurityUtil.noopAccessManager(SecurityUtil.kt:20) at io.javalin.http.JavalinServlet.addHandler$lambda-0(JavalinServlet.kt:96) at io.javalin.http.JavalinServlet$lifecycle$2$1$1.invoke(JavalinServlet.kt:43) at io.javalin.http.JavalinServlet$lifecycle$2$1$1.invoke(JavalinServlet.kt:43) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:99) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServletHandler.executeNextTask$lambda-11$lambda-10(JavalinServletHandler.kt:119) at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:119) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:85) at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:85) at io.javalin.http.JavalinServlet.service(JavalinServlet.kt:89) at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) at io.javalin.jetty.JavalinJettyServlet.service(JavalinJettyServlet.kt:58) at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:763) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:569) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) at io.javalin.jetty.JettyServer$start$wsAndHttpHandler$1.doHandle(JettyServer.kt:52) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:507) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1292) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173) at io.micrometer.core.instrument.binder.jetty.TimedHandler.handle(TimedHandler.java:120) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) at org.eclipse.jetty.server.Server.handle(Server.java:501) at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383) at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) at java.base/java.lang.Thread.run(Thread.java:833)

Aug 10 '22 09:08 grzegorzbor

@grzegorzbor in order to simplify the internal architecture we decided to pass sync responses through the async pipeline (as already completed futures).

@dzikoysk any ideas for this one? 😬

Aug 10 '22 10:08 tipsy

Well, the previous stacktrace is in fact "cleaner" in terms of visibility, but that's mostly because it didn't work properly and was affected by several issues like race conditions & inconsistent behavior of api. Because Javalin already used CompletableFuture and I also didn't want to add any extra async related abstraction as I was quite sure it wouldn't be approved, we just simply decided to implement new servlet on top of completable futures where each next layer is just simply composed with the previous one. I'm not saying that it's impossible to write it slightly differently, but it will for sure add more code and complexity to the core codebase.

As you can see this impl uses just those 4 methods to chain literally all what Javalin does during request execution:

https://github.com/javalin/javalin/blob/master/javalin/src/main/java/io/javalin/http/JavalinServletHandler.kt

We could for instance move sync execution out of futures, but it'd pretty much duplicate part of this code at some point. We could also try to remove chaining (that looks like recursion at some point, but it's more reactive in a way it works), but it'd require a new execution pipeline based on another queue bounded with another thread-pool to continue execution (that's +/- how Jetty works). As long as I'd be able to implement this, from my experience and talks we had I'm not quite sure if that's direction you'd like @tipsy and there's no much benefit of it, if any.

Aug 10 '22 10:08 dzikoysk

Well, the previous stacktrace is in fact "cleaner" in terms of visibility, but that's mostly because it didn't work properly and was affected by several issues like race conditions & inconsistent behavior of api.

To be fair, this was only an issue for the small majority of user's using futures.

As long as I'd be able to implement this, from my experience and talks we had I'm not quite sure if that's direction you'd like @tipsy and there's no much benefit of it, if any.

We briefly discussed making JavalinServlet pluggable, and having one async and one sync implementation. If we extract common code into utils, we might end up with an acceptable amount of code duplication. We could potentially also do SyncContext and AsyncContext, now that Context is an interface.

This is not something to solve before 5.0, but maybe something to consider for the future?

Aug 10 '22 12:08 tipsy

But to the point of this issue, could we improve stack traces when using completed futures somehow, or is it not feasible?

Aug 10 '22 12:08 tipsy

In theory we can override stacktrace of exception:

https://docs.oracle.com/javase/7/docs/api/java/lang/Throwable.html#setStackTrace(java.lang.StackTraceElement[])

so we could just simply drop/replace internal part of it. But it could be misleading and in theory could hide some key data if user would find a bug or sth like that in our implementation. Stacktrace is just a tool to show exactly how it happened, I'm not sure if there's just any point of changing the behavior/cutting this out only to make it "shorter" 🤔 Because on top of that you see the same result, so where the exception was thrown.

We briefly discussed making JavalinServlet pluggable, and having one async and one sync implementation. If we extract common code into utils, we might end up with an acceptable amount of code duplication. We could potentially also do SyncContext and AsyncContext, now that Context is an interface.

This is not something to solve before 5.0, but maybe something to consider for the future?

I'm not in power to decide if it'll be approach you want to go for, but in general I'm still against that:

It'll make API inconsistent again
It'll also add more complexity and issues related to which implementation of servlet I'm currently using + more chances to introduce bugs/breaking issues/a possibility to implement weird abstraction to support custom servlets
It's very odd in general that user has to swap internal impl and use different api to have a possibility to do sth async

Aug 10 '22 12:08 dzikoysk

Overriding the stacktrace on the framework level would probably do more harm than good. Could be very confusing.

My problem with these stacktraces is following. We use the logback for logging. It allows providing the pattern to filter out the stacktrace lines that should not be printed. This was extremely useful with spring-based webapps, because spring tends to add hundreds of stacktrace lines with "org.springframework.aop.Blabblah", "net.sf.cglib.Blah" etc. So with logback you can provide a pattern to skip printing all lines containing text "org.springframework", "net.sf.cglib" etc. That was fine with spring. With javalin, until now the stacktraces being short, we didn't bother with filtering them. Now, in the new approach, when they are so long, it makes debugging a bit more diffucult because distingushing "our code" from "framework code" is a but more time consuming (it no longer fits the screen, you need to scroll, and if you analyze lots of them, it starts to make some difference). I can easily filter out all lines containing "io.javalin". But most of the noise comes from those CompletableFuture.xxx lines. But if I filter out all lines with CompletableFuture, i risk filtering them out from the part of the stack trace where my own code uses CompletableFuture, and this can be confusing.

Aug 10 '22 12:08 grzegorzbor

One solution would be to subclass the ComletableFuture with something like JavalinCompletableFuture which would make the filtering easy. But this can be tricky and I'm not even sure if that's the good idea.

Perhaps it's more the logging library issue. I raised the ticket to logback for smarter stacktrace filtering: https://jira.qos.ch/browse/LOGBACK-1654

Aug 10 '22 13:08 grzegorzbor

java.lang.NullPointerException
	at io.javalin.TestRequest.queryParam_returns_null_for_unknown_param$lambda-45$lambda-44(TestRequest.kt:172)
	at io.javalin.routing.HandlerEntry.handle(HandlerEntry.kt:19)
	at io.javalin.http.JavalinServlet$lifecycle$4$1$1.invoke(JavalinServlet.kt:79)
	at io.javalin.http.JavalinServlet$lifecycle$4$1$1.invoke(JavalinServlet.kt:79)
	at io.javalin.http.JavalinServletHandler$executeNextTask$2$1.invoke(JavalinServletHandler.kt:105)
	at io.javalin.http.JavalinServletHandler$executeNextTask$2$1.invoke(JavalinServletHandler.kt:105)
	at io.javalin.http.JavalinServletHandler.handleFutureResultReference(JavalinServletHandler.kt:128)
	at io.javalin.http.JavalinServletHandler.executeNextTask(JavalinServletHandler.kt:105)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-0(JavalinServletHandler.kt:93)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:93)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:94)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:94)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:94)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:94)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$lambda-1(JavalinServletHandler.kt:94)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168)
	at io.javalin.http.JavalinServletHandler.queueNextTaskOrFinish$javalin(JavalinServletHandler.kt:94)
	at io.javalin.http.JavalinServlet.service(JavalinServlet.kt:96)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
	at io.javalin.jetty.JavalinJettyServlet.service(JavalinJettyServlet.kt:58)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:529)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
	at io.javalin.jetty.JettyServer$start$wsAndHttpHandler$1.doHandle(JettyServer.kt:57)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1297)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.Server.handle(Server.java:562)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)
	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.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:894)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1038)
	at java.base/java.lang.Thread.run(Thread.java:833)

java.lang.NullPointerException
	at io.javalin.TestRequest.queryParam_returns_null_for_unknown_param$lambda-45$lambda-44(TestRequest.kt:172)
	at io.javalin.routing.HandlerEntry.handle(HandlerEntry.kt:19)
	at io.javalin.http.JavalinServlet$lifecycle$4$1$1.invoke(JavalinServlet.kt:79)
	at io.javalin.http.JavalinServlet$lifecycle$4$1$1.invoke(JavalinServlet.kt:79)
	at io.javalin.http.JavalinServletHandler$executeNextTask$2$1.invoke(JavalinServletHandler.kt:105)
	at io.javalin.http.JavalinServletHandler$executeNextTask$2$1.invoke(JavalinServletHandler.kt:105)
	at io.javalin.http.JavalinServlet.service(JavalinServlet.kt:96)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
	at io.javalin.jetty.JavalinJettyServlet.service(JavalinJettyServlet.kt:58)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:587)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:529)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1571)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)
	at io.javalin.jetty.JettyServer$start$wsAndHttpHandler$1.doHandle(JettyServer.kt:57)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1544)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1297)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)
	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)
	at org.eclipse.jetty.server.Server.handle(Server.java:562)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)
	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.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:894)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1038)
	at java.base/java.lang.Thread.run(Thread.java:833)

Aug 13 '22 08:08 tipsy

This was done by adding a small function call to the beginning of the exception mapper:

if (stackTraceCleaner != null) {
    exception.stackTrace = stackTraceCleaner.invoke(exception.stackTrace)
}

This could be passed to Javalin.create { it.core.stackTraceCleaner = ... }

Now, if this is a good idea.. I'm not sure.

Aug 13 '22 08:08 tipsy

Interesting. I didn't even know that is possible. Sounds quite promising. But this will only work inside the exception mapper functions, correct? So in the other places where i do catch(Exception) i will still need to do the cleaning manually. Which is not bad, i can have a static method to call: catch (Exception e) {logger.error(message, cleaned(e))} On the other hand, if i had to call it manually in other places, maybe it's not worth adding it to the framework.

Aug 13 '22 10:08 grzegorzbor

But this will only work inside the exception mapper functions, correct?

Yes, but that should cover all of the frames that you are interested in.

So in the other places where i do catch(Exception) i will still need to do the cleaning manually. Which is not bad, i can have a static method to call:

Yes, but those places shouldn't contain Javalin's async handling frames?

Aug 13 '22 12:08 tipsy

If any code called from inside one my handlers throws an exception, and i catch it inside this handler, and log it, then the full javalin stacktrace will be present there. Something like:

public void handleRequest(Context ctx) {
  try {
     doSomeLogicThatMayFail();
  } catch (MyException e) {
     log.error("my logic failed", e);
     doSomethingOther();
  }
}

So in this case I would need to do instead (which is quite OK, I think): log.error("my logic failed", cleanStack(e));

Aug 14 '22 20:08 grzegorzbor

Ah, gotcha. This is a strange feature to include, but it's also very harmless. I'll put together a PR next week ☺️

Aug 14 '22 21:08 tipsy

https://github.com/javalin/javalin/pull/1648

Aug 15 '22 09:08 tipsy

Merged !

Aug 18 '22 15:08 tipsy

This has been reverted, but request handling has been rewritten so it doesn't use any futures unless the user had explicitly set a future. Stack traces should be short again!

Aug 30 '22 20:08 tipsy

Great! In which release is it expected to be?

wt., 30 sie 2022 o 22:07 David (javalin.io) @.***> napisał(a):

This has been reverted, but request handling has been rewritten so it doesn't use any futures unless the user had explicitly set a future. Stack traces should be short again!

— Reply to this email directly, view it on GitHub https://github.com/javalin/javalin/issues/1640#issuecomment-1232112993, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABZNXVLGJUOGDRNXTG4DDS3V3ZSWLANCNFSM56DX6HSA . You are receiving this because you were mentioned.Message ID: @.***>

Aug 30 '22 20:08 grzegorzbor

@grzegorzbor will be in Javalin 5.0.

Aug 30 '22 21:08 Playacem

javalin javalin copied to clipboard

Cleaner stacktraces?

javalin
javalin copied to clipboard