token generation time increases gradually with increase in cache size

[kkcmadhu]

i am using external cache setup hotrod,and my user-session are stored in external infinispan server.

I just have 1 realm, 1 user, and try to repeatedly get tokens for this user using basic auth. with time i see that the time for obtainin new token increases..
If i clear the cache (infinispan user-sessions cache) from the infinispan console , the token generation time comes down, and it increases again as the number of entries(session) in the cache are added..

Here is a jmeter graph for the same

the dips are whenever i reset/clear the cache..

Plese note, In the infinispan console, performing 'clear index' too helps a bit(but not as good as 'clear all entries'). 'Rebuild index' , do not have much impact..

if i donot clear cache , over time the peformance degrades drastically

[kkcmadhu]

from what i believe, this is something to do with hotrod/infinispan cluster, but how to tweak infinispan for keycloak??
the out of box settings clearly seems to be not working well.

[kkcmadhu]

@pedroigor , @hmlnarik , @mhajas @martin-kanis , @thomasdarimont , can any one suggest how can i get past this issue?

[thomasdarimont]

@kkcmadhu Could you check, if you accidentally create a completely new user session for repeated token requests?

You could verify that by looking at the sessions tab for the client and user in the (old) admin-console.

Since you mention that you are using basic auth to obtain tokens, is it possible that you are using this as some means to authenticate users for a legacy application? If you don't use the token at all you could try to disable the refresh token generation for the client in the client configuration.

[kkcmadhu]

I delibrately created multiple sessions for repeated token requests, thats my use case..
i expect sesssion to keep increasing, and eventually getting cleaned as the token/session expire.

I repeated the same test with legacy store and hotrod, the legacy store gives sub 600ms response (consistently) for all requests, i ended up having more than 80k sessions in my keycloak, without any issues.

but with new store / hot rod, i see responses going upto 7 seconds, for as little as 5k sessions.

[mhajas]

I delibrately created multiple sessions for repeated token requests, thats my use case.. i expect sesssion to keep increasing, and eventually getting cleaned as the token/session expire.

Currently, the HotRod storage does not clean expired user sessions if they are not used. This will change in future though, see #12068, unfortunately, at the moment we are blocked by Infinispan update. It most probably won't be part of Keycloak 20, but should be available in KC 21.

[mhajas]

@kkcmadhu Are you using Keycloak 19 or the current main branch?

[kkcmadhu]

Tag 19.0.3 Sent from Yahoo Mail on Android On Thu, 27 Oct 2022 at 7:38 pm, Michal ***@***.***> wrote: @kkcmadhu Are you using Keycloak 19 or the current main branch? — Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you were mentioned.Message ID: ***@***.***>

[mhajas]

@kkcmadhu I tried to reproduce this, however, I am not able to reproduce any significant performance drop.

I was running it locally. I run Keycloak using:

./kc.sh start-dev --storage=hotrod --storage-hotrod-host=localhost --storage-hotrod-port=11222 --storage-hotrod-username=admin --storage-hotrod-password=admin

and an Infinispan server using:

docker run --network host -e USER="admin" -e PASS="admin" infinispan/server:12.1.7.Final

then I executed the following command in a loop:

ACCESS_TOKEN=$(curl -X POST http://localhost:"$port"/realms/"$realm"/protocol/openid-connect/token \
    -H "Authorization: Basic $(echo -n "$client:$secret" | base64)" \
    -H "content-type: application/x-www-form-urlencoded" \
    -d "username=$username&password=$password&grant_type=password" | jq --raw-output '.access_token')

Currently, I am at 8000th iteration and it still finishes in around 100ms. In the Infinispan console, I can see there are 20000 entries.

Can you please share more details on how you tested it?

[kkcmadhu]

i use docker k8s on windows laptop.
i run infinispan 13.x using infinispan operator on k8s.
my cluster (infinispan crd) looks something linke this

apiVersion: infinispan.org/v1
kind: Infinispan
metadata:
  name: keycloak-cache
  namespace: inficache  
  annotations:
    infinispan.org/monitoring: 'true'
spec:
  replicas: 1 
  service:
    type: DataGrid

I generate my load using jmeter, but thats very very similar to your curl script.
The cache did not get created automatically,and the first time start up failed, however keycloak logs dumped the desired cache definations,which i manually created in infinispan.

and i run keycloak with new stroage pointing to postgressql for realm,clients etc..
and i use hotrod for user-session, onetime objects etc etc.. based on this keycloak blog

typically my keycloak startup command is very similar to

bin/kc.sh start-dev --storage=jpa \
  --db-url=<jdbc-url> --db-username=<username> --db-password=<password> \
  --storage-hotrod-host=<host> --storage-hotrod-port=<port> \
  --storage-hotrod-username=<username> --storage-hotrod-password=<password> \
  --storage-area-action-token=hotrod \
  --storage-area-auth-session=hotrod \
  --storage-area-single-use-object=hotrod \
  --storage-area-user-session=hotrod

The exact k8s yaml i use is this

  spec:
     containers:
       args: ["-v", "start-dev"]        
       env:
       - name: KEYCLOAK_ADMIN
         value: "admin"
       - name: KEYCLOAK_ADMIN_PASSWORD
         value: "blahBlaHablah!!"
#        - name: KC_PROXY
#          value: "edge"
       - name: KC_DB
         value: "postgres"
       - name: KC_DB_URL
         value: "jdbc:postgresql://host.docker.internal:5432/k8s?currentSchema=kc19test"          
       - name: KC_DB_USERNAME
         value: "myuser"
       - name: KC_DB_PASSWORD
         value: "bLalhBlahbla!"
       - name: KC_HEALTH_ENABLED
         value: "true"
       - name: KC_METRICS_ENABLED
         value: "true"
       - name: KC_FEATURES
         value: "token-exchange,preview,scripts,admin-fine-grained-authz,map-storage"
       - name: KC_FEATURES_DISABLED
         value: "admin2"
       - name: KC_HTTP_RELATIVE_PATH
         value: "/auth"
       - name: KC_SPI_ADMIN_REALM
         value: "master"
       - name: KC_HOSTNAME
         value: "mykeycloak.kubernetes.docker.internal"
       - name: KC_HOSTNAME_ADMIN
         value: "mykeycloak.kubernetes.docker.internal"
       - name: KC_HOSTNAME_STRICT
         value: "false"
       - name: KC_HOSTNAME_STRICT_BACKCHANNEL
         value: "false"
       - name: KC_HOSTNAME_STRICT_HTTPS
         value: "false"
       - name: KC_HTTP_ENABLED
         value: "true"
       - name: KC_SPI_HOSTNAME_DEFAULT_ADMIN
         value: "mykeycloak.kubernetes.docker.internal"
       - name: "KC_LOG_CONSOLE_OUTPUT"
         value: "default"
       - name: "KC_LOG_LEVEL"
         value: "info"
       - name: jgroups.dns.query
         value: "mykeycloak-aw-us-headless"
#        - name: KC_CACHE          
#          value: "ispn"
#        - name: KC_CACHE_STACK          
#          value: "kubernetes"
       - name: KC_STORAGE
         value: "jpa"
       - name: KC_STORAGE_HOTROD_HOST
         value: "keycloak-cache.inficache.svc.cluster.local"
       - name: KC_STORAGE_HOTROD_PORT
         value: "11222"
       - name: KC_STORAGE_HOTROD_USERNAME
         value: "developer"
       - name: KC_STORAGE_HOTROD_PASSWORD
         value: "blAhBlahBlah!"
       - name: KC_STORAGE_AREA_ACTION_TOKEN
         value: "hotrod"
       - name: KC_STORAGE_AREA_AUTH_SESSION
         value: "hotrod"
       - name: KC_STORAGE_AREA_SINGLE_USE_OBJECT
         value: "hotrod"
       - name: KC_STORAGE_AREA_USER_SESSION
         value: "hotrod"
       - name: KC_STORAGE_AREA_USER
         value: "jpa"      
       - name: KC_STORAGE_DEPLOYMENT_STATE_VERSION_SEED
         value: "blah"
       - name: KC_SPI_USER_STORAGE_PROVIDER_TIMEOUT
         value: "5000"

i tried scaling the number of keycloak nodes, no of members in infinispan cluster, but they did not have any positive impact.

As far as the cache defination goes, this is exactly what keycloak spewed in the logs, i just copy pasted these definiations one by one in infinispan admin console to create relavent cache entties.

2022-10-13 07:28:58,865 ERROR (non-blocking-thread--p2-t7) [org.infinispan.server.hotrod.BaseRequestProcessor] ISPN005003: Exception reported org.infinispan.commons.CacheConfigurationException: ISPN005053: The supplied configuration for cache 'realms' must contain a single cache configuration for it: <!-- Used for configuration of remote caches on the Infinispan server if the configureRemoteCaches option is set to true
 in DefaultHotRodConnectionProviderFactory configuration. -->
