jGroups/Infinispan Bedevilling: No DB Table Created (Unable to persist Infinispan internal caches as no global state enabled)

1

The following are the build, start, cache-config-file use — and the resultant logs.

Would any kind soul be able to review what could be missed?

The DB table is nbot created – and when created manually, it’s not populated.

BUILD Script

export KC_BUILD_OPTS="$KC_BUILD_OPTS --db=oracle"
export KC_BUILD_OPTS="$KC_BUILD_OPTS --cache-config-file=cache-ispn-jdbc-ping.xml"

START Script

export KC_START_OPTS="$KC_START_OPTS --proxy=edge"
export KC_START_OPTS="$KC_START_OPTS --hostname-strict=false"
export KC_START_OPTS="$KC_START_OPTS --auto-build"
export KC_START_OPTS="$KC_START_OPTS --http-relative-path=/auth/"
export KC_START_OPTS="$KC_START_OPTS --cache-stack=tcp"
export KC_START_OPTS="$KC_START_OPTS --log=console,file"
export KC_START_OPTS="$KC_START_OPTS --log-level=INFO"
export KC_START_OPTS="$KC_START_OPTS --log-file=/var/log/keycloak/keycloak.log"

cache-ispn-jdbc-ping.xml

<?xml version="1.0" encoding="UTF-8"?>
<infinispan
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="urn:infinispan:config:11.0 http://www.infinispan.org/schemas/infinispan-config-11.0.xsd"
    xmlns="urn:infinispan:config:11.0">

  <!-- custom stack goes into the jgroups element -->
<jgroups>
    <stack name="jdbc-ping-tcp" extends="tcp">
      <JDBC_PING connection_driver="oracle.jdbc.driver.OracleDriver"
                 connection_username="keycloak"
                 connection_password="password"
                 connection_url="jdbc:oracle:thin:@db.com:1524/keycloak"
                 initialize_sql="CREATE TABLE JGROUPSPING (own_addr varchar2(200) NOT NULL, cluster_name varchar2(200) NOT NULL,ping_data BLOB,constraint PK_JGROUPSPING PRIMARY KEY (own_addr, cluster_name));"
                 info_writer_sleep_time="500"
                 remove_all_data_on_view_change="true"
                 stack.combine="REPLACE"
                 stack.position="MPING" />
    </stack>
  </jgroups>

  <cache-container name="keycloak">
    <!-- custom stack must be referenced by name in the stack attribute of the transport element -->
    <transport lock-timeout="60000" stack="jdbc-ping-tcp"/>
    <local-cache name="realms">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <memory max-count="10000"/>
    </local-cache>
    <local-cache name="users">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <memory max-count="10000"/>
    </local-cache>
    <distributed-cache name="sessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="authenticationSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="offlineSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="clientSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="offlineClientSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="loginFailures" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <local-cache name="authorization">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <memory max-count="10000"/>
    </local-cache>
    <replicated-cache name="work">
      <expiration lifespan="-1"/>
    </replicated-cache>
    <local-cache name="keys">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <expiration max-idle="3600000"/>
      <memory max-count="1000"/>
    </local-cache>
    <distributed-cache name="actionTokens" owners="2">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <expiration max-idle="-1" lifespan="-1" interval="300000"/>
      <memory max-count="-1"/>
    </distributed-cache>
  </cache-container>
</infinispan>

LOGS

2022-06-29 09:21:01,683 INFO  [org.keycloak.quarkus.runtime.hostname.DefaultHostnameProvider] (main) Hostname settings: FrontEnd: snip.com, Strict HTTPS: true, Path: <request>, Strict BackChannel: false, Admin: <request>, Port: -1, Proxied: true
2022-06-29 09:21:03,982 WARN  [org.infinispan.PERSISTENCE] (keycloak-cache-init) ISPN000554: jboss-marshalling is deprecated and planned for removal
2022-06-29 09:21:04,116 WARN  [org.infinispan.CONFIG] (keycloak-cache-init) ISPN000569: Unable to persist Infinispan internal caches as no global state enabled
2022-06-29 09:21:04,174 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000556: Starting user marshaller 'org.infinispan.jboss.marshalling.core.JBossUserMarshaller'
2022-06-29 09:21:04,939 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000128: Infinispan version: Infinispan 'Triskaidekaphobia' 13.0.9.Final
2022-06-29 09:21:05,293 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000078: Starting JGroups channel `ISPN`
2022-06-29 09:21:07,565 INFO  [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-46-35724: no members discovered after 2002 ms: creating cluster as coordinator
2022-06-29 09:21:07,573 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000094: Received new cluster view for channel ISPN: [ip-snip] (1) [ip-1snip]
2022-06-29 09:21:07,579 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000079: Channel `ISPN` local address is `ip-10-57-226-46-35724`, physical addresses are `[10.57.226.46:7800]`
2022-06-29 09:21:08,359 INFO  [org.keycloak.connections.infinispan.DefaultInfinispanConnectionProviderFactory] (main) Node name: ip-10-57-226-46-35724, Site name: null
2022-06-29 09:21:08,653 INFO  [io.quarkus] (main) Keycloak 18.0.1 on JVM (powered by Quarkus 2.7.5.Final) started in 12.582s. Listening on: http://0.0.0.0:8080
2022-06-29 09:21:08,654 INFO  [io.quarkus] (main) Profile prod activated.
2022-06-29 09:21:08,655 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, jdbc-h2, jdbc-mariadb, jdbc-mssql, jdbc-mysql, jdbc-oracle, jdbc-postgresql, keycloak, narayana-jta, reactive-routes, resteasy, resteasy-jackson, smallrye-context-propagation, smallrye-health, smallrye-metrics, vault, vertx]
Preserve user sessions over Keycloak restart
Preserve user sessions over Keycloak restart
2

You probably mixing things up here…

  1. The warning(!) Unable to persist Infinispan internal caches... is not related to your desired JDBC_PING configuration. This is just a warning, that the infinispan cache is not persisted and only held in memory. JDBC_PING only holds the node registry of the participating nodes in a database table, nothing more.

  2. As you define separate build opts and start opts, I assume (you didn’t it mention explicitly) you also doing a separate build step before starting the server. In your start opts, you have the --auto-build option, but the previous build opts are not contained in the start opts, but you define a separate cache-stack=tcp, so Keycloak (Quarkus) will do another build (b/c --auto-build) using the TCP cache-stack, not your custom cache-config-file. If your cache config would be used, you’d see it in the line of Starting JGroups channel ISPN mentioning your cache config name. I’d suggest to remove the auto-build and cache-stack options from you start opts (and moving the http-relative-path to the build opts)!

In general, the approach from @xgp does work, perhaps with a few adjustments to your environment (depending on the database used, etc.): Keycloak 17 example using JGroups JDBC_PING discovery protocol for Infinispan · GitHub

1 Like
3

Thank you @dasniko . That was very helpful.

The stack is now being detected.

Next to solve: The database table isn’t being created or populated (if I create the table manually). The DEBUG -level logs haven’t provided a clue so far.

1 -LOG

2022-06-30 00:12:22,248 INFO  [org.keycloak.quarkus.runtime.hostname.DefaultHostnameProvider] (main) Hostname settings: FrontEnd: example.com, Strict HTTPS: true, Path: <request>, Strict BackChannel: false, Admin: <request>, Port: -1, Proxied: true
2022-06-30 00:12:23,410 WARN  [org.infinispan.PERSISTENCE] (keycloak-cache-init) ISPN000554: jboss-marshalling is deprecated and planned for removal
2022-06-30 00:12:23,506 WARN  [org.infinispan.CONFIG] (keycloak-cache-init) ISPN000569: Unable to persist Infinispan internal caches as no global state enabled
2022-06-30 00:12:23,520 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000556: Starting user marshaller 'org.infinispan.jboss.marshalling.core.JBossUserMarshaller'
2022-06-30 00:12:23,874 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000128: Infinispan version: Infinispan 'Triskaidekaphobia' 13.0.9.Final
2022-06-30 00:12:24,126 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000078: Starting **JGroups channel `ISPN` with stack `jdbc-ping-tcp**`
2022-06-30 00:12:26,420 INFO  [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-55-32018: no members discovered after 2002 ms: creating cluster as coordinator
2022-06-30 00:12:26,429 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000094: Received new cluster view for channel ISPN: [ip-10-57-226-55-32018|0] (1) [ip-10-57-226-55-32018]
2022-06-30 00:12:26,432 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000079: Channel `ISPN` local address is `ip-10-57-226-55-32018`, physical addresses are `[10.57.226.55:7800]`
2022-06-30 00:12:27,164 INFO  [org.keycloak.connections.infinispan.DefaultInfinispanConnectionProviderFactory] (main) Node name: ip-10-57-226-55-32018, Site name: null
2022-06-30 00:12:27,616 INFO  [io.quarkus] (main) Keycloak 18.0.1 on JVM (powered by Quarkus 2.7.5.Final) started in 10.595s. Listening on: http://0.0.0.0:8080
2022-06-30 00:12:27,617 INFO  [io.quarkus] (main) Profile prod activated.
2022-06-30 00:12:27,617 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, jdbc-h2, jdbc-mariadb, jdbc-mssql, jdbc-mysql, jdbc-oracle, jdbc-postgresql, keycloak, narayana-jta, reactive-routes, resteasy, resteasy-jackson, smallrye-context-propagation, smallrye-health, smallrye-metrics, vault, vertx]

2 - ORACLE DB SETTING

<jgroups>
    <stack name="jdbc-ping-tcp" extends="tcp">
      <JDBC_PING connection_driver="oracle.jdbc.OracleDriver"
                 connection_username="keycloak"
                 connection_password="password"
              connection_url="jdbc:oracle:thin:@//db-url:1524/keycloak"
                 initialize_sql="CREATE TABLE JGROUPSPING (own_addr varchar2(200) NOT NULL, cluster_name varchar2(200) NOT NULL,ping_data BLOB,constraint PK_JGROUPSPING PRIMARY KEY (own_addr, cluster_name));"
                 info_writer_sleep_time="500"
                 remove_all_data_on_view_change="true"
                 stack.combine="REPLACE"
                 stack.position="MPING" />
    </stack>
  </jgroups>
4

I’ve done it only once for Oracle, trying to remember some settings…

  • I created the table manually with the same SQL statement you have in your config :white_check_mark: (and I removed the initialize_sql property from the config)
  • I used as connection_driver the value oracle.jdbc.driver.OracleDriver (this is different from yours)
  • check your connection_url (also together with username/password) - is it correct? does it work in general?

If there’s really not one entry in the JGROUPSPING table, then this is really strange… at least, one entry should be there (the one from the node currently starting and mentioning that it is creating a cluster view).

1 Like
5

Hi @dasniko

Thank you for your post and guidance (including the YT videos) – these were very helpful.

Per you guidance, we are further ahead - see ‘1 - LOG’ below. However no entry in the database table so far (which has been updated see ‘2 - Infinispan Configuration’). I can connect to the database and table (see ‘3 - JGROUPSPING Table Create’ for the table creation statement).

I’ve removed the default Infinispan configuration file. And from logs, it appears the intended file is being picked up. Would there be ways to extract logs to determine why not written to the database (DEBUG did not appear to produce anything of value for the above)?

1 - LOG

2022-07-04 08:52:07,985 INFO  [org.keycloak.quarkus.runtime.hostname.DefaultHostnameProvider] (main) Hostname settings: FrontEnd: foobar.com, Strict HTTPS: true, Path: <request>, Strict BackChannel: false, Admin: <request>, Port: -1, Proxied: true
2022-07-04 08:52:09,419 WARN  [org.infinispan.CONFIG] (keycloak-cache-init) ISPN000569: Unable to persist Infinispan internal caches as no global state enabled
2022-07-04 08:52:09,434 WARN  [org.infinispan.PERSISTENCE] (keycloak-cache-init) ISPN000554: jboss-marshalling is deprecated and planned for removal
2022-07-04 08:52:09,514 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000556: Starting user marshaller 'org.infinispan.jboss.marshalling.core.JBossUserMarshaller'
2022-07-04 08:52:09,879 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000128: Infinispan version: Infinispan 'Triskaidekaphobia' 13.0.9.Final
2022-07-04 08:52:10,214 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000078: Starting JGroups channel `ISPN` with stack `jdbc-ping-tcp`
2022-07-04 08:52:12,425 INFO  [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-114-54993: no members discovered after 2006 ms: creating cluster as coordinator
2022-07-04 08:52:12,443 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000094: Received new cluster view for channel ISPN: [ip-10-57-226-114-54993|0] (1) [ip-10-57-226-114-54993]
2022-07-04 08:52:12,450 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000079: Channel `ISPN` local address is `ip-10-57-226-114-54993`, physical addresses are `[10.57.226.114:7800]`
2022-07-04 08:52:13,143 INFO  [org.keycloak.connections.infinispan.DefaultInfinispanConnectionProviderFactory] (main) Node name: ip-10-57-226-114-54993, Site name: null
2022-07-04 08:52:13,415 INFO  [io.quarkus] (main) Keycloak 18.0.1 on JVM (powered by Quarkus 2.7.5.Final) started in 10.510s. Listening on: http://0.0.0.0:8080
2022-07-04 08:52:13,416 INFO  [io.quarkus] (main) Profile prod activated.
2022-07-04 08:52:13,417 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, jdbc-h2, jdbc-mariadb, jdbc-mssql, jdbc-mysql, jdbc-oracle, jdbc-postgresql, keycloak, narayana-jta, reactive-routes, resteasy, resteasy-jackson, smallrye-context-propagation, smallrye-health, smallrye-metrics, vault, vertx]

2 - Infinispan configuration

<jgroups>
    <stack name="jdbc-ping-tcp" extends="tcp">
      <JDBC_PING connection_driver="oracle.jdbc.driver.OracleDriver"
                 connection_username="keycloak"
                 connection_password="keycloak"
              connection_url="jdbc:oracle:thin:@database:1524/keycloak"
                 info_writer_sleep_time="500"
                 stack.combine="REPLACE"
                 stack.position="MPING" />
    </stack>
  </jgroups>

3 - JGROUPSPING Table Create

CREATE TABLE JGROUPSPING (own_addr varchar2(200) NOT NULL, cluster_name varchar2(200) NOT NULL,ping_data BLOB,constraint PK_JGROUPSPING PRIMARY KEY (own_addr, cluster_name))
6

Hm, don‘t know, I‘m a bit clueless.

@xgp Do you have an idea, why the instance doesn‘t insert itself into the database? Everything seems to look right. What is missing/wrong here?

