search

hazelcast / hazelcast-tomcat-sessionmanager

Tomcat Based Web Session Replication
Other
33 stars 37 forks source link

Session information not fully replicated across a cluster #104

Closed manish-in-java closed 3 years ago

manish-in-java commented 3 years ago

I am trying to test Tomcat Session Manager with the following set up:

   -----------------------------------------------------
  |                                                     |
  |                   H A   P r o x y                   |
  |                                                     |
   -----------------------------------------------------
             |                                 |
             |                                 |
             |                                 |
   ---------------------           ---------------------
  |                     |         |                     |
  |   T o m c a t   1   |         |   T o m c a t   2   |
  |                     |         |                     |
   ---------------------           ---------------------

Each Tomcat instance is running a Hazelcast instance, with discovery-through -multicast turned on. HAProxy is configured to route requests to the backend Tomcat instances in a round-robin fashion, with no stickiness. I am stuck with a non-sticky set up, as this is how the final environment where I need to deploy my application, is set up.

I have deployed a single-page application on both Tomcat instances, that simply reports the session ID, whether the session is new and any attributes stored in the session. With this set up, I am running the following test:

  1. Open a browser and hit the HAProxy URL. This hits either Tomcat 1 or Tomcat 2
  2. The page that opens shows the session ID and reports that the session is newly created, as expected
  3. Refresh the page. Due to the round-robin set up, this requests now hits the other Tomcat instance
  4. The page that opens shows the same session ID and now reports that the session is not new, as expected again

However, I am finding that attributes are saved to only that Tomcat instance to which the request was directed. These are not getting replicated. Is this behaviour to be expected? Is there a way to work around this behaviour, that is, replicate session attributes to all instances in the Hazelcast cluster at the same time?

alparslanavci commented 3 years ago

Hi @manish-in-java, do you still face this issue? With non-sticky sessions, session data is moved all over the cluster every time a new request comes in. Thus your output is not expected. Could you please provide a reproducer?

alparslanavci commented 3 years ago

See this unit test for expected behaviour: https://github.com/hazelcast/hazelcast-tomcat-sessionmanager/blob/master/tomcat-core/src/test/java/com/hazelcast/session/nonsticky/AbstractNonStickySessionsTest.java#L29

manish-in-java commented 3 years ago

Hi @alparslanavci, yes, I am still facing the problem. In fact, I had to drop the idea of using Hazelcast as I faced too many problems using it out of the box. In addition to this issue with Tomcat SessionManager, I ran into another, which I have also reported. Also, I could not get Hazelcast to start on my Windows machine, for which I have reported yet another issue in the Hazelcast repository.

To your question, I have uploaded my sample application at https://drive.google.com/file/d/1dSjgwGyUqJe6cd3-QnytKJf6lvBiFv2L/view?usp=sharing. It has two fully configured Tomcat instances in folders NodeA and NodeB. You will need Java 11 or above to run the application. HA Proxy configuration has also been included.

alparslanavci commented 3 years ago

@manish-in-java I tried your example and it is working as expected in my setup. I guess the cluster somehow couldn't be formed up in your environment, thus you couldn't see the replication.

Are there any logs that you can share with us? Then I can investigate and try to help you.

manish-in-java commented 3 years ago

Hi @alparslanavci, please see the screenshots below for the problem I am facing. These show two consecutive requests, sent to two different servers. Both screenshots show the same session ID, confirming that the session exists on both servers. This is also confirmed by New = false. However, as can be seen, neither server has all attributes saved to the session. Each server has only those attributes that were submitted to it.

HTS-104

Cluster is being formed fine. If that were a problem, a new session would have been created on every request. Logs follow to confirm this:

Node 1 logs

06-Jan-2021 10:13:37.684 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8888"]
06-Jan-2021 10:13:38.375 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [1282] milliseconds
06-Jan-2021 10:13:38.432 INFO [main] com.hazelcast.config.UrlXmlConfig.null Configuring Hazelcast from 'file:/C:/Tomcat/NodeA/bin/../conf/hazelcast.xml'.
06-Jan-2021 10:13:38.812 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
06-Jan-2021 10:13:38.814 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.41]
06-Jan-2021 10:13:38.823 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [C:\Tomcat\NodeA\webapps\ROOT]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.4.0)

2021-01-06 10:13:54.024  INFO 21232 --- [           main] com.example.ServletInitializer           : Starting ServletInitializer using Java 11.0.2 on ELECTRON with PID 21232 (C:\Tomcat\NodeA\webapps\ROOT\WEB-INF\classes started by Admin in C:\Tomcat\NodeA\bin)
2021-01-06 10:13:54.046  INFO 21232 --- [           main] com.example.ServletInitializer           : No active profile set, falling back to default profiles: default
2021-01-06 10:13:57.573  INFO 21232 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 3281 ms
2021-01-06 10:13:59.414  INFO 21232 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2021-01-06 10:14:00.612  INFO 21232 --- [           main] com.example.ServletInitializer           : Started ServletInitializer in 9.117 seconds (JVM running for 23.802)
06-Jan-2021 10:14:01.936 WARNING [main] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [1,277] milliseconds.
06-Jan-2021 10:14:03.254 INFO [main] com.hazelcast.system.null [192.168.160.1]:8881 [dev] [4.1] Hazelcast 4.1 (20201104 - 2a1a477) starting at [192.168.160.1]:8881
06-Jan-2021 10:14:04.225 INFO [main] com.hazelcast.instance.impl.Node.null [192.168.160.1]:8881 [dev] [4.1] Using Multicast discovery
06-Jan-2021 10:14:04.236 WARNING [main] com.hazelcast.cp.CPSubsystem.null [192.168.160.1]:8881 [dev] [4.1] CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
06-Jan-2021 10:14:04.804 INFO [main] com.hazelcast.internal.diagnostics.Diagnostics.null [192.168.160.1]:8881 [dev] [4.1] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
06-Jan-2021 10:14:04.815 INFO [main] com.hazelcast.core.LifecycleService.null [192.168.160.1]:8881 [dev] [4.1] [192.168.160.1]:8881 is STARTING
06-Jan-2021 10:14:07.315 INFO [main] com.hazelcast.internal.cluster.ClusterService.null [192.168.160.1]:8881 [dev] [4.1]

Members {size:1, ver:1} [
        Member [192.168.160.1]:8881 - e6b6b4ba-a107-4d1c-b30c-9915dae5b652 this
]

06-Jan-2021 10:14:07.340 INFO [main] com.hazelcast.core.LifecycleService.null [192.168.160.1]:8881 [dev] [4.1] [192.168.160.1]:8881 is STARTED
06-Jan-2021 10:14:07.392 INFO [main] com.hazelcast.session.HazelcastSessionManager.startInternal HazelcastSessionManager started...
06-Jan-2021 10:14:07.433 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [C:\Tomcat\NodeA\webapps\ROOT] has finished in [28,609] ms
06-Jan-2021 10:14:07.443 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8888"]
06-Jan-2021 10:14:07.463 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [29087] milliseconds
06-Jan-2021 10:17:01.446 INFO [hz.SESSION-REPLICATION-INSTANCE.IO.thread-in-1] com.hazelcast.internal.server.tcp.TcpServerConnection.null [192.168.160.1]:8881 [dev] [4.1] Initialized new cluster connection between /192.168.160.1:8881 and /192.168.160.1:64792
06-Jan-2021 10:17:07.473 INFO [hz.SESSION-REPLICATION-INSTANCE.priority-generic-operation.thread-0] com.hazelcast.internal.cluster.ClusterService.null [192.168.160.1]:8881 [dev] [4.1]

Members {size:2, ver:4} [
        Member [192.168.160.1]:8881 - e6b6b4ba-a107-4d1c-b30c-9915dae5b652 this
        Member [192.168.160.1]:9991 - cb61fbfe-4ef1-4741-8178-b38ef1733700
]

06-Jan-2021 10:17:07.725 INFO [hz.SESSION-REPLICATION-INSTANCE.migration] com.hazelcast.internal.partition.impl.MigrationManager.null [192.168.160.1]:8881 [dev] [4.1] Repartitioning cluster data. Migration tasks count: 271
06-Jan-2021 10:17:07.997 INFO [hz.SESSION-REPLICATION-INSTANCE.migration] com.hazelcast.internal.partition.impl.MigrationManager.null [192.168.160.1]:8881 [dev] [4.1] All migration tasks have been completed. (repartitionTime=Wed Jan 06 10:17:07 IST 2021, plannedMigrations=271, completedMigrations=271, remainingMigrations=0, totalCompletedMigrations=407)

Node 2 logs

06-Jan-2021 10:16:41.179 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-9999"]
06-Jan-2021 10:16:41.810 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [1252] milliseconds
06-Jan-2021 10:16:41.854 INFO [main] com.hazelcast.config.UrlXmlConfig.null Configuring Hazelcast from 'file:/C:/Tomcat/NodeB/bin/../conf/hazelcast.xml'.
06-Jan-2021 10:16:42.262 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
06-Jan-2021 10:16:42.263 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.41]
06-Jan-2021 10:16:42.275 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [C:\Tomcat\NodeB\webapps\ROOT]

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.4.0)

2021-01-06 10:16:53.754  INFO 19020 --- [           main] com.example.ServletInitializer           : Starting ServletInitializer using Java 11.0.2 on ELECTRON with PID 19020 (C:\Tomcat\NodeB\webapps\ROOT\WEB-INF\classes started by Admin in C:\Tomcat\NodeB\bin)
2021-01-06 10:16:53.770  INFO 19020 --- [           main] com.example.ServletInitializer           : No active profile set, falling back to default profiles: default
2021-01-06 10:16:56.036  INFO 19020 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2099 ms
2021-01-06 10:16:57.267  INFO 19020 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2021-01-06 10:16:58.157  INFO 19020 --- [           main] com.example.ServletInitializer           : Started ServletInitializer in 5.902 seconds (JVM running for 17.893)
06-Jan-2021 10:16:59.143 WARNING [main] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [951] milliseconds.
06-Jan-2021 10:17:00.032 INFO [main] com.hazelcast.system.null [192.168.160.1]:9991 [dev] [4.1] Hazelcast 4.1 (20201104 - 2a1a477) starting at [192.168.160.1]:9991
06-Jan-2021 10:17:00.758 INFO [main] com.hazelcast.instance.impl.Node.null [192.168.160.1]:9991 [dev] [4.1] Using Multicast discovery
06-Jan-2021 10:17:00.768 WARNING [main] com.hazelcast.cp.CPSubsystem.null [192.168.160.1]:9991 [dev] [4.1] CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
06-Jan-2021 10:17:01.184 INFO [main] com.hazelcast.internal.diagnostics.Diagnostics.null [192.168.160.1]:9991 [dev] [4.1] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
06-Jan-2021 10:17:01.196 INFO [main] com.hazelcast.core.LifecycleService.null [192.168.160.1]:9991 [dev] [4.1] [192.168.160.1]:9991 is STARTING
06-Jan-2021 10:17:01.400 INFO [main] com.hazelcast.internal.cluster.impl.MulticastJoiner.null [192.168.160.1]:9991 [dev] [4.1] Trying to join to discovered node: [192.168.160.1]:8881
06-Jan-2021 10:17:01.453 INFO [hz.SESSION-REPLICATION-INSTANCE.IO.thread-in-0] com.hazelcast.internal.server.tcp.TcpServerConnection.null [192.168.160.1]:9991 [dev] [4.1] Initialized new cluster connection between /192.168.160.1:64792 and /192.168.160.1:8881
06-Jan-2021 10:17:07.483 INFO [hz.SESSION-REPLICATION-INSTANCE.priority-generic-operation.thread-0] com.hazelcast.internal.cluster.ClusterService.null [192.168.160.1]:9991 [dev] [4.1]

Members {size:2, ver:4} [
        Member [192.168.160.1]:8881 - e6b6b4ba-a107-4d1c-b30c-9915dae5b652
        Member [192.168.160.1]:9991 - cb61fbfe-4ef1-4741-8178-b38ef1733700 this
]

06-Jan-2021 10:17:08.489 INFO [main] com.hazelcast.core.LifecycleService.null [192.168.160.1]:9991 [dev] [4.1] [192.168.160.1]:9991 is STARTED
06-Jan-2021 10:17:08.490 INFO [main] com.hazelcast.session.HazelcastSessionManager.startInternal HazelcastSessionManager started...
06-Jan-2021 10:17:08.524 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [C:\Tomcat\NodeB\webapps\ROOT] has finished in [26,249] ms
06-Jan-2021 10:17:08.532 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-9999"]
06-Jan-2021 10:17:08.549 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [26738] milliseconds

Note

I realize that I have shared the most recent version of the sample application I was playing around with. I am not sure what changes I made to it as I did not document the changes. In the version I have shared with you, the Tomcat configuration file context.xml has the following line:

  <Manager className="com.hazelcast.session.HazelcastSessionManager" deferredWrite="false" sticky="false" />

In the original version, where I am having problems, and which I created by simply following instructions provided in this Git repository, the same file has the following line:

  <Manager className="com.hazelcast.session.HazelcastSessionManager"/>

Since you have reported that you are not facing any problems, could it be that deferredWrite="false" sticky="false" has an impact? If yes, I would strongly suggest that the documentation be updated to include alternative configurations for alternative scenarios. Otherwise, one will have to go through a lot of trial-and-error to figure out what configuration works in what scenario.

alparslanavci commented 3 years ago

@manish-in-java Thanks for the detailed explanation. But it looks you hit an expected behaviour. You mention that you used the following configuration in your original (the one you had problems) setup:

 <Manager className="com.hazelcast.session.HazelcastSessionManager"/>

Since sticky sessions are default, this means that you are NOT using non-sticky sessions as you mentioned before. When using sticky sessions, sessions do not move around the cluster and the sessions are retrieved from the local Tomcat in regular calls. This setup only covers the failover scenarios, which means that you'll get the replicated session data when one of the containers crashed.

This is explained in the documentation, please see the following link: https://github.com/hazelcast/hazelcast-tomcat-sessionmanager#sticky-sessions-and-tomcat

I am closing this issue right now. Please feel free to comment if you have any other issues.