You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by bu...@apache.org on 2020/01/17 15:36:22 UTC

[Bug 64082] New: Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

            Bug ID: 64082
           Summary: Nio2Endpoint for async request doesn't clear
                    OutputBuffer when socket has already been closed
                    (response mixup)
           Product: Tomcat 8
           Version: 8.5.50
          Hardware: PC
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: P2
         Component: Connectors
          Assignee: dev@tomcat.apache.org
          Reporter: william.crowell@roguewave.com
  Target Milestone: ----

This issue is similar to what is described in resolved bug 63022:
https://bz.apache.org/bugzilla/show_bug.cgi?id=63022

We use OpenIG 6.5.1 as a reverse proxy which copies the contents received from
the backend server into HttpServlet's OutputStream.  The following link is the
servlet we are using here: 

https://github.com/WrenArchiver/forgerock-http-framework/blob/master/http-servlet/src/main/java/org/forgerock/http/servlet/HttpFrameworkServlet.java

We are running into an issue where the user agent (browser) is receiving a
response which was meant for another user.  It appears Tomcat does not
clear/recycle the response properly when the socket has already been closed. We
downgraded the Tomcat version from 8.5.47 to 8.5.35 to see if bringing back the
change that was removed by bug 63022 will resolve their issue.  So far, the
issue has not been recreated with 8.5.35 with a change to
org.apache.tomcat.util.net.Nio2Endpoint.isClosed():

https://github.com/apache/tomcat/blob/8.5.37/java/org/apache/tomcat/util/net/Nio2Endpoint.java
...
        @Override
        public boolean isClosed() {
            return closed || !getSocket().isOpen();
        }
...

This issue also occurs in Tomcat 9.0.30.

Tomcat added a boolean variable to check whether a request/socket is closed or
not (revision 1833907). Which is "closed" flag in addition to
!getSocket().isOpen() inside org.apache.tomcat.util.net.Nio2Endpoint. 
!getSocket()isOpen() check was removed starting in Tomcat 8.5.38 in bug 63022
to let Tomcat complete async request gracefully to increment
connectionCount(LimitLatch) for JMX.

However, bug 61918 (referenced from 63022) states:

"I'm not convinced closing sockets like this is a really good idea. The patch
may reintroduce more serious problems, but adding a closed flag seems
possible."  

We see a response mixup which should have been fixed with CVE-2018-8037 because
of the change done in bug 63022 as our issue is not recreated on 8.5.35 which
does not have fix for bug 63022.

We have confirmed with the OpenIG log that the response received from backend
application is in tact.  We have provided data from production environment
which used several different backend applications but had a response mix-up. We
have never encountered the response mix-up issue until OpenIG was running on
tomcat 8.5.47.  We cannot recreate the issue using OpenIG running on Jetty with
the same test application.  We have not been able to recreate the issue using
OpenIG running on Tomcat v8.5.35.  When the mixup happens, HttpFrameworkServlet
was sometimes passed HttpServletResponse object which contained headers from
other requests:

https://github.com/WrenArchiver/forgerock-http-framework/blob/master/http-servlet/src/main/java/org/forgerock/http/servlet/HttpFrameworkServlet.java

Attaching some errors we see around the time of issue. 
----
 [2020-01-04 15:45:32,273] ERROR [I/O dispatcher 5242] o.f.u.p.PromiseImpl
[green] - Ignored unexpected exception thrown by ResultHandler
java.lang.IllegalStateException: Calling [asyncComplete()] is not valid for a
request with Async state [MUST_ERROR]
        at
org.apache.coyote.AsyncStateMachine.doComplete(AsyncStateMachine.java:331)
        at
org.apache.coyote.AsyncStateMachine.asyncComplete(AsyncStateMachine.java:316)
        at
org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:502)
        at org.apache.coyote.Request.action(Request.java:431)
        at
org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:92)
        at
org.forgerock.http.servlet.Servlet3Adapter$ServletAsynchronousSynchronizer.signalAndComplete(Servlet3Adapter.java:75) 
 ----

 ----
[2020-01-02 20:16:56,354] ERROR [AsyncStreamingHttpClient-promises-3530]
o.f.u.p.PromiseImpl [green] - Ignored unexpected exception thrown by
ResultHandler
java.lang.IllegalStateException: The request associated with the AsyncContext
has already completed processing.
        at
org.apache.catalina.core.AsyncContextImpl.check(AsyncContextImpl.java:508)
        at
org.apache.catalina.core.AsyncContextImpl.complete(AsyncContextImpl.java:91)
        at
org.forgerock.http.servlet.Servlet3Adapter$ServletAsynchronousSynchronizer.signalAndComplete(Servlet3Adapter.java:75)
        at
org.forgerock.http.servlet.HttpFrameworkServlet.writeResponse(HttpFrameworkServlet.java:343)
        at
org.forgerock.http.servlet.HttpFrameworkServlet.lambda$service$0(HttpFrameworkServlet.java:265)
        at
org.forgerock.util.promise.PromiseImpl.lambda$thenOnResult$1(PromiseImpl.java:292)
        at
org.forgerock.util.promise.PromiseImpl.lambda$then$6(PromiseImpl.java:374)
        at
org.forgerock.util.promise.PromiseImpl.handleCompletion(PromiseImpl.java:536)
        at
org.forgerock.util.promise.PromiseImpl.setState(PromiseImpl.java:577)
        at
org.forgerock.util.promise.PromiseImpl.tryHandleResult(PromiseImpl.java:258)
        at
org.forgerock.util.promise.PromiseImpl.handleResult(PromiseImpl.java:208)
 ----

 or 
 ----
