Logging in Keycloak.X #8870

DGuhr · 2021-11-22T11:06:44Z

DGuhr
Nov 22, 2021

Locked - please open new separate discussions in https://github.com/keycloak/keycloak/discussions/categories/keycloak-x-quarkus-distribution

Hey 👋

I want to revive the discussion around logging, and logging only, bc. at the moment we totally rely on the (good) features quarkus gives us, but I think we can do even better and hope for input from your side to help us.

Why:

Make logging configuration/usage easy and meaningful
Support common integration use cases in distributed environments.
have even more convenient ux than quarkus logging provides, where possible

Out of Scope:

Tracing (e.g. OpenTracing/Jaeger integration)
Metrics (there's another proposal)

How:
note: the (?) means I am not sure myself if it is a good idea, so please provide feedback on this especially

Have a consistent syntax abstraction for different loggers.
Either:
- kc.log.<category>.<level/min-level/format/...>=...
- where category is optional, as it is ith quarkus, and e.g. kc.log.min-level sets the overall log-minlevel.
- Example: - kc.log.db.level=... -> for hibernate related logging
OR:
e.g.:
- kc.db.log.<level/min-level/format/...>=...
- kc.log.level/min-level/format=... would map internally to quarkus.log.level/min-level/format=... as a base abstraction to not have quarkus prefixed values in keycloak.properties together with kcprefixed.
- Opinion: Imo we should go with kc.log.<category>.<...> approach, bc. it is in line with how quarkus does logging[1] and may make it easier to maintain / integrate, bc. both follow the same approach.

- provide meaningful abstractions around quarkus category logging
- e.g. kc.log.db.level=<...> instead of quarkus.log.category."org.hibernate".level=<...>
- I think it may be a good idea to get rid of these " quarkus uses for its categories, where applicable, bc. these make it hard to e.g. parse them via CLI, and also we wouldn't be able to provide them via envvars. Good inputs for "where applicable" wanted, I think of the following for a start (using level for the sake of simplicity):
- kc.log.db.level -> maps to quarkus.log."org.hibernate".level internally
- kc.log.request-log -> maps internally to 2 quarkus props, and sets internally
quarkus.http.access-log.enabled=true quarkus.http.access-log.category=org.keycloak.request-log
- ...? (e.g. infinispan, but also things like SAML/OIDC related logs may be interesting)

- provide support for plain/json logging
- leverage the quarkus extension quarkus-logging-json for this and map it to be kc prefixed

- support for file/console logging
- only mapping to kc prefix needed.

- support for syslog(?)

- provide ootb support for Logstash/Graylog/FluentD via gelf appender (?)
- note: there's an extension for it, which should make integration relatively easy -> quarkus-logging-gelf[2]

References:
[1] https://quarkus.io/guides/logging
[2] https://quarkus.io/guides/centralized-log-management

Second Topic:
I also have some ideas about changing the log level dynamically when keycloak is running:

Allow dynamical change of log level when keycloak runs(?)

Option 1: filewatcher, and set level it via kc.sh
- pro: easy to setup via cli.
- con: in a cloud native env., you would not want to log into the container, more something for the "classic" dist onprem.
- Also, from my experience this could lead to some dark places in terms of edge cases where it doesn't behave as it should.
Option 2: Have an endpoint for setting/getting log lvl in keycloaks quarkus dist.
- Assumption: We don't want to use /q/ as non-app endpoint, and this endpoint should be protected
- Possibility 1: Talk to quarkus ppl, -> There is an open issue Separate binding/port config for non application endpoints quarkusio/quarkus#13602, which is basically about another vert.x for a somewhat "wildfly-like" mgmt port approach for metrics/health/logging endpoints. Still, we may want to provide our own protection nevertheless.
- Possibility 2: Have our vert.x requestfilter check for this endpoint(s)/path(s) and only allow requests from a whitelist of hosts, usually only containing e.g. localhost. But this could be a performance degradation, and possibly insecure. Example how this could look like, see @thomasdarimont implementation in [1]
- Possibility 2a: integrate sth like https://github.com/quarkiverse/quarkus-logging-manager which has its own basic security, and make it better in following iterations
Option 3:
- We don't provide something ootb.

Imo all options are applicable, but option2 in whatever taste is preferrable, bc it gives us more flexibility, but also needs to be properly secured for sure.

[1] https://github.com/thomasdarimont/keycloak-project-example/blob/main/keycloak/extensionsx/src/main/java/com/github/thomasdarimont/keycloakx/custom/security/AccessFilter.java#L19

pedroigor · 2021-11-22T12:18:24Z

pedroigor
Nov 22, 2021
Collaborator

I also agree we should go for kc.log.<category>.<property>. Where category is optional (e.g.: global logging config) and category would follow these rules:

Map to a specific option group/extension. For instance, kc.log.db, kc.log.http, kc.log.cluster, kc.log.myextension.
If a category does not map to a known option group/extension, use it as is. For instance, kc.log.resteasy.

W.r.t. to the initial scope. I wouldn't include any additional extension in the first iteration but enable the properties we want to support. My point is that we should enable JSON format, integration those 3rd party logging services, depending on the feedback we get from the community.

W.r.t. to the changing log settings. I'm more in favor of 2a but it is not an official extension and I'm not sure if we can rely on it. I also do not think we should need anything else to restrict access to endpoints (like changing our main filter) but rely on the existing security capabilities offered by Quarkus (similarly as quarkus-logging-manager extension does).

But I'm really not sure about doing this via HTTP. For now, I would start simple and just go for watching logging changes in keycloak.properties. It is not so bad, you just need to bash into the container (leveraging the security infrastructure from the platform you are running). Could please you also elaborate what are the dark places here you see if we use this approach?

4 replies

DGuhr Nov 22, 2021
Author

@pedroigor thank you for the feedback! See my answers below.

I also agree we should go for kc.log.<category>.<property>. Where category is optional (e.g.: global logging config) and category would follow these rules:

Map to a specific option group/extension. For instance, kc.log.db, kc.log.http, kc.log.cluster, kc.log.myextension.

If a category does not map to a known option group/extension, use it as is. For instance, kc.log.resteasy.

Seems legit for me. we would just need a 1:n mapping from e.g. kc.log.cluster to all cluster-related logging categories, similar to e.g. the 1:n mapping for db=...

W.r.t. to the initial scope. I wouldn't include any additional extension in the first iteration but enable the properties we want to support. My point is that we should enable JSON format, integration those 3rd party logging services, depending on the feedback we get from the community.

I kindly disagree here, imo this is just very very common. But would love to get other feedback here.

W.r.t. to the changing log settings. I'm more in favor of 2a but it is not an official extension and I'm not sure if we can rely on it. I also do not think we should need anything else to restrict access to endpoints (like changing our main filter) but rely on the existing security capabilities offered by Quarkus (similarly as quarkus-logging-manager extension does).

Same for me, I also prefer 2a.

But I'm really not sure about doing this via HTTP. For now, I would start simple and just go for watching logging changes in keycloak.properties. It is not so bad, you just need to bash into the container (leveraging the security infrastructure from the platform you are running). Could please you also elaborate what are the dark places here you see if we use this approach?

For the elaboration part: It's just personal experience, tbh. But was related to a hot-reloaded connection-pool value, i think logging may be less problematic.
For the HTTP/s part: Not sure. Would love to get more feedback :)

cc @jonathanvila @vmuzikar

pedroigor Nov 22, 2021
Collaborator

F438

Regardless the approach (http/file) we should avoid impacting the runtime. For that, we should consider enabling this capability when building the server instead of having enabled by default.

andreaTP Nov 24, 2021

Talking about "personal taste" I do have a (not so)secret love for static configuration and immutability, so, for me Option 3 is totally fine 🙂
In the K8s world you would simply change the configMap/secret mounted as configuration file for the logging and restart the pod.
This works under the assumption that Keycloak would perform zero downtime rolling restarts/updates.

Regarding Option 1, many logging libraries offer file watching and hot reloading out-of-the-box:

It would be interesting to evaluate if something like this can be implemented even without code-changes (e.g. without implementing the File Watching service by ourselves).

pedroigor Dec 2, 2021
Collaborator

We are not restricting people to k8s and we still have requirements for running on bare-metal.

If you can get it for free, one more reason we should not do REST at all. One thing though, we are also trying to design here the abstraction around logging by leveraging Quarkus related properties. Not sure if the watching capabilities from log4j, for instance, should work here? I don't know.

DGuhr · 2021-11-22T16:27:59Z

DGuhr
Nov 22, 2021
Author

I just tried it out a bit on this branch: https://github.com/DGuhr/keycloak/tree/PoC_Logging

Here are some visuals, maybe it helps some ppl:

https://youtu.be/qPuUd1ZE-xU (general test)
https://youtu.be/NuGeL7r_9h0 (playing around with the wildcard config approach)

0 replies

thomasdarimont · 2021-11-24T08:54:54Z

thomasdarimont
Nov 24, 2021
Collaborator

Thanks for creating a discussion for logging. There are also some comments in this Spec PR that might be helpful: keycloak/keycloak-community#238

0 replies

fidgi · 2021-12-02T17:23:47Z

fidgi
Dec 2, 2021

Hi,
Our logs are collected and visualized using ELK .
So , we'd like to output logs to stdout in JSON following the Elastic Common Schema and with the ability to add custom structured fields (which may require to use log4j2 ).

0 replies

trixpan · 2021-12-02T22:42:50Z

trixpan
Dec 2, 2021

I support KC as part of my day to day job and have a background in data engineering in security logging scenarios.

Regarding @DGuhr and @fidgi comments on format (GELF or ECS) I would rather not have format definition nor specific pipeline framework integration bundled out of the box.

The rationale is simple:

Places using Splunk are unlikely to use ECS, while places using ArcSight are unlikely to use JSON.

The overall idea of configuration and extensibility is to be able to use a particular set of features you depend on without having to recompile stuff from zero.

Today, wildfly logging makes using either JSON or KV delimited logging particularly simple. Even multiline logging, the worst logging challenge in java, can be solved by configuring the logging framework to to replace \n with \u2028. Happy days.

Having written a parser for CEF (one of the earliest interactions of log schema standards) I can honestly say that logging formats are set to fail.

Trying to make anything standard across a single enterprise is already hard enough, let aside across different organisations.

To make it worse, most places with high volume logging needs already realised that JSON is terrible for data storage and handling. As consequence I am seeing an increasing number of shops moving to different encoding such as avro or protobufs.

Things gets messy very quickly in logging world. Like REALLY messy.

We, KC users, already struggle with the current dependency injections arising from Wildfly, so my view is, keep things as simple as possible, allow people to extend as they need. this seems to be aligned with overall quarkus modularity principles, so we may just need to figure out a way of configuring them during kc.sh config or similar.

1 reply

pedroigor Dec 20, 2021
Collaborator

@trixpan Nice points. I'm revising my position and also based on @andreaTP feedback, we should probably keep it simple for now and just leverages logging capabilities for Quarkus. That would mean:

Exposing specific logging properties in our side not only to abstract Quarkus properties but also add value for what we think is common (like expiration for daily rotating files, as suggested by @cgeorgilakis, etc).
Logging changes should require a restart and that should be aligned with our immutability store. And not a problem if running on k8s.

cgeorgilakis · 2021-12-03T08:04:38Z

cgeorgilakis
Dec 3, 2021

I am not sure that all this complex log feature is needed.

However, you need to support simple log features that is now difficult with current Keycloak.
One important feature that I do not observe in this discussion is to support log files expiration for daily rotating files ( or being easy to achieve it with other way like configuring libraries like log4j2).
Here you could see the problem we have with this in current Keycloak.

4 replies

trixpan Dec 3, 2021

@cgeorgilakis am I missing something?

quarkus.log.level=INFO
quarkus.log.file.enable=true
quarkus.log.file.level=INFO
quarkus.log.file.format=%d{HH:mm:ss} %-5p [%c{2.}]] (%t) %s%e%n
quarkus.log.file.rotation.max-file-size=1M
quarkus.log.file.rotation.max-backup-index=100
quarkus.log.file.rotation.rotate-on-boot=true

followed by:

find /path/to/log/files -type f -mtime +30 -delete

?

trixpan Dec 3, 2021

if size rotation isn't desired, then

quarkus.log.file.rotation.file-suffix

File handler rotation file suffix. When used, the file will be rotated based on its suffix. Example fileSuffix: .yyyy-MM-dd

cgeorgilakis Dec 3, 2021

We want rotation to be done daily - not per size limit as I see in your configuration - and delete old files ( created x days before) automatically. See for example log4j2 retention policy.
I did not understand your script command.

Keycloak X will support logging libraries supporting by Quarkus?

PS I did not see your last comment. If Quarkus overcome this jboss logging issue we are ok. We have test/search this only in Keycloak 15.

trixpan Dec 3, 2021

@cgeorgilakis

find /path/to/log/files -type f -mtime +30 -delete

running the command above on a daily basis via cronjob will delete any file older than 30 days. ;-)

DGuhr · 2021-12-16T08:55:41Z

DGuhr
Dec 16, 2021
Author

Hey everyone. First of all thank you all for the very valuable Feedback. Just a heads up: I'm looking forward to create some issues out of this discussion and start with a v1 integration early next year, or even this year (when I get bored over christmas ;) ). If anyone is willing to help, feel free to reach out and we'll figure out a work mode (I come from a more "onsite" background, so love to do pairing/ensemble programming if you want).

0 replies

jangaraj · 2022-02-13T13:47:52Z

jangaraj
Feb 13, 2022

Hi, is there any option how to switch Keycloak 17 logs to the JSON format, please?

Naive solution, e.g.:

log-format={"time":"%d{yyyy-MM-dd HH:mm:ss,SSS}", "category":"%c", "thread-name":"%t", "thread-id":"%t{id}", "process-id":"%i", "message":"%m", "exception":"%e"}%n

doesn't work very well.

1 reply

stianst Feb 14, 2022
Maintainer

Could you open a new thread in https://github.com/keycloak/keycloak/discussions/categories/keycloak-x-quarkus-distribution? We should probably just have something simple like "--logging-format=json" or something, but would be good to have a discussion around it.

stianst · 2022-02-14T11:25:47Z

stianst
Feb 14, 2022
Maintainer

I'm going to lock this thread as it is becoming rather lengthy and doesn't have a proper summary/description at the top. @DGuhr will create a new general logging proposal in https://github.com/keycloak/keycloak/discussions/categories/keycloak-x-quarkus-distribution, but in the meantime feel free to open separate discussions about different topics (such as json logging format).

0 replies

Logging in Keycloak.X #8870

Uh oh!

Uh oh!

Replies: 9 comments · 10 replies

Uh oh!

pedroigor Nov 22, 2021 Collaborator

Uh oh!

DGuhr Nov 22, 2021 Author

Uh oh!

pedroigor Nov 22, 2021 Collaborator

Uh oh!

Uh oh!

Uh oh!

pedroigor Dec 2, 2021 Collaborator

Uh oh!

DGuhr Nov 22, 2021 Author

Uh oh!

thomasdarimont Nov 24, 2021 Collaborator

Uh oh!

Uh oh!

Uh oh!

Uh oh!

pedroigor Dec 20, 2021 Collaborator

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

DGuhr Dec 16, 2021 Author

Uh oh!

Uh oh!

stianst Feb 14, 2022 Maintainer

Uh oh!

stianst Feb 14, 2022 Maintainer

Replies: 9 comments 10 replies

pedroigor
Nov 22, 2021
Collaborator

DGuhr Nov 22, 2021
Author

pedroigor Nov 22, 2021
Collaborator

pedroigor Dec 2, 2021
Collaborator

DGuhr
Nov 22, 2021
Author

thomasdarimont
Nov 24, 2021
Collaborator

pedroigor Dec 20, 2021
Collaborator

DGuhr
Dec 16, 2021
Author

stianst Feb 14, 2022
Maintainer

stianst
Feb 14, 2022
Maintainer