Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-12635

Http requests failed with ISPN000299 after redirect and session invalidation

    Details

    • Steps to Reproduce:
      Hide

      I attached reproducer.zip.
      $ cd hello
      $ mvn clean package wildfly:deploy

      Start up EAP with ha profile. (this issue can be reproduced with a single instance.)
      Please access the following URL via web browser.
      1. http://localhost:8080/hello/hello
      2. http://localhost:8080/hello/redirect
      3. you can see the error.
      After issue reproduced, if you send the following request from same browser, all request would be failed with the ISPN000299 continuously.
      4. http://localhost:8080/hello/log

      Unfortunately, the issue does not always occur with the reproducer.
      If it doesn't reproduce, please repeat the above step after restarting server.


      curl access also can reproduce the issue instead of browser access.

      for i in {0..1}; do 
          curl http://localhost:8080/hello/hello -c cookie.txt
          curl -L http://localhost:8080/hello/redirect -b cookie.txt
      done
      

      After reproduce, you can see that requests would be blocked with same session id with following command.

      curl http://localhost:8080/hello/log -b cookie.txt
      
      Show
      I attached reproducer.zip. $ cd hello $ mvn clean package wildfly:deploy Start up EAP with ha profile. (this issue can be reproduced with a single instance.) Please access the following URL via web browser. 1. http://localhost:8080/hello/hello 2. http://localhost:8080/hello/redirect 3. you can see the error. After issue reproduced, if you send the following request from same browser, all request would be failed with the ISPN000299 continuously. 4. http://localhost:8080/hello/log Unfortunately, the issue does not always occur with the reproducer. If it doesn't reproduce, please repeat the above step after restarting server. — curl access also can reproduce the issue instead of browser access. for i in {0..1}; do curl http: //localhost:8080/hello/hello -c cookie.txt curl -L http: //localhost:8080/hello/redirect -b cookie.txt done After reproduce, you can see that requests would be blocked with same session id with following command. curl http: //localhost:8080/hello/log -b cookie.txt
    • Workaround:
      Workaround Exists
    • Workaround Description:
      Hide

      Reproducable code:

      response.sendRedirect("./x");
      request.getSession(false).invalidate();
      

      Workaround:

      request.getSession(false).invalidate();
      response.sendRedirect("./x");
      
      Show
      Reproducable code: response.sendRedirect( "./x" ); request.getSession( false ).invalidate(); Workaround: request.getSession( false ).invalidate(); response.sendRedirect( "./x" );

      Description

      ISPN000299 occurred when invoking redirect and session invalidation on a servlet. After that happens, requests with same session id failed with the ISPN000299 continously. This issue can be occurred with a single EAP node.
      Full stacktrace is in the logs.zip.

      2019-10-01 20:22:42,655 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (async-thread--p22-t1) ISPN000136: Error executing command RemoveCommand, writing keys [SessionCreationMetaDataKey(Mvpa7i8iMTyGTgWLPVIr32P7fYzsUWAUQ2ZJIxkl)]: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key SessionCreationMetaDataKey(Mvpa7i8iMTyGTgWLPVIr32P7fYzsUWAUQ2ZJIxkl) and requestor GlobalTx:jboss_node1:17. Lock is held by GlobalTx:jboss_node1:16
      	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
      	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:218)
      	at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:436)
      	at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lambda$toInvocationStage$3(InfinispanLock.java:412)
      	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602)
      	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)
      	at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:442)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
      	at java.lang.Thread.run(Thread.java:748)
      
      2019-10-01 20:22:42,660 ERROR [io.undertow.request] (default task-1) UT005023: Exception handling request to /hello/redirect: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key SessionCreationMetaDataKey(Mvpa7i8iMTyGTgWLPVIr32P7fYzsUWAUQ2ZJIxkl) and requestor GlobalTx:jboss_node1:17. Lock is held by GlobalTx:jboss_node1:16
      	at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
      	at org.infinispan.cache.impl.CacheImpl.executeCommandWithInjectedTx(CacheImpl.java:1729)
      	at org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1707)
      	at org.infinispan.cache.impl.CacheImpl.remove(CacheImpl.java:632)
      	at org.infinispan.cache.impl.DecoratedCache.remove(DecoratedCache.java:549)
      	at org.infinispan.cache.impl.AbstractDelegatingCache.remove(AbstractDelegatingCache.java:363)
      	at org.infinispan.cache.impl.EncoderCache.remove(EncoderCache.java:683)
      	at org.infinispan.cache.impl.AbstractDelegatingCache.remove(AbstractDelegatingCache.java:363)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.remove(InfinispanSessionMetaDataFactory.java:131)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.remove(InfinispanSessionMetaDataFactory.java:119)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.remove(InfinispanSessionMetaDataFactory.java:43)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.remove(InfinispanSessionFactory.java:87)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.remove(InfinispanSessionFactory.java:37)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSession.invalidate(InfinispanSession.java:61)
      	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager$SchedulableSession.invalidate(InfinispanSessionManager.java:388)
      	at org.wildfly.clustering.web.undertow.session.DistributableSession.invalidate(DistributableSession.java:208)
      	at io.undertow.servlet.spec.HttpSessionImpl.invalidate(HttpSessionImpl.java:198)
      	at com.example.RedirectServlet.doGet(RedirectServlet.java:28)
        ...
        Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key SessionCreationMetaDataKey(Mvpa7i8iMTyGTgWLPVIr32P7fYzsUWAUQ2ZJIxkl) and requestor GlobalTx:jboss_node1:17. Lock is held by GlobalTx:jboss_node1:16
      	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
      	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:218)
      	at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:436)
      	at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lambda$toInvocationStage$3(InfinispanLock.java:412)
      	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602)
      	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)
      	at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:442)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
      	... 1 more
      	Suppressed: org.infinispan.util.logging.TraceException
      		at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
      		at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
      		at org.infinispan.cache.impl.CacheImpl.executeCommandWithInjectedTx(CacheImpl.java:1729)
      		at org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1707)
      		at org.infinispan.cache.impl.CacheImpl.remove(CacheImpl.java:632)
      		at org.infinispan.cache.impl.DecoratedCache.remove(DecoratedCache.java:549)
      		at org.infinispan.cache.impl.AbstractDelegatingCache.remove(AbstractDelegatingCache.java:363)
      		at org.infinispan.cache.impl.EncoderCache.remove(EncoderCache.java:683)
      		at org.infinispan.cache.impl.AbstractDelegatingCache.remove(AbstractDelegatingCache.java:363)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.remove(InfinispanSessionMetaDataFactory.java:131)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.remove(InfinispanSessionMetaDataFactory.java:119)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.remove(InfinispanSessionMetaDataFactory.java:43)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.remove(InfinispanSessionFactory.java:87)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.remove(InfinispanSessionFactory.java:37)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSession.invalidate(InfinispanSession.java:61)
      		at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager$SchedulableSession.invalidate(InfinispanSessionManager.java:388)
      		at org.wildfly.clustering.web.undertow.session.DistributableSession.invalidate(DistributableSession.java:208)
      		at io.undertow.servlet.spec.HttpSessionImpl.invalidate(HttpSessionImpl.java:198)
      		at com.example.RedirectServlet.doGet(RedirectServlet.java:28)
      		at javax.servlet.http.HttpServlet.service(HttpServlet.java:686)
      		at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
      		at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
      		at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
      		at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
      		at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
      		at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
      		at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      		at io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
      		at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
      		at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
      		at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      		at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
      		at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
      		at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
      		at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
      		at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
      		at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
      		at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      		at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
      		at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      		at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
      		at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
      		at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269)
      		at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
      		at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
      		at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
      		at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
      		at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
      		at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
      		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
      		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
      		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
      		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
      		at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
      		at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
      		at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
      		at io.undertow.server.Connectors.executeRootHandler(Connectors.java:376)
      		at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
      		at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
      		at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
      		at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
      		at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
      		... 1 more
      

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  rhn-support-rmartinc Ricardo Martin Camarero
                  Reporter:
                  rhn-support-rmartinc Ricardo Martin Camarero
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  1 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: