Issue #3913 Fix races in session request reference counting #3947

janbartel · 2019-08-08T07:37:38Z

#3913
Fixed races in the reference counting used by sessioncache to work out when it can evict a session. As part of fixing races, also discovered a couple of other problem cases to do with complex server-side forwarding chains to other contexts, and also problems with cleaning up sessions on async dispatches. The code is now a lot simpler and clearer in the lifecycle and reference counts for sessions.

Signed-off-by: Jan Bartel <janb@webtide.com>

olamy

very minor comment

olamy · 2019-08-08T07:49:17Z

jetty-server/src/main/java/org/eclipse/jetty/server/session/AbstractSessionCache.java

     *
     * @param id session id
     * @return the Session object matching the id
     */
-    public abstract Session doGet(String id);
+    protected abstract Session doGet(String id);


changing visibility in minor release? (maybe in 10?)

Yes, bit naughty I know. These methods should have been protected from the start. I figure that as they are only called by the session cache itself, then there should be no incompatibilities with this change.

olamy · 2019-08-08T07:49:30Z

jetty-server/src/main/java/org/eclipse/jetty/server/session/AbstractSessionCache.java

@@ -125,7 +126,7 @@
     * @param session the session object
     * @return null if the session wasn't already in the map, or the existing entry otherwise
     */
-    public abstract Session doPutIfAbsent(String id, Session session);
+    protected abstract Session doPutIfAbsent(String id, Session session);


changing visibility in minor release? (maybe in 10?)

See previous comment. I guess if I absolutely had to, I could leave the viz changes until 10 ...

olamy · 2019-08-08T07:49:37Z

jetty-server/src/main/java/org/eclipse/jetty/server/session/AbstractSessionCache.java

@@ -135,7 +136,7 @@
     * @param newValue the new value
     * @return true if replacement was done
     */
-    public abstract boolean doReplace(String id, Session oldValue, Session newValue);
+    protected abstract boolean doReplace(String id, Session oldValue, Session newValue);


changing visibility in minor release? (maybe in 10?)

As per previous comment.

sbordet · 2019-08-08T13:14:24Z

@janbartel in order to review this PR I need a clear description of what the problem is.
The issue mentions a nasty race but does not tell exactly what/where.

Also, I need a clear description of what the solution is to solve that race.

sbordet

You got to fix your formatting configuration.

Can't really review this PR without @janbartel driving me through what the problem was and how is the solution solving the problem.

The fact that many tests had to be changed to introduce a wait for the "complete" event tells me that a normal application could undergo the same race (but it won't wait for the "complete" event), so how are we dealing with this situation?

jetty-server/src/main/java/org/eclipse/jetty/server/HttpChannel.java

jetty-server/src/main/java/org/eclipse/jetty/server/Request.java

sbordet · 2019-08-08T13:00:47Z

jetty-server/src/main/java/org/eclipse/jetty/server/Request.java

+        Session session = Session.class.cast(s);
+        if (LOG.isDebugEnabled())
+            LOG.debug("Request {} leaving session {}", this, session);
+        session.getSessionHandler().complete(session);


This strikes me as asymmetric: why the "enter" event does not need to tell the SessionHandler but adds the session to the list, but the "leave" event needs to tell to the SessionHandler and not remove the session from the list?
I mean I can see the list is cleared out in recycle(), but often asymmetries of this kind are indication of a problem.

The SessionHandler tells the Request that it has entered the Session. The Request knows when it is completing, and tells the SessionHandler that it is leaving the Session. The Request could iterate over the list and remove each Session as it calls its SessionHandler with it. I just didn't bother because the next thing that happens is that the Request gets recycled.

sbordet · 2019-08-08T13:39:13Z

jetty-server/src/main/java/org/eclipse/jetty/server/session/SessionHandler.java

+                    LOG.warn(e);
+                }
+            }
+        }


This is weird to me. Javadocs for release() say that the method should be called once a request is finished with a session.
It does not strike me that the request is finished with this session before existing this method. What am I missing?

The javadoc on line 1103 says that the request reference count will be incremented by the call to sessionCache.renewSessionId; the finally clause makes sure that this increment is decremented again.

You have to consider the case where the session id exists on multiple different contexts, and thus must all be renewed when a request invokes changeId method. There may be no active requests in any of the other contexts, thus sessioncache for each context needs to load in the session if its not already present - this has to increment a reference count. If we did not then decrement the count when we've finished changing the session id, the session would sit forever in the sessioncaches of these other contexts with ref count =1. By always incrementing and decrementing for change of session id we maintain the correct behaviour of the caches.

...-sessions/test-sessions-common/src/test/java/org/eclipse/jetty/server/session/AsyncTest.java

sbordet · 2019-08-08T14:03:33Z

I'm also slightly worried about locking.
The code references many components, each of which has its own lock.
Are we always sure that the lock ordering is the same (i.e. A grabs a_lock then calls B which grabs b_lock) and we never end up in a situation where the order is inverted (B grabs b_lock and then calls A which grabs a_lock)? Because otherwise it's a possible deadlock.

Signed-off-by: Jan Bartel <janb@webtide.com>

janbartel · 2019-08-12T02:05:20Z

@sbordet re deadlocking: I believe that the locking is sound but we can discuss on hangout.

re using CountDownLatch in tests to ensure that the request has finished processing is just for testing purposes. It is true that responses can flow back to the client who may make another request before the previous request has fully exited, but there are modes on the SessionCache to deal with that (specifically SAVE_ON_CREATE to ensure that a session is immediately saved to the store, rather than lazily saved when the last request drains out). I'm not testing those other modes in the tests where I use CountDownLatches - there are other tests for that.

Signed-off-by: Jan Bartel <janb@webtide.com>

janbartel · 2019-08-12T05:28:24Z

Added comment on issue #3913 describing race condition that was fixed.

During fixing of this issue I also discovered and fixed these 2 problems:

If a request creates a session in eg contextA, forwards to a chain of other contexts, then forwards back to contextA, we will not be able to find the newly created session because we only retain the previous session & SessionHandler. Note that forwarding to only 1 other context before forwarding back to contextA the problem does not occur, because the previous context is contextA.
Async completion was not being handled correctly: we were registering an AsyncListener if asyncStarted == true when the SessionHandler exited. However the AsyncListener will only clean up a session if it was created in the same context for which async was started: if the request visits other contexts and creates sessions in them before async completion, none of those sessions will be cleaned up correctly.

For a full list of session use cases considered and verified for the fix, see the attached file.

httpsession-fix.txt

Signed-off-by: Jan Bartel <janb@webtide.com>

Issue #3913 Fix races in session request reference counting

6b28d52

Signed-off-by: Jan Bartel <janb@webtide.com>

janbartel requested review from gregw, joakime and sbordet August 8, 2019 07:37

olamy reviewed Aug 8, 2019

View reviewed changes

sbordet requested changes Aug 8, 2019

View reviewed changes

joakime added this to In Review in Jetty 9.4.21 Aug 8, 2019

joakime mentioned this pull request Aug 8, 2019

Clustered HttpSession IllegalStateException: Invalid for read #3913

Closed

Issue #3913 Fix ClusteredSessionScavengingTest

f4cac77

Signed-off-by: Jan Bartel <janb@webtide.com>

janbartel added 2 commits August 12, 2019 12:09

Issue #3913 Changes after review

8f7d98a

Signed-off-by: Jan Bartel <janb@webtide.com>

Issue #3913 Fix the fix to the ClusteredSessionScavengingTest

3e5e55f

Signed-off-by: Jan Bartel <janb@webtide.com>

janbartel added 2 commits August 12, 2019 15:33

Issue #3913 Fix the fix of the fix for ClusteredSessionScavengingTest

5ce5fad

Signed-off-by: Jan Bartel <janb@webtide.com>

Issue #3913 Fix tests

d8dbff1

Signed-off-by: Jan Bartel <janb@webtide.com>

sbordet approved these changes Aug 13, 2019

View reviewed changes

Issue #3913 Reformatted code according to checkstyle rules

4e2e36d

Signed-off-by: Jan Bartel <janb@webtide.com>

janbartel merged commit af6c675 into jetty-9.4.x Aug 15, 2019

Jetty 9.4.21 automation moved this from In Review to Done Aug 15, 2019

janbartel deleted the jetty-9.4.x-3913-session-reference-count-race branch August 15, 2019 02:27

stuban mentioned this pull request Oct 4, 2019

IllegalStateException when forwarding to jsp with new session #4156

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Issue #3913 Fix races in session request reference counting #3947

Issue #3913 Fix races in session request reference counting #3947

janbartel commented Aug 8, 2019 •

edited

olamy left a comment

olamy Aug 8, 2019

janbartel Aug 12, 2019

olamy Aug 8, 2019

janbartel Aug 12, 2019

olamy Aug 8, 2019

janbartel Aug 12, 2019

sbordet commented Aug 8, 2019

sbordet left a comment

sbordet Aug 8, 2019

janbartel Aug 12, 2019

sbordet Aug 8, 2019

janbartel Aug 12, 2019

sbordet commented Aug 8, 2019

janbartel commented Aug 12, 2019 •

edited

janbartel commented Aug 12, 2019

Issue #3913 Fix races in session request reference counting #3947

Issue #3913 Fix races in session request reference counting #3947

Conversation

janbartel commented Aug 8, 2019 • edited

olamy left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sbordet commented Aug 8, 2019

sbordet left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sbordet commented Aug 8, 2019

janbartel commented Aug 12, 2019 • edited

janbartel commented Aug 12, 2019

janbartel commented Aug 8, 2019 •

edited

janbartel commented Aug 12, 2019 •

edited