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

Http requests failed with ISPN000299 after redirect and session invalidation

    XMLWordPrintable

Details

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

    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

        Issue Links

          is cloned by

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-17922 [GSS](7.3.z) Http requests failed with ISPN000299 after redirect and session invalidation

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Verified

          Activity

            People

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

              Dates

                Created:
                Updated:
                Resolved: