eclipse-ee4j / eclipse-ee4j/jersey

Blocked thread if WebApplicationException is reused.

Open
#4,097 11 comments 2 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
730
Forks
382
PR merge metrics
No merged PRs in 30d

Description

I think this exception has been raise a few times; but it never seems to come with a reproducer so the scenario is that after a while there is a number of stuck threads noted in this case by WLS 12.2.1; but I can see that this code would be a problem in the servers:

"[ACTIVE] ExecuteThread: '48' for queue: 'weblogic.kernel.Default (self-tuning)'" #157 daemon prio=5 os_prio=0 tid=0x00007f1c849e2000 nid=0x56c7 waiting on condition [0x00007f1c58318000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007b36845c8> (a jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:285)
at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
at org.glassfish.jersey.servlet.internal.ResponseWriter.getResponseContext(ResponseWriter.java:299)
at org.glassfish.jersey.servlet.internal.ResponseWriter.callSendError(ResponseWriter.java:215)
at org.glassfish.jersey.servlet.internal.ResponseWriter.commit(ResponseWriter.java:194)
at org.glassfish.jersey.server.ContainerResponse.close(ContainerResponse.java:413)
at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:784)
at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:444)
at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:490)
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:334)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:471)
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:425)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:383)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:336)
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:223)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:286)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:260)
at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:137)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:350)
at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:25)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at weblogic.security.internal.IDCSSessionSynchronizationFilter.doFilter(IDCSSessionSynchronizationFilter.java:176)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at weblogic.websocket.tyrus.TyrusServletFilter.doFilter(TyrusServletFilter.java:274)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.authorization.CSRFFilter.doFilter(CSRFFilter.java:124)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.service.SlashSlashWarningFilter.doFilter(SlashSlashWarningFilter.java:51)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.authorization.CORSFilter.doFilter(CORSFilter.java:125)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.metrics.DtVisitorTrackingFilter.doFilter(DtVisitorTrackingFilter.java:253)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.authorization.TenantFilter.doFilter(TenantFilter.java:224)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.authorization.TrackingFilter.doFilter(TrackingFilter.java:173)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at com.oracle.breeze.service.inject.LocaleFilter.doFilter(LocaleFilter.java:35)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:78)
at oracle.security.jps.ee.http.JpsAbsFilter$3.run(JpsAbsFilter.java:172)

https://github.com/jersey/jersey/issues/3558
https://github.com/jersey/jersey/issues/3800
https://github.com/jersey/jersey/issues/3207
https://github.com/jersey/jersey/issues/3619
https://github.com/eclipse-ee4j/jersey/issues/3474

None of these appear to have a reproducible test case, so I have raised this bug in case they are separate concerns.

This behaviour is seen in our code when a WebApplicationException is rethrown by a Guava Cache but the Response in this case is no longer valid as it has previously been used or is in use.

```
Response r = Response.status(this.getStatus())
.type(getMediaType())
// Make it more detectable that someone is trying to re-use this response object
// by causing an stream closed IO Exception, do not remove please consult
// BUFP-29699 as to why this is a good idea
.entity(new StringReader(toJSON()))
.build();
throw new WebApplicationException(response);
```

Note originally the response was a string; but the problem became more reproducible when we use an entity that cannot be re-used; but it isn't required.

Of course Response is an instance of OutboundJaxrsResponse which holds and instance of OutboundMessageContext which in turns holds a CommittingOutputStream which is not re-usable.

Depending on the load you either see two thread using the CommittingOutputStream at once or errors due to closed streams. It most cases the client in unaware of what has gone wrong and that makes it much harder to track down. Not sure how it gets the right response in this case.

So the deadlock happens in this section of code in SeverRuntime.java:

```
try {
response.setStreamProvider(new OutboundMessageContext.StreamProvider() {
@Override
public OutputStream getOutputStream(final int contentLength) throws IOException {
if (!runtime.disableLocationHeaderRelativeUriResolution) {
ServerRuntime.ensureAbsolute(response.getLocation(), response.getHeaders(),
response.getRequestContext(), runtime.rfc7231LocationHeaderRelativeUriResolution);
}
final OutputStream outputStream = writer.writeResponseStatusAndHeaders(contentLength, response);
return isHead ? null : outputStream;
}
});

if ((writer.enableResponseBuffering() || isHead) && !response.isChunked()) {
response.enableBuffering(runtime.configuration);
}

try {
response.setEntityStream(request.getWorkers().writeTo(
entity,
entity.getClass(),
response.getEntityType(),
response.getEntityAnnotations(),
response.getMediaType(),
response.getHeaders(),
request.getPropertiesDelegate(),
response.getEntityStream(),
request.getWriterInterceptors()));
} catch (final MappableException mpe) {
if (mpe.getCause() instanceof IOException) {
connectionCallbackRunner.onDisconnect(processingContext.asyncContext());
}
throw mpe;
}
tracingLogger.log(ServerTraceEvent.FINISHED, response.getStatusInfo());
tracingLogger.flush(response.getHeaders());

setWrittenResponse(response);

} catch (final Throwable ex) {
if (response.isCommitted()) {
/**
* We're done with processing here. There's nothing we can do about the exception so
* let's just log it.
*/
LOGGER.log(Level.SEVERE, LocalizationMessages.ERROR_WRITING_RESPONSE_ENTITY(), ex);
} else {
skipFinally = true;
if (ex instanceof RuntimeException) {
throw (RuntimeException) ex;
} else {
throw new MappableException(ex);
}
}
} finally {
if (!skipFinally) {
boolean close = !response.isChunked();
if (response.isChunked()) {
try {
response.commitStream();
} catch (final Exception e) {
LOGGER.log(Level.SEVERE, LocalizationMessages.ERROR_COMMITTING_OUTPUT_STREAM(), e);
close = true;
}

final ChunkedOutput chunked = (ChunkedOutput) entity;
try {
chunked.setContext(
runtime.requestScope,
runtime.requestScope.referenceCurrent(),
request,
response,
connectionCallbackRunner,
processingContext.asyncContextValue());
} catch (final IOException ex) {
LOGGER.log(Level.SEVERE, LocalizationMessages.ERROR_WRITING_RESPONSE_ENTITY_CHUNK(), ex);
close = true;
}
// suspend the writer indefinitely (passing null timeout handler is ok in such case) if the output is not
// already closed.
// TODO what to do if we detect that the writer has already been suspended? override the timeout value?
if (!chunked.isClosed()
&& !writer.suspend(AsyncResponder.NO_TIMEOUT, TimeUnit.SECONDS, null)) {
LOGGER.fine(LocalizationMessages.ERROR_SUSPENDING_CHUNKED_OUTPUT_RESPONSE());
}
}

if (close) {
try {
// the response must be closed here instead of just flushed or committed. Some
// output streams writes out bytes only on close (for example GZipOutputStream).
response.close();
} catch (final Exception e) {
LOGGER.log(Level.SEVERE, LocalizationMessages.ERROR_CLOSING_COMMIT_OUTPUT_STREAM(), e);
}
}
}
}
```

For example if the code in response.enableBuffering(runtime.configuration); fails because someone has already started to use the buffer you end up in the Throwable block before the code in setStreamProvider is executed. This means that when you get to response.close() it eventually get suck in ResponseWriter.commit but the ResponseContext is never set.

So it would make sense if the .get on the future this ResponseWriter had some kind of timeout; but it would be even better if the code properly recovered from this situation. As I say this is a hard was to track down because if the requirement for concurrency and for re-using the same Response object.

I can demonstrate this working in a running system if it helps with a fix, for the moment we worked around this using a trivial subclass:

```
/**
* Provide access to the internal state of the error without having to re-parse the entity body with
* the problems this entails.
*/
public static class DetailWebApplicationException extends WebApplicationException {

@Getter
private final ExceptionDetailResourceType type;

/*package*/ DetailWebApplicationException(ExceptionDetailResourceType type) {
super(type.toResponse());
this.type = type;
}

@Override
public Response getResponse() {
// You cannot reuse a response, and in some cases when the exception is cached we find that
// the exception was being resent to the user causing a thread leakage due to a design flaw
// in the Jersey runtime, please consult BUFP-29699 before modifying this code.
return type.toResponse();
}
}
```

But it might be possible to use an interceptor to clone the Response; but I didn't try it.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.