Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Avoid 'stream was already closed' when the client hangs up early #2165

Closed
lmsurpre opened this issue Mar 29, 2021 · 3 comments
Closed

Avoid 'stream was already closed' when the client hangs up early #2165

lmsurpre opened this issue Mar 29, 2021 · 3 comments
Assignees
Labels
bug Something isn't working enhancement New feature or request

Comments

@lmsurpre
Copy link
Member

Is your feature request related to a problem? Please describe.
Occasionally, we see the following stack trace in our logs:

WARNING Interceptor for {http://resources.server.fhir.ibm.com/}Patch has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: XML_WRITE_EXC
	at org.apache.cxf.jaxrs.interceptor.JAXRSDefaultFaultOutInterceptor.handleMessage(JAXRSDefaultFaultOutInterceptor.java:129)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:318)
	at org.apache.cxf.interceptor.AbstractFaultChainInitiatorObserver.onMessage(AbstractFaultChainInitiatorObserver.java:112)
	at org.apache.cxf.phase.PhaseInterceptorChain.wrapExceptionAsFault(PhaseInterceptorChain.java:384)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:342)
	at org.apache.cxf.interceptor.OutgoingChainInterceptor.handleMessage(OutgoingChainInterceptor.java:93)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:318)
	at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:123)
	at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:273)
	at com.ibm.ws.jaxrs20.endpoint.AbstractJaxRsWebEndpoint.invoke(AbstractJaxRsWebEndpoint.java:136)
	at com.ibm.websphere.jaxrs.server.IBMRestServlet.handleRequest(IBMRestServlet.java:146)
	at com.ibm.websphere.jaxrs.server.IBMRestServlet.doGet(IBMRestServlet.java:112)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:686)
	at com.ibm.websphere.jaxrs.server.IBMRestServlet.service(IBMRestServlet.java:96)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1225)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:729)
	at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:426)
	at com.ibm.ws.webcontainer.filter.WebAppFilterChain.invokeTarget(WebAppFilterChain.java:182)
	at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:93)
	at com.ibm.fhir.server.filter.rest.FHIRRestServletFilter.doFilter(FHIRRestServletFilter.java:142)
	at javax.servlet.http.HttpFilter.doFilter(HttpFilter.java:127)
	at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)
	at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:90)
	at com.ibm.fhir.server.filter.rest.FHIRRestAuthorizationServletFilter.doFilter(FHIRRestAuthorizationServletFilter.java:86)
	at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:201)
	at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:90)
	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:1001)
	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1139)
	at com.ibm.ws.webcontainer.filter.WebAppFilterManager.invokeFilters(WebAppFilterManager.java:1010)
	at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:75)
	at com.ibm.ws.webcontainer40.servlet.CacheServletWrapper40.handleRequest(CacheServletWrapper40.java:83)
	at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:936)
	at com.ibm.ws.webcontainer.osgi.DynamicVirtualHost$2.run(DynamicVirtualHost.java:279)
	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink$TaskWrapper.run(HttpDispatcherLink.java:1134)
	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.wrapHandlerAndExecute(HttpDispatcherLink.java:415)
	at com.ibm.ws.http.dispatcher.internal.channel.HttpDispatcherLink.ready(HttpDispatcherLink.java:374)
	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:577)
	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.handleNewRequest(HttpInboundLink.java:511)
	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.processRequest(HttpInboundLink.java:359)
	at com.ibm.ws.http.channel.internal.inbound.HttpInboundLink.ready(HttpInboundLink.java:326)
	at com.ibm.ws.http.channel.h2internal.H2HttpInboundLinkWrap.ready(H2HttpInboundLinkWrap.java:98)
	at com.ibm.ws.http.channel.h2internal.H2StreamProcessor$Http2Ready.run(H2StreamProcessor.java:1787)
	at com.ibm.ws.threading.internal.ExecutorServiceImpl$RunnableWrapper.run(ExecutorServiceImpl.java:239)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:823)
Caused by: com.ctc.wstx.exc.WstxIOException: com.ibm.ws.http2.upgrade.H2Exception: stream was already closed!
	at com.ctc.wstx.sw.BaseStreamWriter.flush(BaseStreamWriter.java:262)
	at org.apache.cxf.jaxrs.interceptor.JAXRSDefaultFaultOutInterceptor.handleMessage(JAXRSDefaultFaultOutInterceptor.java:127)
	... 45 more
