Uploaded image for project: 'Undertow'
  1. Undertow
  2. UNDERTOW-2313

NPE occurs in session invalidation if a session creation attempt hits UNDERTOW-1971

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • 2.3.9.Final, 2.2.27.Final
    • 2.2.26.SP1
    • Core
    • None
    • Hide

      This is a race condition so byteman helps to hit it deterministically instead of randomly. To reproduce, deploy the ut2313.ear and enable byteman in your JVM options with the attached rule:

      -javaagent:<mypath>/lib/byteman.jar=script:<mypath>/ut2313.btm,sys:<mypath>/lib/byteman.jar

      Then attempt requests:
      1. http://localhost:8080/helloworld/hi.jsp
      2. Then from multiple browser tabs after that completes, concurrent requests to http://localhost:8080/helloworld2/hi2.jsp
      A simple one liner to do that from the command line with curl:

      curl -c /tmp/cookies.txt http://localhost:8080/helloworld/hi.jsp; sleep 2; curl -b /tmp/cookies.txt http://localhost:8080/helloworld2/hi2.jsp & curl -b /tmp/cookies.txt http://localhost:8080/helloworld2/hi2.jsp
      Show
      This is a race condition so byteman helps to hit it deterministically instead of randomly. To reproduce, deploy the ut2313.ear and enable byteman in your JVM options with the attached rule: -javaagent:<mypath>/lib/byteman.jar=script:<mypath>/ut2313.btm,sys:<mypath>/lib/byteman.jar Then attempt requests: 1. http://localhost:8080/helloworld/hi.jsp 2. Then from multiple browser tabs after that completes, concurrent requests to http://localhost:8080/helloworld2/hi2.jsp A simple one liner to do that from the command line with curl: curl -c /tmp/cookies.txt http: //localhost:8080/helloworld/hi.jsp; sleep 2; curl -b /tmp/cookies.txt http://localhost:8080/helloworld2/hi2.jsp & curl -b /tmp/cookies.txt http://localhost:8080/helloworld2/hi2.jsp

      If a session creation attempt hits the point addressed by UNDERTOW-1971, an IllegalStateException no longer occurs, but it leaves an empty session with a pending expiration task that hits a NullPointerException. That's because the IllegalStateException is still thrown in a concurrent session create attempt here so it short circuits the creation attempt to leave an empty session with a scheduled expiration task but no set id. That is evidenced by undertow TRACE logs showing multiple session timeouts set but only one session created with an id in the end:

      2023-09-26 16:02:27,559 DEBUG [io.undertow.session] (default task-1) Setting max inactive interval for null to 60
2023-09-26 16:02:27,559 DEBUG [io.undertow.session] (default task-3) Setting max inactive interval for null to 60
2023-09-26 16:02:27,559 DEBUG [io.undertow.session] (default task-4) Setting max inactive interval for null to 60
2023-09-26 16:02:27,559 DEBUG [io.undertow.session] (default task-5) Setting max inactive interval for null to 60
2023-09-26 16:02:27,559 DEBUG [io.undertow.session] (default task-6) Setting max inactive interval for null to 60
2023-09-26 16:02:27,559 TRACE [io.undertow.session] (default task-4) Bumping timeout for session null to 1695758607559
2023-09-26 16:02:27,559 TRACE [io.undertow.session] (default task-3) Bumping timeout for session null to 1695758607559
2023-09-26 16:02:27,559 TRACE [io.undertow.session] (default task-1) Bumping timeout for session null to 1695758607559
2023-09-26 16:02:27,559 TRACE [io.undertow.session] (default task-6) Bumping timeout for session null to 1695758607559
2023-09-26 16:02:27,559 TRACE [io.undertow.session] (default task-5) Bumping timeout for session null to 1695758607559
2023-09-26 16:02:27,559 DEBUG [io.undertow.session] (default task-1) Created session with id yGgLDELJ21Oe_6Ub-6opC4QDzbYSB7hbdAuAXym7 for exchange HttpServerExchange{ GET /helloworld2/hi2.jsp}

      So then all the creation attempts that failed with that now safely handled IllegalStateException hit this NPE upon reaching their timeout:

      2023-09-26 16:03:27,620 ERROR [org.jboss.threads.errors] (default task-7) Thread Thread[default task-7,5,main] threw an uncaught exception: java.lang.NullPointerException
	at java.base/java.util.concurrent.ConcurrentHashMap.replaceNode(ConcurrentHashMap.java:1111)
	at java.base/java.util.concurrent.ConcurrentHashMap.remove(ConcurrentHashMap.java:1102)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl.invalidate(InMemorySessionManager.java:609)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl$2$1.run(InMemorySessionManager.java:417)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at org.jboss.xnio@3.8.9.Final-redhat-00001//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
	at java.base/java.lang.Thread.run(Thread.java:829)

2023-09-26 16:03:27,621 ERROR [org.jboss.threads.errors] (default task-6) Thread Thread[default task-6,5,main] threw an uncaught exception: java.lang.NullPointerException
	at java.base/java.util.concurrent.ConcurrentHashMap.replaceNode(ConcurrentHashMap.java:1111)
	at java.base/java.util.concurrent.ConcurrentHashMap.remove(ConcurrentHashMap.java:1102)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl.invalidate(InMemorySessionManager.java:609)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl$2$1.run(InMemorySessionManager.java:417)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at org.jboss.xnio@3.8.9.Final-redhat-00001//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
	at java.base/java.lang.Thread.run(Thread.java:829)

2023-09-26 16:03:27,621 ERROR [org.jboss.threads.errors] (default task-5) Thread Thread[default task-5,5,main] threw an uncaught exception: java.lang.NullPointerException
	at java.base/java.util.concurrent.ConcurrentHashMap.replaceNode(ConcurrentHashMap.java:1111)
	at java.base/java.util.concurrent.ConcurrentHashMap.remove(ConcurrentHashMap.java:1102)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl.invalidate(InMemorySessionManager.java:609)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl$2$1.run(InMemorySessionManager.java:417)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at org.jboss.xnio@3.8.9.Final-redhat-00001//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
	at java.base/java.lang.Thread.run(Thread.java:829)

2023-09-26 16:03:27,622 ERROR [org.jboss.threads.errors] (default task-8) Thread Thread[default task-8,5,main] threw an uncaught exception: java.lang.NullPointerException
	at java.base/java.util.concurrent.ConcurrentHashMap.replaceNode(ConcurrentHashMap.java:1111)
	at java.base/java.util.concurrent.ConcurrentHashMap.remove(ConcurrentHashMap.java:1102)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl.invalidate(InMemorySessionManager.java:609)
	at io.undertow.core@2.2.25.SP3-redhat-00001//io.undertow.server.session.InMemorySessionManager$SessionImpl$2$1.run(InMemorySessionManager.java:417)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads@2.4.0.Final-redhat-00001//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1348)
	at org.jboss.xnio@3.8.9.Final-redhat-00001//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
	at java.base/java.lang.Thread.run(Thread.java:829)

      It's ultimately a failure just expiring an empty session so seems it'd be no net impact in the end other than the unwanted ERROR log chatter.

        1. ut2313reproducer.zip
          2 kB

              flaviarnn Flavia Rainone
              rhn-support-aogburn Aaron Ogburn
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: