You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@geode.apache.org by GitBox <gi...@apache.org> on 2020/06/11 21:05:44 UTC

[GitHub] [geode] pivotal-jbarrett opened a new pull request #5246: GEODE-8221: Commits session data prior to sending output to browser

pivotal-jbarrett opened a new pull request #5246:
URL: https://github.com/apache/geode/pull/5246


   Thank you for submitting a contribution to Apache Geode.
   
   In order to streamline the review of the contribution we ask you
   to ensure the following steps have been taken:
   
   ### For all changes:
   - [ ] Is there a JIRA ticket associated with this PR? Is it referenced in the commit message?
   
   - [ ] Has your PR been rebased against the latest commit within the target branch (typically `develop`)?
   
   - [ ] Is your initial contribution a single, squashed commit?
   
   - [ ] Does `gradlew build` run cleanly?
   
   - [ ] Have you written or updated unit tests to verify your changes?
   
   - [ ] If adding new dependencies to the code, are these dependencies licensed in a way that is compatible for inclusion under [ASF 2.0](http://www.apache.org/legal/resolved.html#category-a)?
   
   ### Note:
   Please ensure that once the PR is submitted, check Concourse for build issues and
   submit an update to your PR as soon as possible. If you need help, please send an
   email to dev@geode.apache.org.
   


----------------------------------------------------------------
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:
users@infra.apache.org



[GitHub] [geode] boglesby commented on a change in pull request #5246: GEODE-8221: Commits session data prior to sending output to browser

Posted by GitBox <gi...@apache.org>.
boglesby commented on a change in pull request #5246:
URL: https://github.com/apache/geode/pull/5246#discussion_r441207166



##########
File path: extensions/geode-modules/src/main/java/org/apache/geode/modules/session/catalina/AbstractCommitSessionValve.java
##########
@@ -0,0 +1,86 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more contributor license
+ * agreements. See the NOTICE file distributed with this work for additional information regarding
+ * copyright ownership. The ASF licenses this file to You under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance with the License. You may obtain a
+ * copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software distributed under the License
+ * is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express
+ * or implied. See the License for the specific language governing permissions and limitations under
+ * the License.
+ */
+package org.apache.geode.modules.session.catalina;
+
+import static org.apache.geode.util.internal.UncheckedUtils.uncheckedCast;
+
+import java.io.IOException;
+
+import javax.servlet.ServletException;
+
+import org.apache.catalina.Context;
+import org.apache.catalina.Manager;
+import org.apache.catalina.connector.Request;
+import org.apache.catalina.connector.Response;
+import org.apache.catalina.valves.ValveBase;
+import org.apache.juli.logging.Log;
+import org.apache.juli.logging.LogFactory;
+
+
+public abstract class AbstractCommitSessionValve<SelfT extends AbstractCommitSessionValve<?>>
+    extends ValveBase {
+
+  private static final Log log = LogFactory.getLog(AbstractCommitSessionValve.class);
+
+  protected static final String info =
+      "org.apache.geode.modules.session.catalina.CommitSessionValve/1.0";
+
+  AbstractCommitSessionValve() {
+    log.info("Initialized");
+  }
+
+  @Override
+  public void invoke(final Request request, final Response response)
+      throws IOException, ServletException {
+    // Invoke the next Valve
+    try {
+      getNext().invoke(request, wrapResponse(response));
+    } finally {
+      commitSession(request);
+    }
+  }
+
+  /**
+   * Commit session only if DeltaSessionManager is in place.
+   *
+   * @param request to commit session from.
+   */
+  protected static <SelfT extends AbstractCommitSessionValve<?>> void commitSession(
+      final Request request) {
+    final Context context = request.getContext();
+    final Manager manager = context.getManager();
+    if (manager instanceof DeltaSessionManager) {
+      final DeltaSessionFacade session = (DeltaSessionFacade) request.getSession(false);
+      if (session != null) {
+        final DeltaSessionManager<SelfT> deltaSessionManager = uncheckedCast(manager);
+        final Log contextLogger = context.getLogger();

Review comment:
       Can you change this to use the AbstractCommitSessionValve's Logger (the static log variable) instead of the Context's logger? I'm not sure why its like this, but if we use the AbstractCommitSessionValve's Logger, then only 1 line in logging.properties is necessary to debug this class rather than 2:
   ```
   org.apache.geode.modules.session.level = FINE
   ```




----------------------------------------------------------------
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:
users@infra.apache.org



[GitHub] [geode] pivotal-jbarrett merged pull request #5246: GEODE-8221: Commits session data prior to sending output to browser

Posted by GitBox <gi...@apache.org>.
pivotal-jbarrett merged pull request #5246:
URL: https://github.com/apache/geode/pull/5246


   


----------------------------------------------------------------
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:
users@infra.apache.org



[GitHub] [geode] boglesby commented on pull request #5246: GEODE-8221: Commits session data prior to sending output to browser

Posted by GitBox <gi...@apache.org>.
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:
users@infra.apache.org



[GitHub] [geode] boglesby commented on pull request #5246: GEODE-8221: Commits session data prior to sending output to browser

Posted by GitBox <gi...@apache.org>.
boglesby commented on pull request #5246:
URL: https://github.com/apache/geode/pull/5246#issuecomment-645070010


   Tomcat9DeltaSessionManager with Tomcat 9.0.33:
   
   I see the same behavior as above, but only 3 times instead of 4. The same kind of change in Tomcat9CommitSessionValve.wrapResponse addresses the issue:
   ```
   if (!(delegateOutputBuffer instanceof Tomcat9CommitSessionOutputBuffer)) {
     final Request request = response.getRequest();
     final OutputBuffer sessionCommitOutputBuffer =
       new Tomcat9CommitSessionOutputBuffer(() -> commitSession(request), delegateOutputBuffer);
     coyoteResponse.setOutputBuffer(sessionCommitOutputBuffer);
   }
   ```
   One difference in behavior between 8 and 9 is this NPE right at the start of the test. It happens before my index.jsp is displayed and doesn't seem to affect anything. It probably should be addressed, though.
   ```
   16-Jun-2020 16:54:11.924 SEVERE [http-nio-8080-exec-3] org.apache.coyote.http11.Http11Processor.service Error processing request
   	java.lang.NullPointerException
   		at org.apache.geode.modules.session.catalina.AbstractCommitSessionValve.commitSession(AbstractCommitSessionValve.java:63)
   		at org.apache.geode.modules.session.catalina.Tomcat9CommitSessionValve.lambda$wrapResponse$0(Tomcat9CommitSessionValve.java:44)
   		at org.apache.geode.modules.session.catalina.Tomcat9CommitSessionOutputBuffer.doWrite(Tomcat9CommitSessionOutputBuffer.java:40)
   		at org.apache.coyote.Response.doWrite(Response.java:601)
   		at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:339)
   		at org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffer.java:776)
   		at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:298)
   		at org.apache.catalina.connector.OutputBuffer.close(OutputBuffer.java:251)
   		at org.apache.catalina.connector.Response.finishResponse(Response.java:441)
   		at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:374)
   		at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
   		at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
   		at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
   		at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1594)
   		at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
   		at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
   		at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
   		at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
   		at java.base/java.lang.Thread.run(Thread.java:834)
   ```
   The context is null in this case, so the NPE is thrown attempting to get the Manager:
   ```
                                            final Context context = request.getContext();
   AbstractCommitSessionValve.java:63 ->    final Manager manager = context.getManager();
   ```


----------------------------------------------------------------
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:
users@infra.apache.org