[2020-01-02 00:42:13,595] INFO [I/O dispatcher 2350]
o.f.o.f.S.UnauthorizedLogger [blue] - [TRANSACTION_ID:
a9a42e42-adb3-4fc8-953e-58309f5aed54-5743700][URI:
https://xxx.com/xxx/test.css][METHOD: GET][UID: XXXXX]Unauthorized.
[2020-01-02 00:42:38,890] ERROR [I/O dispatcher 6597]
o.f.h.s.HttpFrameworkServlet [blue] - Failed to write response
org.apache.catalina.connector.ClientAbortException: java.io.IOException:
Connection reset by peer
        at
org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:372)
        at
org.apache.catalina.connector.OutputBuffer.appendByteArray(OutputBuffer.java:811)
        at
org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:740)
        at
org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:407)
        at
org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:385)
        at
org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:96)
        at org.forgerock.http.io.IO.stream(IO.java:290)
        at
org.forgerock.http.servlet.HttpFrameworkServlet.writeResponse(HttpFrameworkServlet.java:372)
        at
org.forgerock.http.servlet.HttpFrameworkServlet.writeResponse(HttpFrameworkServlet.java:340)
        at
org.forgerock.http.servlet.HttpFrameworkServlet.lambda$service$0(HttpFrameworkServlet.java:265)
 ----

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #8 from william.crowell@roguewave.com ---
> Are you also able to reliably reproduce the error without RECYCLE_FACADES enabled?

Yes, it happens on each test run.

> Tomcat (usually) properly protects these objects from shared-use, but applications have minds of their own.

Are issues like this usually application related?

> What kind of request-load are you expecting? 

Let me check on this.

> My guess is that correctness is more important than performance.

Yes, that is correct.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #9 from Christopher Schultz <ch...@christopherschultz.net> ---
(In reply to william.crowell from comment #8)
> > Are you also able to reliably reproduce the error without RECYCLE_FACADES enabled?
> 
> Yes, it happens on each test run.

Great.

> > Tomcat (usually) properly protects these objects from shared-use, but applications have minds of their own.
> 
> Are issues like this usually application related?

Almost always.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #11 from william.crowell@roguewave.com ---
Bear with us for a moment as we are trying to get a viable test case together.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #5 from Remy Maucherat <re...@apache.org> ---
I described the scenario in my comment, the application code is most likely not
aware that the async is done. To know where the problem comes from a simple
test case would be useful.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #12 from william.crowell@roguewave.com ---
Please close this issue.  We cannot provide a valid test case.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #1 from william.crowell@roguewave.com ---
For reference:

Tomcat 8.5.3 - 8.5.31 and 9.0.0 - 9.0.8:

...
@Override

public boolean isClosed()

{ return !getSocket().isOpen(); }
...

Tomcat 8.5.32 - 8.5.37 and 9.0.9 - 9.0.14

...
@Override

public boolean isClosed()

{ return closed || !getSocket().isOpen(); }
...

Tomcat 8.5.38 - 8.5.50 and 9.0.15 - 9.0.21:

...
@Override

public boolean isClosed()

{ return closed; }
...

This code has been rewritten from 9.0.22 and on.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

Remy Maucherat <re...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |NEEDINFO

--- Comment #3 from Remy Maucherat <re...@apache.org> ---
Please test with the system property
"org.apache.catalina.connector.RECYCLE_FACADES" set to "true".

The scenario in similar issues is:
- IO error occurs, gets more or less ignored or seen as not important (the
reason why is interesting and could be a bug depending on what happens)
- as a result, framework or Servlet thinks async is still going
- meanwhile the container recycles everything and reuses for another request
- the request facades still point to the same objects, so they see another
request from another user (the recycle facades setting prevents that)

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #4 from william.crowell@roguewave.com ---
Setting org.apache.catalina.connector.RECYCLE_FACADES to true did work.  Do you
know why that fixed the issue?  I am also concerned about the performance
impact of setting that flag to true.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #6 from william.crowell@roguewave.com ---
For a simple test case are you looking for application code?

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #2 from Remy Maucherat <re...@apache.org> ---
You are presenting what could be an issue in a complex and confusing IMO. So
let's start over.

The changes to isClosed is likely not relevant and this will not be changed.
They ensure that the socket wrapper close occurs once and nothing more. This is
important. If the network layer becomes closed it still doesn't change this
need to close the wrapper or else you run into other problems (= all the bugs
you quote).

If you're encountering a recycling issue at the Servlet layer, the first step
to start working on it is going to be to set the system
propertyorg.apache.catalina.connector.RECYCLE_FACADES to true, or enable the
security manager.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #7 from Christopher Schultz <ch...@christopherschultz.net> ---
(In reply to william.crowell from comment #4)
> Setting org.apache.catalina.connector.RECYCLE_FACADES to true did work.

Excellent. Since it "works", are you also able to reliably reproduce the error
without RECYCLE_FACADES enabled?

> Do you know why that fixed the issue?

It prevented the sharing of response objects between requests. Tomcat (usually)
properly protects these objects from shared-use, but applications have minds of
their own.

> I am also concerned about the performance impact of setting that flag to true.

What kind of request-load are you expecting? The request objects are fairly
lightweight and, since they should be short-lived, shouldn't put too much
strain on the garbage collector (whose runtime is related to the number of live
objects, not dead ones).

My guess is that correctness is more important than performance.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

--- Comment #10 from william.crowell@roguewave.com ---
Thanks for your reply.  I will post an update to this issue tomorrow.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org


[Bug 64082] Nio2Endpoint for async request doesn't clear OutputBuffer when socket has already been closed (response mixup)

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=64082

Mark Thomas <ma...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEEDINFO                    |RESOLVED
         Resolution|---                         |INVALID

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org