HttpChannel.minimalErrorResponse - fails recursively (IllegalStateException: Committed)

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

HttpChannel.minimalErrorResponse - fails recursively (IllegalStateException: Committed)

Jason Young
Hi,

I don't know how to reproduce this behavior, but I have seen in our logs e.g.:

java.lang.OutOfMemoryError: Java heap space
<redacted - serializing session objects >
at org.eclipse.jetty.server.session.SessionHandler.complete(SessionHandler.java:420)
at org.eclipse.jetty.server.session.SessionHandler.ensureCompletion(SessionHandler.java:445)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1563)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:494)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374)
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:314)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918)
at java.lang.Thread.run(Thread.java:819)
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:417)
... 4 more
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.minimalErrorResponse(HttpChannel.java:653)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:455)
... 4 more

times 20 of each suppressed exception (some have `EatWhatYouKill` etc.)--over 1300 lines in this stack trace. Every method call in this trace is in a jetty namespace or java.* namespace--none of our code or other third-party libs are in this stack trace. I don't think we're doing anything weird with the config to put Jetty into an infinite loop like this. We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

From code analysis, I see that `minimalErrorResponse` is attempted after a failed `handle`, and indeed every other suppressed exception attempts a `minimalErrorResponse`, so there's an attempt at a less error-prone error-handling routine, which is good (though it is not helpful in this case, as `HttpChannel.resetBuffer` is attempted either way). The trouble is, it _appears_ that a failure in `minimalErrorResponse` triggers the original error-handling routine.

What might cause this behavior?

I believe the OOME happened first for causes unrelated to this question or Jetty in general.

Using Jetty 9.4.20.v20190813.

--
Jason Young


_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
Reply | Threaded
Open this post in threaded view
|

Re: HttpChannel.minimalErrorResponse - fails recursively (IllegalStateException: Committed)

Joakim Erdfelt-8
> Using Jetty 9.4.20.v20190813

There's been a lot of error handling improvements since 9.4.20
Can you try 9.4.22.v20191022 and see if you have less issues?

For example, Jetty 9.4.21 removed HttpChannel.minimalErrorResponse().

> We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

It would be better if you just used the existing ErrorPageErrorHandler on your context, and called ...
ErrorPageErrorHandler.addErrorPage(ErrorPageErrorHandler.GLOBAL_ERROR_PAGE, "/empty");

And had a file in your base resources called "empty" which is empty.

Joakim Erdfelt / [hidden email]


On Mon, Nov 4, 2019 at 3:25 PM Jason Young <[hidden email]> wrote:
Hi,

I don't know how to reproduce this behavior, but I have seen in our logs e.g.:

java.lang.OutOfMemoryError: Java heap space
<redacted - serializing session objects >
at org.eclipse.jetty.server.session.SessionHandler.complete(SessionHandler.java:420)
at org.eclipse.jetty.server.session.SessionHandler.ensureCompletion(SessionHandler.java:445)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1563)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:494)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374)
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:314)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918)
at java.lang.Thread.run(Thread.java:819)
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:417)
... 4 more
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.minimalErrorResponse(HttpChannel.java:653)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:455)
... 4 more

times 20 of each suppressed exception (some have `EatWhatYouKill` etc.)--over 1300 lines in this stack trace. Every method call in this trace is in a jetty namespace or java.* namespace--none of our code or other third-party libs are in this stack trace. I don't think we're doing anything weird with the config to put Jetty into an infinite loop like this. We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

From code analysis, I see that `minimalErrorResponse` is attempted after a failed `handle`, and indeed every other suppressed exception attempts a `minimalErrorResponse`, so there's an attempt at a less error-prone error-handling routine, which is good (though it is not helpful in this case, as `HttpChannel.resetBuffer` is attempted either way). The trouble is, it _appears_ that a failure in `minimalErrorResponse` triggers the original error-handling routine.

What might cause this behavior?

I believe the OOME happened first for causes unrelated to this question or Jetty in general.

Using Jetty 9.4.20.v20190813.

--
Jason Young

_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users

_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
Reply | Threaded
Open this post in threaded view
|

Re: HttpChannel.minimalErrorResponse - fails recursively (IllegalStateException: Committed)

Jason Young
Thanks, I will try an update.

As for `ErrorPageErrorHandler`, does it make a difference that we're not displaying pages to users? Our use of Jetty is mostly AJAX Web services--the client doesn't really have anything to look at in the response body if the status code is 4xx or 5xx.

On Mon, Nov 4, 2019 at 4:29 PM Joakim Erdfelt <[hidden email]> wrote:
> Using Jetty 9.4.20.v20190813

There's been a lot of error handling improvements since 9.4.20
Can you try 9.4.22.v20191022 and see if you have less issues?

For example, Jetty 9.4.21 removed HttpChannel.minimalErrorResponse().

> We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

It would be better if you just used the existing ErrorPageErrorHandler on your context, and called ...
ErrorPageErrorHandler.addErrorPage(ErrorPageErrorHandler.GLOBAL_ERROR_PAGE, "/empty");

And had a file in your base resources called "empty" which is empty.

Joakim Erdfelt / [hidden email]


On Mon, Nov 4, 2019 at 3:25 PM Jason Young <[hidden email]> wrote:
Hi,

I don't know how to reproduce this behavior, but I have seen in our logs e.g.:

java.lang.OutOfMemoryError: Java heap space
<redacted - serializing session objects >
at org.eclipse.jetty.server.session.SessionHandler.complete(SessionHandler.java:420)
at org.eclipse.jetty.server.session.SessionHandler.ensureCompletion(SessionHandler.java:445)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1563)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:494)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374)
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:314)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918)
at java.lang.Thread.run(Thread.java:819)
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:417)
... 4 more
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.minimalErrorResponse(HttpChannel.java:653)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:455)
... 4 more

times 20 of each suppressed exception (some have `EatWhatYouKill` etc.)--over 1300 lines in this stack trace. Every method call in this trace is in a jetty namespace or java.* namespace--none of our code or other third-party libs are in this stack trace. I don't think we're doing anything weird with the config to put Jetty into an infinite loop like this. We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

From code analysis, I see that `minimalErrorResponse` is attempted after a failed `handle`, and indeed every other suppressed exception attempts a `minimalErrorResponse`, so there's an attempt at a less error-prone error-handling routine, which is good (though it is not helpful in this case, as `HttpChannel.resetBuffer` is attempted either way). The trouble is, it _appears_ that a failure in `minimalErrorResponse` triggers the original error-handling routine.

What might cause this behavior?

I believe the OOME happened first for causes unrelated to this question or Jetty in general.

Using Jetty 9.4.20.v20190813.

--
Jason Young

_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users



_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
Reply | Threaded
Open this post in threaded view
|

Re: HttpChannel.minimalErrorResponse - fails recursively (IllegalStateException: Committed)

Joakim Erdfelt-8
> As for `ErrorPageErrorHandler`, does it make a difference that we're not displaying pages to users? Our use of Jetty is mostly AJAX Web services--the client doesn't really have anything to look at in the response body if the status code is 4xx or 5xx.

Even errors can have responses, AJAX included.

Typically the advice on 4xx is that all 4xx responses have body content (Except HEAD requests).
The server, and your application, should contain a body content explaining the error situation, in the Content-Type supported by the Accept header of the request.
It should also indicate if this is a temporary or permanent condition.

So if you request a JSON, the response should be at a minimum a valid JSON response, even if it's an empty JSON response (such as "{}")

Joakim Erdfelt / [hidden email]


On Mon, Nov 4, 2019 at 5:17 PM Jason Young <[hidden email]> wrote:
Thanks, I will try an update.

As for `ErrorPageErrorHandler`, does it make a difference that we're not displaying pages to users? Our use of Jetty is mostly AJAX Web services--the client doesn't really have anything to look at in the response body if the status code is 4xx or 5xx.

On Mon, Nov 4, 2019 at 4:29 PM Joakim Erdfelt <[hidden email]> wrote:
> Using Jetty 9.4.20.v20190813

There's been a lot of error handling improvements since 9.4.20
Can you try 9.4.22.v20191022 and see if you have less issues?

For example, Jetty 9.4.21 removed HttpChannel.minimalErrorResponse().

> We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

It would be better if you just used the existing ErrorPageErrorHandler on your context, and called ...
ErrorPageErrorHandler.addErrorPage(ErrorPageErrorHandler.GLOBAL_ERROR_PAGE, "/empty");

And had a file in your base resources called "empty" which is empty.

Joakim Erdfelt / [hidden email]


On Mon, Nov 4, 2019 at 3:25 PM Jason Young <[hidden email]> wrote:
Hi,

I don't know how to reproduce this behavior, but I have seen in our logs e.g.:

java.lang.OutOfMemoryError: Java heap space
<redacted - serializing session objects >
at org.eclipse.jetty.server.session.SessionHandler.complete(SessionHandler.java:420)
at org.eclipse.jetty.server.session.SessionHandler.ensureCompletion(SessionHandler.java:445)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1563)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:494)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374)
at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:314)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918)
at java.lang.Thread.run(Thread.java:819)
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:417)
... 4 more
Suppressed: java.lang.IllegalStateException: Committed
at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:936)
at org.eclipse.jetty.server.HttpOutput$Interceptor.resetBuffer(HttpOutput.java:125)
at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:1081)
at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1108)
at org.eclipse.jetty.server.Response.resetForForward(Response.java:1101)
at org.eclipse.jetty.server.Response.reset(Response.java:1050)
at org.eclipse.jetty.server.HttpChannel.minimalErrorResponse(HttpChannel.java:653)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:455)
... 4 more

times 20 of each suppressed exception (some have `EatWhatYouKill` etc.)--over 1300 lines in this stack trace. Every method call in this trace is in a jetty namespace or java.* namespace--none of our code or other third-party libs are in this stack trace. I don't think we're doing anything weird with the config to put Jetty into an infinite loop like this. We do inject a custom `ErrorHandler` with an empty `writeErrorPage`.

From code analysis, I see that `minimalErrorResponse` is attempted after a failed `handle`, and indeed every other suppressed exception attempts a `minimalErrorResponse`, so there's an attempt at a less error-prone error-handling routine, which is good (though it is not helpful in this case, as `HttpChannel.resetBuffer` is attempted either way). The trouble is, it _appears_ that a failure in `minimalErrorResponse` triggers the original error-handling routine.

What might cause this behavior?

I believe the OOME happened first for causes unrelated to this question or Jetty in general.

Using Jetty 9.4.20.v20190813.

--
Jason Young

_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users
_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users


_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users

_______________________________________________
jetty-users mailing list
[hidden email]
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://www.eclipse.org/mailman/listinfo/jetty-users