Inconsistent sessions between the clustered applications using Jgroups

[fudifudi1993]

deploy two applications in two different JVMs
app1(single war) in JVM1 with Server ID host1:8080
app2(single war) in JVM2 with Server ID host2:9080
config the interaction between two applications with the jgroups.xml copying from cuba-core-7.2.5.jar!/jgroups.xml without any modification.

my question is when logging the sessions with userSessionService.loadUserSessionEntities(UserSessionService.Filter.ALL)，that shows app1 is always different from sessions of app2, eg: app2.sessions = {1,2,3} app1.sessions = {2,4}， why their sharing data are inconsistent?
the log code is

        log.debug("LogSerssionBean PostConstructing...");
        ScheduledFuture<?> handler = executorService.scheduleAtFixedRate(() -> {
            log.debug("LogSerssionBean sessions printing...");
            try {
                authentication.begin();
                for (UserSessionEntity session : userSessionService.loadUserSessionEntities(UserSessionService.Filter.ALL)) {
                    log.debug(String.format("current sessions: %s ", session.toString()));
                }
                authentication.end();
            } catch (Exception e) {
                log.error("error", e);
            }
            log.debug("LogSerssionBean sessions printed");
        },1, 1, TimeUnit.MINUTES);

the app1.log

2020-07-07 11:54:25.516 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=5ddd775a-ad91-63ef-dac0-9bdda92a079e, login=admin, user=Administrator, since=Tue Jul 07 11:52:25 CST 2020, last=Tue Jul 07 11:54:25 CST 2020 
2020-07-07 11:54:25.516 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=ef0894db-4f59-d97d-dbac-4b3d1fc8e349, login=anonymous, user=Anonymous, since=Tue Jul 07 11:51:33 CST 2020, last=Tue Jul 07 11:51:33 CST 2020 

the app2.log

2020-07-07 11:52:38.867 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=a988b0a3-cb62-7b84-3870-9bc6e9ab8ac3, login=admin, user=Administrator, since=Tue Jul 07 11:52:38 CST 2020, last=Tue Jul 07 11:52:38 CST 2020 
2020-07-07 11:52:38.867 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=ef0894db-4f59-d97d-dbac-4b3d1fc8e349, login=anonymous, user=Anonymous, since=Tue Jul 07 11:51:33 CST 2020, last=Tue Jul 07 11:51:33 CST 2020 
2020-07-07 11:52:38.867 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=584e3374-0193-c2e1-4d7e-819dbc2dd72a, login=anonymous, user=Anonymous, since=Tue Jul 07 11:51:42 CST 2020, last=Tue Jul 07 11:51:42 CST 2020 

[albudarov (Alexander Budarov)]

Hi,
“anonymous” user session is a system session. System sessions are not replicated to other cluster nodes, they are used only locally on one node.

[albudarov (Alexander Budarov)]

In your case even “admin” sessions are different between nodes.
I suspect that jgroups cluster is not working in your environment (maybe, closed ports between servers).

You can check state of your jgroups cluster in the JMX console screen. Check state of these JMX beans:

• app-core.cuba:type=ClusterManager (started, currentView, master)
• app-core.jgroups:type=channel,cluster=“cubaCluster” (view)

[fudifudi1993]

access app1 through chrome

access app2 through safari

it looks the cluster is well?
and the log app1

2020-07-08 17:44:12.283 DEBUG [pool-7-thread-1] moe.dam.devra.core.LogSerssionBean - LogSerssionBean sessions printing...
2020-07-08 17:44:12.284 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=003d1180-5d2f-5636-7b1f-0c0141ba49d4, login=anonymous, user=Anonymous, since=Wed Jul 08 17:13:18 CST 2020, last=Wed Jul 08 17:13:20 CST 2020 
2020-07-08 17:44:12.284 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=9a64d60c-d87b-0cb5-33a7-720526793489, login=admin, user=Administrator, since=Wed Jul 08 17:19:26 CST 2020, last=Wed Jul 08 17:39:24 CST 2020 
2020-07-08 17:44:12.284 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=283856ee-5e25-3d73-46d0-fc04869c58e0, login=admin, user=Administrator, since=Wed Jul 08 17:14:12 CST 2020, last=Wed Jul 08 17:44:12 CST 2020 
2020-07-08 17:44:12.284 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=408d2597-72aa-40fb-be5e-8b2484a8ff40, login=admin, user=Administrator, since=Wed Jul 08 17:14:05 CST 2020, last=Wed Jul 08 17:43:22 CST 2020 
2020-07-08 17:44:12.284 DEBUG [pool-7-thread-1] moe.dam.devra.core.LogSerssionBean - LogSerssionBean sessions printed

log app2

2020-07-08 17:43:23.937 DEBUG [pool-7-thread-1] moe.dam.devra.core.LogSerssionBean - LogSerssionBean sessions printing...
2020-07-08 17:43:23.938 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=003d1180-5d2f-5636-7b1f-0c0141ba49d4, login=anonymous, user=Anonymous, since=Wed Jul 08 17:13:18 CST 2020, last=Wed Jul 08 17:13:20 CST 2020 
2020-07-08 17:43:23.950 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=9a64d60c-d87b-0cb5-33a7-720526793489, login=admin, user=Administrator, since=Wed Jul 08 17:19:26 CST 2020, last=Wed Jul 08 17:39:24 CST 2020 
2020-07-08 17:43:23.950 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=76108f5c-8988-16d5-41d3-8a4571597199, login=anonymous, user=Anonymous, since=Wed Jul 08 17:14:27 CST 2020, last=Wed Jul 08 17:18:01 CST 2020 
2020-07-08 17:43:23.950 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=283856ee-5e25-3d73-46d0-fc04869c58e0, login=admin, user=Administrator, since=Wed Jul 08 17:14:12 CST 2020, last=Wed Jul 08 17:14:12 CST 2020 
2020-07-08 17:43:23.950 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=408d2597-72aa-40fb-be5e-8b2484a8ff40, login=admin, user=Administrator, since=Wed Jul 08 17:14:05 CST 2020, last=Wed Jul 08 17:43:22 CST 2020 
2020-07-08 17:43:23.950 DEBUG [pool-7-thread-1/devra-core/admin] moe.dam.devra.core.LogSerssionBean - current sessions: id=7087649a-d508-d777-4273-43c6647c75a5, login=admin, user=Administrator, since=Wed Jul 08 17:15:24 CST 2020, last=Wed Jul 08 17:43:23 CST 2020 
2020-07-08 17:43:23.951 DEBUG [pool-7-thread-1] moe.dam.devra.core.LogSerssionBean - LogSerssionBean sessions printed

[albudarov (Alexander Budarov)]

The cluster state looks well.

If you experience problems with session replication, you can enable debug logging for the following categories and look at the messages to investigate what is going on under the hood.

• “com.haulmont.cuba.security.app.UserSessions” (DEBUG)
• “com.haulmont.cuba.core.app.ClusterManager” (DEBUG or TRACE)

[fudifudi1993]

I got the emphasized log, found that the master(app1) shared its both system sessions which one is anonymous and the other one generated from authentication.begin() as above code shows to the slave(app2), but the slave didn’t send its system sessions to master. Why did the master share it system session to slave?
the app1 emphasized log

2020-07-09 00:01:27.193 DEBUG [ClusterManagerMessageSender-8] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:01:27 CST 2020 (14067 bytes)
2020-07-09 00:01:35.430 DEBUG [ClusterManagerMessageSender-9] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: a023659c-fe59-12c7-18b4-57aa29450c68 [admin], since: Wed Jul 08 23:59:12 CST 2020, lastUsed: Thu Jul 09 00:01:35 CST 2020 (14115 bytes)
2020-07-09 00:02:23.726 DEBUG [jgroups-31,cubaCluster,DESKTOP-DSU3GNL-57474] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:02:23 CST 2020 (14115 bytes)
2020-07-09 00:02:23.729 DEBUG [jgroups-31,cubaCluster,DESKTOP-DSU3GNL-57474] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:02:23 CST 2020 (14115 bytes)
2020-07-09 00:02:33.855 DEBUG [jgroups-31,cubaCluster,DESKTOP-DSU3GNL-57474] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:02:33 CST 2020 (14115 bytes)
2020-07-09 00:02:37.062 DEBUG [ClusterManagerMessageSender-10] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:02:37 CST 2020 (14067 bytes)
2020-07-09 00:05:50.276 DEBUG [ClusterManagerMessageSender-11] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:05:50 CST 2020 (14067 bytes)
2020-07-09 00:08:12.358 DEBUG [ClusterManagerMessageSender-12] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:08:12 CST 2020 (14067 bytes)
2020-07-09 00:08:23.789 DEBUG [ClusterManagerMessageSender-13] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:08:23 CST 2020 (14067 bytes)
2020-07-09 00:08:24.105 DEBUG [ClusterManagerMessageSender-14] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.core.app.dynamicattributes.DynamicAttributesManager$ReloadCacheMsg: com.haulmont.cuba.core.app.dynamicattributes.DynamicAttributesManager$ReloadCacheMsg@70a9070f (105 bytes)
2020-07-09 00:09:52.468 DEBUG [jgroups-37,cubaCluster,DESKTOP-DSU3GNL-57474] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:09:52 CST 2020 (14115 bytes)
2020-07-09 00:11:09.727 DEBUG [ClusterManagerMessageSender-15] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:11:09 CST 2020 (14067 bytes)
2020-07-09 00:12:21.232 DEBUG [jgroups-39,cubaCluster,DESKTOP-DSU3GNL-57474] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:12:21 CST 2020 (14115 bytes)
2020-07-09 00:15:50.364 DEBUG [ClusterManagerMessageSender-16] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:15:50 CST 2020 (14067 bytes)

the app1 emphasized log

2020-07-09 00:01:27.193 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:01:27 CST 2020 (14067 bytes)
2020-07-09 00:01:35.434 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: a023659c-fe59-12c7-18b4-57aa29450c68 [admin], since: Wed Jul 08 23:59:12 CST 2020, lastUsed: Thu Jul 09 00:01:35 CST 2020 (14115 bytes)
2020-07-09 00:02:23.636 DEBUG [ClusterManagerMessageSender-0] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:02:23 CST 2020 (14115 bytes)
2020-07-09 00:02:23.644 DEBUG [ClusterManagerMessageSender-1] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:02:23 CST 2020 (14115 bytes)
2020-07-09 00:02:33.847 DEBUG [ClusterManagerMessageSender-2] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:02:33 CST 2020 (14115 bytes)
2020-07-09 00:02:37.062 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:02:37 CST 2020 (14067 bytes)
2020-07-09 00:05:50.282 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:05:50 CST 2020 (14067 bytes)
2020-07-09 00:08:12.362 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:08:12 CST 2020 (14067 bytes)
2020-07-09 00:08:23.791 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:08:23 CST 2020 (14067 bytes)
2020-07-09 00:08:24.115 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.core.app.dynamicattributes.DynamicAttributesManager$ReloadCacheMsg: com.haulmont.cuba.core.app.dynamicattributes.DynamicAttributesManager$ReloadCacheMsg@418f9cdf (105 bytes)
2020-07-09 00:09:52.465 DEBUG [ClusterManagerMessageSender-3] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:09:52 CST 2020 (14115 bytes)
2020-07-09 00:11:09.727 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:11:09 CST 2020 (14067 bytes)
2020-07-09 00:12:21.216 DEBUG [ClusterManagerMessageSender-4] com.haulmont.cuba.core.app.ClusterManager - Sending message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: e4c42c49-bb58-fe9c-e3cd-4de86edb7af0 [admin], since: Thu Jul 09 00:02:23 CST 2020, lastUsed: Thu Jul 09 00:12:21 CST 2020 (14115 bytes)
2020-07-09 00:15:50.364 DEBUG [jgroups-11,cubaCluster,DESKTOP-DSU3GNL-58440] com.haulmont.cuba.core.app.ClusterManager - Received message: class com.haulmont.cuba.security.app.UserSessions$UserSessionInfo: fb6d7e9b-916b-b5be-b464-4360cf5da7b9 [admin], since: Wed Jul 08 23:45:54 CST 2020, lastUsed: Thu Jul 09 00:15:50 CST 2020 (14067 bytes)

and the app1 user session browse show:

the app2 user session browse show:

1046ce34-ea6b-9be2-fc85-8b45c4805bbf(anonymous) and 5ca50835-0d5a-7a6c-a0ba-1972f329944c(admin in System authentication) in app2 aren’t shared

[albudarov (Alexander Budarov)]

I have some ideas about why this can happen, I’ll check them later.

Do you have any problems because of user sessions not being identically replicated between cluster nodes?

[fudifudi1993]

@AlexBudarov thanks very much for your reply.
My cluster is

the web1 and core1 are packed in single war, so do the web2 and core2, the Apache load balancer is configuring turning off sticky session.
I wonder if Cuba Platform supports expected deployment topology? The architecture is different from any topology describing in Application Scaling document? If so, why it always show session expired when I come to the login page. I expect the load balancer to route all requests randomly to the application instances other than one user’s requests route to exact one in its total session life (which the sticky session does). what my requirement is protecting users from re-logining when one instance crashes. I guess my problem is related to the inconsistent sessions.

Any idea to implement my requirement?

[fudifudi1993]

It seems that my requirement is called Single Sign On in multiple same instances. Can’t the above architecture do that? if the answer is it can’t, what is the primary purpose of the shared sessions? I found the addon IDP which may be the right one, yes?

[krivopustov (Konstantin Krivopustov)]

@fudifudi1993

found that the master(app1) shared its both system sessions which one is anonymous and the other one generated from authentication.begin() as above code shows to the slave(app2), but the slave didn’t send its system sessions to master. Why did the master share it system session to slave?

This is because when the second node starts, it grabs all sessions currently existing on master including the system ones - this is a process of “receiving the cluster state”. These system sessions are useless on
the receiving node, but they don’t harm either.

@fudifudi1993

the Apache load balancer is configuring turning off sticky session.

This is the cause of the problem - you have to turn sticky sessions on. HTTP sessions are not replicated between web nodes, so your users must go only to the node that logged them in and has their UI state.

[fudifudi1993]

Thanks very much your reply, I really appreciate that you have solved the trouble comfusing me quite a while. may I have a convenient way to implement that route all requests randomly to the application instances other than one user’s requests route to exact one in its total session life (which the sticky session does), I don’t want to use sticky session, it asks user to re-login after one instance crashed. Or is there a way to store all sessions in Redis? every node request session will read from Redis and every login will write the session to Redis.

[krivopustov (Konstantin Krivopustov)]

Unfortunately, it’s impossible to replicate HTTP sessions because they contain the whole user’s UI state, and this is a massive chunk of data (usually 5…10MB) containing also non-serializable classes. Consider this as a cost of convenient Java-only UI development approach.