<infinispan>
    <cache-container>
       <!-- Specify all remote caches that should be created on the Infinispan server. -->
        <distributed-cache name="auth-sessions" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodRootAuthenticationSessionEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="clients" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodClientEntity</indexed-entity>
                    <indexed-entity>kc.HotRodAttributeEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="client-scopes" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodClientScopeEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="groups" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodGroupEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="roles" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodRoleEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="users" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodUserEntity</indexed-entity>
                    <indexed-entity>kc.HotRodAttributeEntity</indexed-entity>
                    <indexed-entity>kc.HotRodUserFederatedIdentityEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="user-login-failures" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodUserLoginFailureEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="realms" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodRealmEntity</indexed-entity>
                    <indexed-entity>kc.HotRodComponentEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="user-sessions" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodUserSessionEntity</indexed-entity>
                    <indexed-entity>kc.HotRodAuthenticatedClientSessionEntityReference</indexed-entity>
                    <indexed-entity>kc.HotRodStringPair</indexed-entity>
                    <indexed-entity>kc.HotRodAuthenticatedClientSessionEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
        <distributed-cache name="authz" mode="SYNC">
            <encoding media-type="application/x-protostream"/>
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodResourceServerEntity</indexed-entity>
                    <indexed-entity>kc.HotRodResourceEntity</indexed-entity>
                    <indexed-entity>kc.HotRodScopeEntity</indexed-entity>
                    <indexed-entity>kc.HotRodPolicyEntity</indexed-entity>
                    <indexed-entity>kc.HotRodPermissionTicketEntity</indexed-entity>
                    <indexed-entity>kc.HotRodStringPair</indexed-entity>
                </indexed-entities>
            </indexing>
        </distributed-cache>
        <distributed-cache name="auth-events" mode="SYNC">
            <encoding media-type="application/x-protostream"/>
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodAuthEventEntity</indexed-entity>
                </indexed-entities>
            </indexing>
        </distributed-cache>
        <distributed-cache name="admin-events" mode="SYNC">
            <encoding media-type="application/x-protostream"/>
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodAdminEventEntity</indexed-entity>
                </indexed-entities>
            </indexing>
        </distributed-cache>
		
		
		
		
	
        <distributed-cache name="single-use-objects" mode="SYNC">
            <indexing>
                <indexed-entities>
                    <indexed-entity>kc.HotRodSingleUseObjectEntity</indexed-entity>
                </indexed-entities>
            </indexing>
            <encoding media-type="application/x-protostream"/>
        </distributed-cache>
    </cache-container>
</infinispan>

[mhajas]

Would it be possible to test it with Infiniepan 12.1.7? I suspect with 13 for some reason indexes are not used.

With 12.1.7 it should not be necessary to create caches manually.

Or you can wait some time to Keycloak 20 that should support Intinispan 13 out of the box.

Btw. In the blog you mentioned there is also mentioned that KC 19 does support only Infinispan 12.1

[kkcmadhu]

Would it be possible to test it with Infiniepan 12.1.7? I suspect with 13 for some reason indexes are not used.

With 12.1.7 it should not be necessary to create caches manually.

Or you can wait some time to Keycloak 20 that should support Intinispan 13 out of the box.

Btw. In the blog you mentioned there is also mentioned that KC 19 does support only Infinispan 12.1

yes.. i saw the note on infinispan 12.1 as the offically supported version, i can try again on infinispan 12.x ( few other discussion mentioned about creating index manually in infinispan 13.x, so went with it).. Will certainly try out 12.x and get back.

[kkcmadhu]

@mhajas i tried with 12.1.x that too is not too different , this time around the cache entties got created automatically..
but then in terms of performance i still dont see any significant difference..

at the moment i have about 10k session after 15 mins run and i see the latency increasing with time..
no of sessions :

latency graph :

infinispan version :

cache content :

[kkcmadhu]

ok if use all hot rod (like your test ) i.e --storate=hotrod ,instead of combination of hotrod and postgres, i see some improvment in perforamnce, but the pattern is still same, with time, the token generation time increases..

the numbers are not in 100ms range as in your test.. may be i will try with keycloak from the main branch too and get back..

[kkcmadhu]

the nightly build quay.io/keycloak/keycloak:nightly too has similar performance, these are definately way slower than existing legacy store