boglesby commented on pull request #5246:
URL: https://github.com/apache/geode/pull/5246#issuecomment-645069891
I ran some tests with Tomcat 8.5.15 and 9.0.33.
I used Tomcat8DeltaSessionManager with Tomcat 8.5.15 and
Tomcat9DeltaSessionManager with Tomcat 9.0.33.
My test does this.
1. index.jsp that displays a form with a button
2. selection of the button in the browser causes login.jsp to run which:
a. creates a LoginStatus
b. sets its success to true
c. stores it in the session
d. returns a form with a button using flushBuffer
e. sleeps
3. selection of the button in the browser causes confirm.jsp that:
a. gets the LoginStatus
b. returns success value
Before these changes, the test returned null because the CommitSessionValve
had not been run yet. With these changes, the test works in both 8 and 9, but I
have a few comments and notes.
Step 2d is:
```
logger.warning(": about to flushBuffer");
response.flushBuffer();
logger.warning(": done flushBuffer");
```
Tomcat8DeltaSessionManager with Tomcat 8.5.15:
Logging in AbstractCommitSessionValve.commitSession shows it being invoked 4
times during the flushBuffer call:
```
16-Jun-2020 15:16:42.588 WARNING [http-nio-8080-exec-5]
org.apache.jsp.login_jsp._jspService : about to flushBuffer
16-Jun-2020 15:16:42.591 FINE [http-nio-8080-exec-5]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession
org.apache.geode.modules.session.catalina.DeltaSessionFacade@3a3c9678:
Committed.
16-Jun-2020 15:16:42.593 FINE [http-nio-8080-exec-5]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession
org.apache.geode.modules.session.catalina.DeltaSessionFacade@3a3c9678:
Committed.
16-Jun-2020 15:16:42.595 FINE [http-nio-8080-exec-5]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession
org.apache.geode.modules.session.catalina.DeltaSessionFacade@3a3c9678:
Committed.
16-Jun-2020 15:16:42.597 FINE [http-nio-8080-exec-5]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession
org.apache.geode.modules.session.catalina.DeltaSessionFacade@3a3c9678:
Committed.
16-Jun-2020 15:16:42.598 WARNING [http-nio-8080-exec-5]
org.apache.jsp.login_jsp._jspService : done flushBuffer
```
AbstractCommitSessionValve.invoke is being called 4 times (each with a
different thread) for the same Request/Response before the index.jsp is
displayed on the browser. I'm not sure if this is something to do with how it
is initialized from Intellij or my test, but it is causing
Tomcat8CommitSessionValve.wrapResponse to wrap the Response 4 times. The first
call correctly wrapped an Http11OutputBuffer; each subsequent call wraps a
Tomcat8CommitSessionOutputBuffer. So, flush was being called 4 times
recursively up the chain.
Here is some logging that shows that behavior:
AbstractCommitSessionValve.invoke:
```
16-Jun-2020 15:28:57.161 WARNING [http-nio-8080-exec-1]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.invoke
request=org.apache.catalina.connector.Request@70c9c573;
response=org.apache.catalina.connector.Response@17d9e65a
16-Jun-2020 15:28:57.558 WARNING [http-nio-8080-exec-2]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.invoke
request=org.apache.catalina.connector.Request@70c9c573;
response=org.apache.catalina.connector.Response@17d9e65a
16-Jun-2020 15:28:57.689 WARNING [http-nio-8080-exec-3]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.invoke
request=org.apache.catalina.connector.Request@70c9c573;
response=org.apache.catalina.connector.Response@17d9e65a
16-Jun-2020 15:28:59.109 WARNING [http-nio-8080-exec-4]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.invoke
request=org.apache.catalina.connector.Request@70c9c573;
response=org.apache.catalina.connector.Response@17d9e65a
```
Tomcat8CommitSessionValve.wrapResponse:
```
WARNING [http-nio-8080-exec-1]
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionValve.wrapResponse
delegateOutputBuffer=org.apache.coyote.http11.Http11OutputBuffer@5df32eac;
class=Http11OutputBuffer
WARNING [http-nio-8080-exec-2]
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionValve.wrapResponse
delegateOutputBuffer=org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer@65dd7542;
class=Tomcat8CommitSessionOutputBuffer
WARNING [http-nio-8080-exec-3]
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionValve.wrapResponse
delegateOutputBuffer=org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer@3f27e10a;
class=Tomcat8CommitSessionOutputBuffer
WARNING [http-nio-8080-exec-4]
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionValve.wrapResponse
delegateOutputBuffer=org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer@28a261f8;
class=Tomcat8CommitSessionOutputBuffer
```
Here is a stack showing the recursion:
```
java.lang.Exception
at
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession(AbstractCommitSessionValve.java:73)
at
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionValve.lambda$wrapResponse$0(Tomcat8CommitSessionValve.java:45)
at
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer.doWrite(Tomcat8CommitSessionOutputBuffer.java:48)
at
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer.doWrite(Tomcat8CommitSessionOutputBuffer.java:49)
at
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer.doWrite(Tomcat8CommitSessionOutputBuffer.java:49)
at
org.apache.geode.modules.session.catalina.Tomcat8CommitSessionOutputBuffer.doWrite(Tomcat8CommitSessionOutputBuffer.java:49)
at org.apache.coyote.Response.doWrite(Response.java:568)
at
org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:351)
at
org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffer.java:815)
at
org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:310)
at
org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:284)
at org.apache.catalina.connector.Response.flushBuffer(Response.java:543)
at
org.apache.catalina.connector.ResponseFacade.flushBuffer(ResponseFacade.java:312)
at org.apache.jsp.login_jsp._jspService(login_jsp.java:160)
```
I made this change to Tomcat8CommitSessionValve.wrapResponse to address this
issue.
```
if (!(delegateOutputBuffer instanceof Tomcat8CommitSessionOutputBuffer)) {
final Request request = response.getRequest();
final OutputBuffer sessionCommitOutputBuffer =
new Tomcat8CommitSessionOutputBuffer(() -> commitSession(request),
delegateOutputBuffer);
coyoteResponse.setOutputBuffer(sessionCommitOutputBuffer);
}
```
With that change, I see 1 call to AbstractCommitSessionValve.commitSession:
```
16-Jun-2020 15:42:13.883 WARNING [http-nio-8080-exec-4]
org.apache.jsp.login_jsp._jspService : about to flushBuffer
16-Jun-2020 15:42:13.886 FINE [http-nio-8080-exec-4]
org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession
org.apache.geode.modules.session.catalina.DeltaSessionFacade@2ef2ff: Committed.
16-Jun-2020 15:42:13.886 WARNING [http-nio-8080-exec-4]
org.apache.jsp.login_jsp._jspService : done flushBuffer
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
[email protected]
