sessionwildflyinfinispandistributed-cachewildfly-17

Wildfly 17 Distributed Infinispan Cache Session not found


I'm looking into configuring wf 17 with distributed cache for sessions, but I have problems making it work properly. It's a distributed configuration, I use basic authentication and when we send the post to /j_security_check it's going to one node and the get for /index.html after the authentication is done successfully it's going to a different node. When the request arrives on the second node I have this exception :

2019-10-16 17:17:39,901 TRACE [org.wildfly.clustering.web.infinispan] (default task-9) Session _ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ not found  
2019-10-16 17:17:39,903 TRACE [org.wildfly.clustering.web.infinispan] (default task-9) Session _ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ not found  
2019-10-16 17:17:39,905 TRACE [org.wildfly.clustering.web.infinispan] (default task-9) Session _ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ not found  
2019-10-16 17:17:39,906 TRACE [org.wildfly.clustering.web.infinispan] (remote-thread--p17-t4) Session vjStKgUR6gnUne3KPr_v89S_37Dp-jc4eqNXZ1kk will be removed  
2019-10-16 17:17:39,907 TRACE [org.wildfly.clustering.web.infinispan] (default task-9) Session _ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ not found  
2019-10-16 17:17:39,965 ERROR [io.undertow.request] (default task-9) UT005023: Exception handling request to /index.html: java.lang.IllegalStateException: WFLYCLWEBUT0002: Session _ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ already exists  
        at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.createSession(DistributableSessionManager.java:169)  
        at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:918)  
        at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)  
        at io.undertow.servlet.handlers.security.ServletFormAuthenticationMechanism.storeInitialLocation(ServletFormAuthenticationMechanism.java:175)  

I can see on the other server where the /j_security_check post happened:

    contentLength=0  
       contentType=null  
            cookie=JSESSIONID=_ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ.staging-2:staging-2-wildfly; domain=null; path=/  
            header=Expires=0  
            header=Connection=close  
            header=Cache-Control=no-cache, no-store, must-revalidate  
            header=Set-Cookie=JSESSIONID="_ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ.staging-2:staging-2-wildfly"; Version=1; Path=/; Secure; HttpOnly  
            header=Pragma=no-cache  
            header=Location=....  
            header=Content-Length=0  
            header=Date=Wed, 16 Oct 2019 16:17:39 GMT  
            status=302  
2019-10-16 17:17:39,210 TRACE [org.wildfly.clustering.web.infinispan] (default task-10) Session _ttZ3PQsisp4qCdTlkY512jYoG02S3DiYgpDUGjJ will expire in 14401 sec  

My configuration for inifinispan cache is:

                <cache-container name="web" default-cache="dist" module="org.wildfly.clustering.web.infinispan">
                    <transport lock-timeout="60000"/>
                    <distributed-cache name="dist" remote-timeout="17500" l1-lifespan="0" owners="2">
                        <locking acquire-timeout="60000" isolation="READ_COMMITTED"/>
                        <transaction locking="OPTIMISTIC" mode="BATCH"/>
                        <file-store/>
                    </distributed-cache>
                </cache-container>

As long as the session is cached in infinispan how come when the request hits the second server initially it's not found but when trying to create it complains that it already exists?

Also, I tried configuring the distributable-web:1.0 wf subsystem to use the above-mentioned cache but the output is the same. Not sure if that is needed, if I have the tag in the web.xml it's going to be the same "default" distributable-web subsystem right?

A different situation that I noticed and I don't understand:

----------------------------REQUEST---------------------------  
               URI=/j_security_check  
             cookie=JSESSIONID=0Zb-sRk9GvM_NXxpOcS5SPifwCour07qm41kTujh.starscream:starscream-wildfly  
           method=POST  
--------------------------RESPONSE--------------------------  
            cookie=JSESSIONID=mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI.starscream:starscream-wildfly; domain=null; path=/  
            status=302  
==============================================================  
2019-10-17 10:06:42,347 TRACE [org.wildfly.clustering.web.infinispan] (default task-59) Session mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI will expire in 14401 sec  
2019-10-17 10:06:42,355 TRACE [org.wildfly.clustering.web.infinispan] (default task-72) Session mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI not found  
2019-10-17 10:06:42,357 TRACE [org.wildfly.clustering.web.infinispan] (default task-72) Session mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI not found  
2019-10-17 10:06:42,360 TRACE [org.wildfly.clustering.web.infinispan] (default task-72) Session mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI not found  
2019-10-17 10:06:42,409 INFO  [io.undertow.request.dump] (default task-72)   
----------------------------REQUEST---------------------------  
               URI=/index.html  
            cookie=JSESSIONID=mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI.starscream:starscream-wildfly  
            method=GET  
--------------------------RESPONSE--------------------------  
            status=200  
==============================================================  
2019-10-17 10:06:42,411 TRACE [org.wildfly.clustering.web.infinispan] (default task-72) Session mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI will expire in 14400 sec  
2019-10-17 10:06:44,333 WARN  [org.springframework.web.servlet.PageNotFound] (default task-72) No mapping found for HTTP request with URI [/j_security_check] in DispatcherServlet with name 'dispatcher'  
2019-10-17 10:06:44,347 TRACE [org.wildfly.clustering.web.infinispan] (default task-72) Session mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI will expire in 14401 sec  
2019-10-17 10:06:44,357 INFO  [io.undertow.request.dump] (default task-72)   
----------------------------REQUEST---------------------------  
               URI=/j_security_check  
            cookie=JSESSIONID=mUInjx6SmUXCXz9CJDN3IYVE8it9RGI9fMXYKTtI.starscream:starscream-wildfly  
            method=POST  
--------------------------RESPONSE--------------------------  
            status=404  

This happened on the same node, I receive the response with the above session and moments after that it's not able to find the session, eventually receiving a 404 for j_security_check.


Solution

  • The problem was that the redirected request was attempting to read the session before the previous request finished committing. Removing the transaction and locking tag solve it.