1 Like
7

I’ve been following this, and I can’t see anything wrong with what he’s doing, or why it isn’t writing the record. I don’t have an oracle setup to test this. Would it be possible for @melancholia to turn up logging to TRACE for org.jgroups to see if anything useful is coming out?

2 Likes
8

Thank you @dasniko @xgp. I very much appreciate your help and guidance.

Turned on trace for:org.jgroups:trace (see below).

There wasn’t anything per se in the logs that caught my eye (in fact nothing specific that it’s connecting to the database - is that in itself an indicator?). Do you see any smoking guns?

2022-07-04 12:21:47,410 INFO  [org.keycloak.quarkus.runtime.hostname.DefaultHostnameProvider] (main) Hostname settings: FrontEnd: foobar.com, Strict HTTPS: true, Path: <request>, Strict BackChannel: false, Admin: <request>, Port: -1, Proxied: true
2022-07-04 12:21:50,141 WARN  [org.infinispan.CONFIG] (keycloak-cache-init) ISPN000569: Unable to persist Infinispan internal caches as no global state enabled
2022-07-04 12:21:50,184 WARN  [org.infinispan.PERSISTENCE] (keycloak-cache-init) ISPN000554: jboss-marshalling is deprecated and planned for removal
2022-07-04 12:21:50,275 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000556: Starting user marshaller 'org.infinispan.jboss.marshalling.core.JBossUserMarshaller'
2022-07-04 12:21:50,720 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000128: Infinispan version: Infinispan 'Triskaidekaphobia' 13.0.9.Final
2022-07-04 12:21:50,994 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000078: Starting JGroups channel `ISPN` with stack `jdbc-ping-tcp`
2022-07-04 12:21:51,180 DEBUG [org.jgroups.stack.Configurator] (keycloak-cache-init) set property TCP.diagnostics_addr to default value /224.0.75.75
2022-07-04 12:21:51,206 DEBUG [org.jgroups.protocols.TCP] (keycloak-cache-init) thread pool min/max/keep-alive: 0/200/60000 use_fork_join=false, internal pool: 0/4/30000 (2 cores available)
2022-07-04 12:21:51,211 DEBUG [org.jgroups.protocols.MPING] (keycloak-cache-init) bind_addr=/10.57.226.121, mcast_addr=/228.6.7.8, mcast_port=46655
2022-07-04 12:21:51,212 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (keycloak-cache-init) null: set max_xmit_req_size from 0 to 511600
2022-07-04 12:21:51,213 TRACE [org.jgroups.protocols.UNICAST3] (keycloak-cache-init) null: set max_xmit_req_size from 0 to 511600
2022-07-04 12:21:51,230 DEBUG [org.jgroups.protocols.MPING] (keycloak-cache-init) receiver thread started
2022-07-04 12:21:51,244 TRACE [org.jgroups.protocols.pbcast.STABLE] (keycloak-cache-init) ip-10-57-226-121-41122: stable task started
2022-07-04 12:21:51,244 DEBUG [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) address=ip-10-57-226-121-41122, cluster=ISPN, physical address=10.57.226.121:7800
2022-07-04 12:21:53,253 INFO  [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-121-41122: no members discovered after 2002 ms: creating cluster as coordinator
2022-07-04 12:21:53,255 DEBUG [org.jgroups.protocols.pbcast.NAKACK2] (keycloak-cache-init)
[ip-10-57-226-121-41122 setDigest()]
existing digest:  []
new digest:       ip-10-57-226-121-41122: [0 (0)]
resulting digest: ip-10-57-226-121-41122: [0 (0)]
2022-07-04 12:21:53,256 DEBUG [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-121-41122: installing view [ip-10-57-226-121-41122|0] (1) [ip-10-57-226-121-41122] (ip-10-57-226-121-41122 joined)
2022-07-04 12:21:53,258 DEBUG [org.jgroups.protocols.pbcast.STABLE] (keycloak-cache-init) resuming message garbage collection
2022-07-04 12:21:53,265 TRACE [org.jgroups.protocols.UFC] (keycloak-cache-init) new membership: [ip-10-57-226-121-41122]
2022-07-04 12:21:53,266 TRACE [org.jgroups.protocols.MFC] (keycloak-cache-init) new membership: [ip-10-57-226-121-41122]
2022-07-04 12:21:53,268 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000094: Received new cluster view for channel ISPN: [ip-10-57-226-121-41122|0] (1) [ip-10-57-226-121-41122]
2022-07-04 12:21:53,273 DEBUG [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-121-41122: created cluster (first member). My view is [ip-10-57-226-121-41122|0], implis CoordGmsImpl
2022-07-04 12:21:53,274 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000079: Channel `ISPN` local address is `ip-10-57-226-121-41122`, physical addresses are `[10.57.226.121:7800]`
2022-07-04 12:21:53,656 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122 --> [all]: #1
2022-07-04 12:21:53,659 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2219, headers are NAKACK2: [MSG, seqno=1], TP: [cluster=ISPN]
2022-07-04 12:21:53,671 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122 used 2176 credits, 3997824 remaining
2022-07-04 12:21:53,751 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122 --> [all]: #2
2022-07-04 12:21:53,751 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2205, headers are NAKACK2: [MSG, seqno=2], TP: [cluster=ISPN]
2022-07-04 12:21:53,752 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122 used 2162 credits, 3995662 remaining
2022-07-04 12:21:53,764 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122 --> [all]: #3
2022-07-04 12:21:53,765 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2211, headers are NAKACK2: [MSG, seqno=3], TP: [cluster=ISPN]
2022-07-04 12:21:53,765 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122 used 2168 credits, 3993494 remaining
2022-07-04 12:21:53,791 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t2) ip-10-57-226-121-41122 --> [all]: #4
2022-07-04 12:21:53,791 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t2) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=1180, headers are NAKACK2: [MSG, seqno=4], TP: [cluster=ISPN]
2022-07-04 12:21:53,793 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t2) ip-10-57-226-121-41122 used 1137 credits, 3992357 remaining
2022-07-04 12:21:53,806 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122 --> [all]: #5
2022-07-04 12:21:53,807 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=1213, headers are NAKACK2: [MSG, seqno=5], TP: [cluster=ISPN]
2022-07-04 12:21:53,807 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122 used 1170 credits, 3991187 remaining
2022-07-04 12:21:53,828 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122 --> [all]: #6
2022-07-04 12:21:53,828 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2210, headers are NAKACK2: [MSG, seqno=6], TP: [cluster=ISPN]
2022-07-04 12:21:53,828 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122 used 2167 credits, 3989020 remaining
2022-07-04 12:21:53,845 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122 --> [all]: #7
2022-07-04 12:21:53,845 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2218, headers are NAKACK2: [MSG, seqno=7], TP: [cluster=ISPN]
2022-07-04 12:21:53,845 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122 used 2175 credits, 3986845 remaining
2022-07-04 12:21:53,857 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t2) ip-10-57-226-121-41122 --> [all]: #8
2022-07-04 12:21:53,857 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t2) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=1197, headers are NAKACK2: [MSG, seqno=8], TP: [cluster=ISPN]
2022-07-04 12:21:53,857 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t2) ip-10-57-226-121-41122 used 1154 credits, 3985691 remaining
2022-07-04 12:21:53,869 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122 --> [all]: #9
2022-07-04 12:21:53,869 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2219, headers are NAKACK2: [MSG, seqno=9], TP: [cluster=ISPN]
2022-07-04 12:21:53,869 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t1) ip-10-57-226-121-41122 used 2176 credits, 3983515 remaining
2022-07-04 12:21:53,879 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122 --> [all]: #10
2022-07-04 12:21:53,880 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2212, headers are NAKACK2: [MSG, seqno=10], TP: [cluster=ISPN]
2022-07-04 12:21:53,880 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t4) ip-10-57-226-121-41122 used 2169 credits, 3981346 remaining
2022-07-04 12:21:53,893 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122 --> [all]: #11
2022-07-04 12:21:53,893 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=2209, headers are NAKACK2: [MSG, seqno=11], TP: [cluster=ISPN]
2022-07-04 12:21:53,893 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t3) ip-10-57-226-121-41122 used 2166 credits, 3979180 remaining
2022-07-04 12:21:54,044 INFO  [org.keycloak.connections.infinispan.DefaultInfinispanConnectionProviderFactory] (main) Node name: ip-10-57-226-121-41122, Site name: null
2022-07-04 12:21:54,248 TRACE [org.jgroups.protocols.TCP] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=39, headers areNAKACK2: [HIGHEST_SEQNO, seqno=11], TP: [cluster=ISPN]
2022-07-04 12:21:54,337 INFO  [io.quarkus] (main) Keycloak 18.0.1 on JVM (powered by Quarkus 2.7.5.Final) started in 11.024s. Listening on: http://0.0.0.0:8080
2022-07-04 12:21:54,337 INFO  [io.quarkus] (main) Profile prod activated.
2022-07-04 12:21:54,337 INFO  [io.quarkus] (main) Installed features: [agroal, cdi, hibernate-orm, jdbc-h2, jdbc-mariadb, jdbc-mssql, jdbc-mysql, jdbc-oracle, jdbc-postgresql, keycloak, narayana-jta, reactive-routes, resteasy, resteasy-jackson, smallrye-context-propagation, smallrye-health, smallrye-metrics, vault, vertx]
2022-07-04 12:21:56,629 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: updating the local figest with a stable message (coordinator): ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:21:56,630 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: handling digest from ip-10-57-226-121-41122:
mine:   ip-10-57-226-121-41122: [-1]
sender: ip-10-57-226-121-41122: [11]
result: ip-10-57-226-121-41122: [11]

2022-07-04 12:21:56,630 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending stability msg ip-10-57-226-121-41122: [11]
2022-07-04 12:21:56,630 TRACE [org.jgroups.protocols.TCP] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=83, headers areSTABLE: [STABILITY] view-id= [ip-10-57-226-121-41122|0], TP: [cluster=ISPN]
2022-07-04 12:21:56,631 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: received stable digest ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:21:56,631 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: deleting msgs <= 11 from ip-10-57-226-121-41122
2022-07-04 12:22:05,844 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: updating the local figest with a stable message (coordinator): ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:05,845 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: handling digest from ip-10-57-226-121-41122:
mine:   ip-10-57-226-121-41122: [-1]
sender: ip-10-57-226-121-41122: [11]
result: ip-10-57-226-121-41122: [11]

2022-07-04 12:22:05,845 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending stability msg ip-10-57-226-121-41122: [11]
2022-07-04 12:22:05,847 TRACE [org.jgroups.protocols.TCP] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=83, headers areSTABLE: [STABILITY] view-id= [ip-10-57-226-121-41122|0], TP: [cluster=ISPN]
2022-07-04 12:22:05,847 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: received stable digest ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:05,847 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: deleting msgs <= 11 from ip-10-57-226-121-41122
2022-07-04 12:22:07,137 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: updating the local figest with a stable message (coordinator): ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:07,137 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: handling digest from ip-10-57-226-121-41122:
mine:   ip-10-57-226-121-41122: [-1]
sender: ip-10-57-226-121-41122: [11]
result: ip-10-57-226-121-41122: [11]