Caused by: java.io.IOException: com.ibm.ws.http2.upgrade.H2Exception: stream was already closed!
	at com.ibm.ws.http.channel.h2internal.H2HttpInboundLinkWrap.writeFramesSync(H2HttpInboundLinkWrap.java:491)
	at com.ibm.ws.http.channel.internal.HttpServiceContextImpl.synchWrite(HttpServiceContextImpl.java:3150)
	at com.ibm.ws.http.channel.internal.HttpServiceContextImpl.sendFullOutgoing(HttpServiceContextImpl.java:2860)
	at com.ibm.ws.http.channel.internal.inbound.HttpInboundServiceContextImpl.finishResponseMessage(HttpInboundServiceContextImpl.java:935)
	at com.ibm.ws.http.channel.internal.outbound.HttpOutputStreamImpl.flushBuffers(HttpOutputStreamImpl.java:539)
	at com.ibm.ws.http.channel.internal.outbound.HttpOutputStreamImpl.close(HttpOutputStreamImpl.java:626)
	at com.ibm.ws.webcontainer.osgi.response.WCOutputStream.close(WCOutputStream.java:214)
	at com.ibm.ws.webcontainer31.osgi.response.WCOutputStream31.close(WCOutputStream31.java:89)
	at org.apache.cxf.transport.http.AbstractHTTPDestination$WrappedOutputStream.close(AbstractHTTPDestination.java:885)
	at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
	at org.apache.cxf.transport.http.AbstractHTTPDestination$BackChannelConduit.close(AbstractHTTPDestination.java:815)
	at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:63)
	at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:318)
	... 41 more
Caused by: com.ibm.ws.http2.upgrade.H2Exception: stream was already closed!
	... 54 more

I believe it comes from our kubernetes readiness check. Under certain conditions, Kubernetes isn't reading the whole response body (on success).

Describe the solution you'd like
Configure liberty not to log this exception.

Describe alternatives you've considered

  1. Stop writing a response body from $healthcheck during success.
  2. Replace the Kubernetes HTTP-based readiness check with a script-based healthcheck that actually reads the response body (for non-$healthcheck endpoints)

Acceptance Criteria

Additional context
Liberty 21.0.0.2 introduced OpenLiberty/open-liberty#12490 which allows us to control this behavior.

@lmsurpre lmsurpre changed the title https://github.com/OpenLiberty/open-liberty/issues/12490 Avoid 'stream was already closed' when the client hangs up early Mar 29, 2021
@lmsurpre
Copy link
Member Author

Discussed with Paul a bit and we think that, in addition to using this new config setting, we should also change the $healthcheck behavior to return a 200 OK with an empty body in case of success.

For those depending on the existing behavior, we will introduce Prefer header support.
By default, users will get Prefer: return=minimal behavior (empty body on success).
But, if desired, clients can pass Prefer: return=OperationOutcome to get back the current OperationOutcome upon success.

@prb112 prb112 added bug Something isn't working enhancement New feature or request labels Mar 29, 2021
@lmsurpre
Copy link
Member Author

lmsurpre commented Mar 30, 2021

I decided to do only the $healthcheck change (and not the config change to the default Liberty server.xml). This should be sufficient for those that are using our $healthcheck endpoint for their readiness/liveness probes.

For anyone else wishing to suppress this same stream was already closed exception, you can add the following in a Liberty configDropin:

    <!-- Specify whether the HTTP channel creates an I/O exception when an inbound connection is closed 
        while still in use by the servlet. -->
    <httpOptions id="defaultHttpOptions" ThrowIOEForInboundConnections="false"/>

@lmsurpre lmsurpre self-assigned this Mar 30, 2021
@lmsurpre lmsurpre added this to the Sprint 2021-04 milestone Mar 30, 2021
@prb112
Copy link
Contributor

prb112 commented Apr 8, 2021

QA - Looks good...

docker build fhir-install -t ibmcom-dev/fhir-server
docker run -p 9443:9443 -e BOOTSTRAP_DB=true ibmcom-dev/fhir-server
curl --location --request POST 'https://localhost:9443/fhir-server/api/v4/$healthcheck'
Injected, Canceled Early and Did not see an issue

I did also try a large bundle
curl --location --request POST 'https://localhost:9443/fhir-server/api/v4'
--header 'Content-Type: application/fhir+json'
--header 'Authorization: Basic ....'
--data-raw '{
"resourceType": "Bundle",
"type": "transaction",
"entry": [

Canceled the 1.4M Bundle
Did not find the exception, although the implementation did not include it.

Also tried with OperationOutcome

@prb112 prb112 closed this as completed Apr 8, 2021
mmouly added a commit to DecisionsDev/odm-ondocker that referenced this issue Feb 21, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working enhancement New feature or request
Projects
None yet
Development

No branches or pull requests

2 participants