Search code examples
loggingjbosskeycloak

Keycloak debug level logs with jboss are cluttered


I am using jboss/keycloak:15.0.2. To comply with security requirements, I need to enable DEBUG level logs to log success messages for user login. The docker compose config looks like

  loginservice:
    image: my-image
    environment:
    - KEYCLOAK_IMPORT=/tmp/realm-export-deploy.json
    - KEYCLOAK_USER=admin
    - KEYCLOAK_LOGLEVEL=DEBUG
    - KEYCLOAK_PASSWORD_FILE=/run/secrets/loginadmin
    - SYS_PROPS=-Dkeycloak.migration.strategy=IGNORE_EXISTING
    - PROXY_ADDRESS_FORWARDING=true
    - KEYCLOAK_FRONTEND_URL=https://servername.net/keycloak/auth
    ports:
    - 7070:8080

However, as soon as the service comes up the logs are getting cluttered with repeated messaging of

08:00:30,986 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$2097/0x0000000841707840
08:00:35,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
08:00:35,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
08:00:35,985 DEBUG [org.keycloak.models.sessions.infinispan.changes.sessions.PersisterLastSessionRefreshStore] (Timer-2) Updating 0 userSessions with lastSessionRefresh: 1639123175
08:00:35,986 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper  commit
08:00:35,986 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end
08:00:35,986 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$2097/0x0000000841707840
08:00:40,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
08:00:40,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
08:00:40,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper  commit
08:00:40,986 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end
08:00:40,986 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$2097/0x0000000841707840
08:00:45,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
08:00:45,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
08:00:45,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper  commit
08:00:45,985 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end

The events I enabled from keycloak UI: enter image description here

Any clue whats up with the clutter and how can it be disabled?


Solution

  • You don't need to enable DEBUG logs for all Keycloak packages. Just enabling it for org.keycloak.events is enough. This can be done by adding this JBOSS startup script to the Keycloak container:

    embed-server --server-config=standalone-ha.xml
    /subsystem=logging/logger=org.keycloak.events/:add(category=org.keycloak.events,level=DEBUG)
    stop-embedded-server
    

    This will capture most of the relevant events in the logs.

    Or this can be specified as parameters to the start/start-dev command:

    bin/kc.[sh|bat] start --log-level="<root-level>,<org.category1>:<org.category1-level>"
    

    e.g.

    bin/kc.bat start-dev --log-level="WARN,org.keycloak.events:INFO,org.keycloak.saml:TRACE"
    

    See the docs for details.