2022-07-04 12:22:07,137 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending stability msg ip-10-57-226-121-41122: [11]
2022-07-04 12:22:07,138 TRACE [org.jgroups.protocols.TCP] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=83, headers areSTABLE: [STABILITY] view-id= [ip-10-57-226-121-41122|0], TP: [cluster=ISPN]
2022-07-04 12:22:07,138 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: received stable digest ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:07,138 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: deleting msgs <= 11 from ip-10-57-226-121-41122
2022-07-04 12:22:07,359 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: updating the local figest with a stable message (coordinator): ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:07,359 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: handling digest from ip-10-57-226-121-41122:
mine:   ip-10-57-226-121-41122: [-1]
sender: ip-10-57-226-121-41122: [11]
result: ip-10-57-226-121-41122: [11]

2022-07-04 12:22:07,360 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending stability msg ip-10-57-226-121-41122: [11]
2022-07-04 12:22:07,361 TRACE [org.jgroups.protocols.TCP] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: sending msg to null, src=ip-10-57-226-121-41122, size=83, headers areSTABLE: [STABILITY] view-id= [ip-10-57-226-121-41122|0], TP: [cluster=ISPN]
2022-07-04 12:22:07,361 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: received stable digest ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:07,361 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: deleting msgs <= 11 from ip-10-57-226-121-41122
2022-07-04 12:22:10,845 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: updating the local figest with a stable message (coordinator): ip-10-57-226-121-41122: [11 (11)]
2022-07-04 12:22:10,845 TRACE [org.jgroups.protocols.pbcast.STABLE] (jgroups-6,ip-10-57-226-121-41122) ip-10-57-226-121-41122: handling digest from ip-10-57-226-121-41122:
mine:   ip-10-57-226-121-41122: [-1]
sender: ip-10-57-226-121-41122: [11]
result: ip-10-57-226-121-41122: [11]
9

There should be a lot of entries for the org.jgroups.protocols.JDBC_PING class (at least that’s what I see when I run my setup against postgres). Still not sure why it never tries to connect (or why it fails silently).

10

Thanks @xgp

I’ve moved to using Visual Studio Code – the following ‘problem’, in screenshot pasted below, pops-up – could this be a smoking gun? Have I potentially missed an earlier step (oddly under ‘One of the following is expected’ is ‘JDBC_PING’)?

image
image2962×924 242 KB

12

I see the same thing when I open it in VSCode, but it works when I run it.

Can we see your whole setup? How you are building the container, and all your config files? I have no way to debug this just looking at one piece.

13

@xgp Thank you!

The Keycloak v18.0.1 runs on AWS EC2 Linux (no containers); load balanced on ALB (running on 1 node pending figuring out clustering).

Please find the build, start, cache-ispn-jdbc-ping.xml, logs (INFO; with TRACE for org.jgroups.protocols). The DB Vendor is ‘oracle’.

Very much appreciate your and @dasniko’s help.

Thanks.

1- Build

export KC_BUILD_OPTS="$KC_BUILD_OPTS --db=${KEYCLOAK_DB_VENDOR}"
export KC_BUILD_OPTS="$KC_START_OPTS --http-relative-path=/auth/"
export KC_BUILD_OPTS="$KC_BUILD_OPTS --cache-stack=tcp"
export KC_BUILD_OPTS="$KC_BUILD_OPTS --cache-config-file=cache-ispn-jdbc-ping.xml"

2 - Start

export KC_START_OPTS="$KC_START_OPTS --proxy=edge"
export KC_START_OPTS="$KC_START_OPTS --hostname-strict=false"
export KC_START_OPTS="$KC_START_OPTS --log=console,file"
export KC_START_OPTS="$KC_START_OPTS --log-level=INFO,org.jgroups.protocols:TRACE"
export KC_START_OPTS="$KC_START_OPTS --log-file=/var/log/keycloak/keycloak.log"

3- cache-ispn-jdbc-ping.xml


<?xml version="1.0" encoding="UTF-8"?>
<infinispan
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="urn:infinispan:config:11.0 http://www.infinispan.org/schemas/infinispan-config-11.0.xsd"
    xmlns="urn:infinispan:config:11.0">

  <!-- custom stack goes into the jgroups element -->
  <jgroups>
    <stack name="jdbc-ping-tcp" extends="tcp">
      <JDBC_PING connection_driver="oracle.jdbc.driver.OracleDriver"
                 connection_username="${env.KC_DB_USERNAME}" 
                 connection_password="${env.KC_DB_PASSWORD}" 
                 connection_url="${env.KC_DB_URL}" 
                 info_writer_sleep_time="500"
                 stack.combine="REPLACE"
                 stack.position="MPING" />
    </stack>
  </jgroups>
  
  <cache-container name="keycloak">
    <!-- custom stack must be referenced by name in the stack attribute of the transport element -->
    <transport lock-timeout="60000" stack="jdbc-ping-tcp"/>
    <local-cache name="realms">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <memory max-count="10000"/>
    </local-cache>
    <local-cache name="users">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <memory max-count="10000"/>
    </local-cache>
    <distributed-cache name="sessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="authenticationSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="offlineSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="clientSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="offlineClientSessions" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <distributed-cache name="loginFailures" owners="2">
      <expiration lifespan="-1"/>
    </distributed-cache>
    <local-cache name="authorization">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <memory max-count="10000"/>
    </local-cache>
    <replicated-cache name="work">
      <expiration lifespan="-1"/>
    </replicated-cache>
    <local-cache name="keys">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <expiration max-idle="3600000"/>
      <memory max-count="1000"/>
    </local-cache>
    <distributed-cache name="actionTokens" owners="2">
      <encoding>
        <key media-type="application/x-java-object"/>
        <value media-type="application/x-java-object"/>
      </encoding>
      <expiration max-idle="-1" lifespan="-1" interval="300000"/>
      <memory max-count="-1"/>
    </distributed-cache>
  </cache-container>
</infinispan>

4 - LOGS


022-07-05 10:17:57,005 INFO  [org.keycloak.quarkus.runtime.hostname.DefaultHostnameProvider] (main) Hostname settings: FrontEnd: foobar.com, Strict HTTPS: true, Path: <request>, Strict BackChannel: false, Admin: <request>, Port: -1, Proxied: true
2022-07-05 10:18:01,018 WARN  [org.infinispan.PERSISTENCE] (keycloak-cache-init) ISPN000554: jboss-marshalling is deprecated and planned for removal
2022-07-05 10:18:01,056 WARN  [org.infinispan.CONFIG] (keycloak-cache-init) ISPN000569: Unable to persist Infinispan internal caches as no global state enabled
2022-07-05 10:18:01,112 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000556: Starting user marshaller 'org.infinispan.jboss.marshalling.core.JBossUserMarshaller'
2022-07-05 10:18:01,960 INFO  [org.infinispan.CONTAINER] (keycloak-cache-init) ISPN000128: Infinispan version: Infinispan 'Triskaidekaphobia' 13.0.9.Final
2022-07-05 10:18:02,222 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000078: Starting JGroups channel `ISPN` with stack `jdbc-ping-tcp`
2022-07-05 10:18:02,411 DEBUG [org.jgroups.protocols.TCP] (keycloak-cache-init) thread pool min/max/keep-alive: 0/200/60000 use_fork_join=false, internal pool: 0/4/30000 (2 cores available)
2022-07-05 10:18:02,417 DEBUG [org.jgroups.protocols.MPING] (keycloak-cache-init) bind_addr=/10.57.226.71, mcast_addr=/228.6.7.8, mcast_port=46655
2022-07-05 10:18:02,427 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (keycloak-cache-init) null: set max_xmit_req_size from 0 to 511600
2022-07-05 10:18:02,428 TRACE [org.jgroups.protocols.UNICAST3] (keycloak-cache-init) null: set max_xmit_req_size from 0 to 511600
2022-07-05 10:18:02,479 DEBUG [org.jgroups.protocols.MPING] (keycloak-cache-init) receiver thread started
2022-07-05 10:18:02,486 TRACE [org.jgroups.protocols.pbcast.STABLE] (keycloak-cache-init) ip-10-57-226-71-22387: stable task started
2022-07-05 10:18:02,487 DEBUG [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) address=ip-10-57-226-71-22387, cluster=ISPN, physical address=10.57.226.71:7800
2022-07-05 10:18:04,501 INFO  [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-71-22387: no members discovered after 2002 ms: creating cluster as coordinator
2022-07-05 10:18:04,503 DEBUG [org.jgroups.protocols.pbcast.NAKACK2] (keycloak-cache-init)
[ip-10-57-226-71-22387 setDigest()]
existing digest:  []
new digest:       ip-10-57-226-71-22387: [0 (0)]
resulting digest: ip-10-57-226-71-22387: [0 (0)]
2022-07-05 10:18:04,503 DEBUG [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-71-22387: installing view [ip-10-57-226-71-22387|0] (1) [ip-10-57-226-71-22387] (ip-10-57-226-71-22387 joined)
2022-07-05 10:18:04,505 DEBUG [org.jgroups.protocols.pbcast.STABLE] (keycloak-cache-init) resuming message garbage collection
2022-07-05 10:18:04,510 TRACE [org.jgroups.protocols.UFC] (keycloak-cache-init) new membership: [ip-10-57-226-71-22387]
2022-07-05 10:18:04,511 TRACE [org.jgroups.protocols.MFC] (keycloak-cache-init) new membership: [ip-10-57-226-71-22387]
2022-07-05 10:18:04,513 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000094: Received new cluster view for channel ISPN: [ip-10-57-226-71-22387|0] (1) [ip-10-57-226-71-22387]
2022-07-05 10:18:04,517 DEBUG [org.jgroups.protocols.pbcast.GMS] (keycloak-cache-init) ip-10-57-226-71-22387: created cluster (first member). My view is [ip-10-57-226-71-22387|0], impl is CoordGmsImpl
2022-07-05 10:18:04,518 INFO  [org.infinispan.CLUSTER] (keycloak-cache-init) ISPN000079: Channel `ISPN` local address is `ip-10-57-226-71-22387`, physical addresses are `[10.57.226.71:7800]`
2022-07-05 10:18:04,996 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t1) ip-10-57-226-71-22387 --> [all]: #1
2022-07-05 10:18:05,001 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t1) ip-10-57-226-71-22387: sending msg to null, src=ip-10-57-226-71-22387, size=2219, headers are NAKACK2: [MSG, seqno=1], TP: [cluster=ISPN]
2022-07-05 10:18:05,005 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t1) ip-10-57-226-71-22387 used 2176 credits, 3997824 remaining
2022-07-05 10:18:05,071 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t4) ip-10-57-226-71-22387 --> [all]: #2
2022-07-05 10:18:05,072 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t4) ip-10-57-226-71-22387: sending msg to null, src=ip-10-57-226-71-22387, size=2205, headers are NAKACK2: [MSG, seqno=2], TP: [cluster=ISPN]
2022-07-05 10:18:05,072 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t4) ip-10-57-226-71-22387 used 2162 credits, 3995662 remaining
2022-07-05 10:18:05,085 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t3) ip-10-57-226-71-22387 --> [all]: #3
2022-07-05 10:18:05,086 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t3) ip-10-57-226-71-22387: sending msg to null, src=ip-10-57-226-71-22387, size=2211, headers are NAKACK2: [MSG, seqno=3], TP: [cluster=ISPN]
2022-07-05 10:18:05,086 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t3) ip-10-57-226-71-22387 used 2168 credits, 3993494 remaining
2022-07-05 10:18:05,106 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t2) ip-10-57-226-71-22387 --> [all]: #4
2022-07-05 10:18:05,107 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t2) ip-10-57-226-71-22387: sending msg to null, src=ip-10-57-226-71-22387, size=1180, headers are NAKACK2: [MSG, seqno=4], TP: [cluster=ISPN]
2022-07-05 10:18:05,107 TRACE [org.jgroups.protocols.MFC] (non-blocking-thread--p2-t2) ip-10-57-226-71-22387 used 1137 credits, 3992357 remaining
2022-07-05 10:18:05,118 TRACE [org.jgroups.protocols.pbcast.NAKACK2] (non-blocking-thread--p2-t1) ip-10-57-226-71-22387 --> [all]: #5
2022-07-05 10:18:05,118 TRACE [org.jgroups.protocols.TCP] (non-blocking-thread--p2-t1) ip-10-57-226-71-22387: sending msg to null, src=ip-10-57-226-71-22387, size=1213, headers are NAKACK
Persist infinispan cache
14

Remove the line with —cache-stack=tcp.
I guess this is causing the problem.
As soon as you are using a custom cache stack config file, don‘t specifiy the cache-stack!

1 Like
15

+1 for @dasniko 's response. I just ran a test, and if you specify --cache-stack, it ignores --cache-config-file.

1 Like
16

That was it — bingo.

Thank you so much @xgp and @dasniko. Very much appreciated.

Please ping me if you are ever in PNW - I will buy you the best beer in the region, or whichever your favourite beverage.

1 Like
17

thanks all 3 of you!