Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-17682

[GSS](7.2.z) Http requests failed with ISPN000299 after redirect and session invalidation

    XMLWordPrintable

Details

    • +
    • Workaround Exists
    • 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" );
    • 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

    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
      

      Attachments

        1. logs.zip
          35 kB
        2. reproducer.zip
          11 kB
        3. server_2nd.log
          45 kB

        Issue Links

          Activity

            People

              rpelisse@redhat.com Romain Pelisse
              rhn-support-hdaicho Hiroki Daicho (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: