Skip to content

Commit

Permalink
Support for console-JSON and FILE logging
Browse files Browse the repository at this point in the history
See logging.adoc for details on the usage

Closes keycloak#10523, keycloak#10607 and keycloak#10415
  • Loading branch information
DGuhr committed Mar 7, 2022
1 parent e1318d5 commit c9a48ff
Show file tree
Hide file tree
Showing 21 changed files with 535 additions and 57 deletions.
90 changes: 79 additions & 11 deletions docs/guides/src/main/server/logging.adoc
Expand Up @@ -7,9 +7,16 @@ title="Configuring logging"
summary="Learn how to configure Logging"
includedOptions="log-*">
Logging is done on a per-category basis in Keycloak. You can configure logging for the root log level, or for more specific categories like `org.hibernate` or `org.keycloak`. In this guide, you will learn how to configure the log level and format.
Keycloak uses the jboss logmanager logging framework. The high-level overview for the available log handlers is shown below:
== Log level
* root
** console (_default_)
** file

== Logging: Root configuration
Logging is done on a per-category basis in Keycloak. You can configure logging for the root log level, or for more specific categories like `org.hibernate` or `org.keycloak`. In this guide, you will learn how to configure logging.

=== Root Log level
The available log levels are listed in the following Table:

|====
Expand All @@ -29,7 +36,7 @@ The root loggers log level can be set using the following command:

<@kc.start parameters="--log-level=<root-level>"/>

using one of the levels mentioned in the table above. When no log level configuration exists for a more specific category logger, the enclosing category is used instead. When there is no enclosing category, the root logger level is used.
using one of the levels mentioned in the table above. When no log level configuration exists for a more specific category logger (see below), the enclosing category is used instead. When there is no enclosing category, the root logger level is used.

Setting the log level is case-insensitive, so you could either use for example `DEBUG` or `debug`.

Expand All @@ -46,10 +53,17 @@ A configuration that applies to a category also applies to all sub-categories of
<@kc.start parameters="--log-level=INFO,org.hibernate:debug,org.hibernate.hql.internal.ast:info"/>
The example above sets the root log level for all loggers to INFO, and the hibernate log level in general to debug. But as we don't want SQL abstract syntax trees to make the log output verbose, we set the more specific sub category `org.hibernate.hql.internal.ast` to info, so the SQL abstract syntax trees, which would be shown at `debug` level, don't show up anymore.

== Configuring the logging format
Keycloak uses a pattern-based logging formatter that generates human-readable text logs by default.
== Enabling log handlers
To enable one or more log handlers, run the following command:
<@kc.start parameters="--log=<handler1>,<handler2>"/>

The available handlers are `console` and `file`. The more specific handler configuration mentioned below will only take effect when the handler is added to this comma-separated list.

The logging format template for these lines can be applied at the root level.
== Console Log Handler
The console log handler is enabled by default, providing unstructured log messages for the console.

=== Configuring the console log format
Keycloak uses a pattern-based logging formatter that generates human-readable text logs by default.

The default format template is:

Expand All @@ -74,17 +88,71 @@ The format string supports the following symbols:
|%s|Simple message|Renders only the log message, without exception trace.
|%t|Thread name|Renders the thread name.
|%t{id}|Thread ID|Render the thread ID.
|%z{<zone name>}|Time zone|Set the time zone of log output to <zone name>.
|%z{<zone name>}|Timezone|Set the time zone of log output to <zone name>.
|====

=== Set the logging format
To set the logging format for a logged line, build your desired format template using the table above and run the following command:
<@kc.start parameters="--log-format=\"\'<format>\'\""/>

<@kc.start parameters="--log-console-format=\"\'<format>\'\""/>

Be aware that you need to escape characters when invoking commands containing special shell characters such as `;` using the CLI, so you might want to set it in the configuration file instead.

.Example: Abbreviate the fully qualified category name
<@kc.start parameters="\"\'%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c{3.}] (%t) %s%e%n\'\""/>
The example above abbreviates the category name, which could get rather long in some cases, to three characters by setting `[%c{3.}]` in the template instead of the default `[%c]`.
<@kc.start parameters="--log-console-format=\"\'%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c{3.}] (%t) %s%e%n\'\""/>
The example above abbreviates the category name to three characters by setting `[%c{3.}]` in the template instead of the default `[%c]`.

=== Configuring JSON or plain console logging
By default, the console log handler logs plain unstructured data to the console. To use structured JSON log output instead, run the following command:

<@kc.start parameters="--log-console-output=json"/>

.Example Log Message
[source, json]
----
{"timestamp":"2022-02-25T10:31:32.452+01:00","sequence":8442,"loggerClassName":"org.jboss.logging.Logger","loggerName":"io.quarkus","level":"INFO","message":"Keycloak 18.0.0-SNAPSHOT on JVM (powered by Quarkus 2.7.2.Final) started in 3.253s. Listening on: http://0.0.0.0:8080","threadName":"main","threadId":1,"mdc":{},"ndc":"","hostName":"host-name","processName":"QuarkusEntryPoint","processId":36946}
----

When using JSON output, colors are disabled and the format settings set by `--log-console-format` will not apply.

To use unstructured logging, run the following command:

<@kc.start parameters="--log-console-output=default"/>

.Example Log Message:
[source, bash]
----
2022-03-02 10:36:50,603 INFO [io.quarkus] (main) Keycloak 18.0.0-SNAPSHOT on JVM (powered by Quarkus 2.7.2.Final) started in 3.615s. Listening on: http://0.0.0.0:8080
----

=== Colors
Colored console log output for unstructured logs is disabled by default. It may lead to better readability, but can cause problems when shipping logs to external log aggregation systems. If you want to enable or disable color-coded console log output, run following command:

<@kc.start parameters="--log-console-color=<false|true>"/>

== File logging
Instead of logging to the console, Keycloak also supports unstructured logging to a file.

=== Enable file logging
Logging to a file is disabled by default. To enable it, run the following command:

<@kc.start parameters="--log=console,file"/>

=== Configuring path and name of the generated log file
By enabling the file log handler, a log file named `keycloak.log` will be created inside the `data/log` directory of your Keycloak installation.

To change the location and name of the generated log file, run the following command:

<@kc.start parameters="--log=console,file --log-file=<path-to>/<your-file.log>"/>

Please make sure the location for the logfile is writeable. If not, an error will be thrown at start-up. Keycloak will start correctly, but no file containing logs will be created.

=== Configuring the file handler format
You can configure a different logging format for the file log handler by running the following command:

<@kc.start parameters="--log-file-format=<pattern>"/>

Please see the <<Configuring the console log format>> section in this guide for more information and a table of the available pattern configuration.

== Configuring raw quarkus logging properties
At the time of writing, the logging features of the quarkus based Keycloak are basic, yet powerful. Nevertheless, expect more to come and feel free to join the https://github.com/keycloak/keycloak/discussions/8870[discussion] at GitHub.
Expand Down
14 changes: 9 additions & 5 deletions quarkus/deployment/pom.xml
Expand Up @@ -78,21 +78,25 @@
<groupId>io.quarkus</groupId>
<artifactId>quarkus-smallrye-metrics-deployment</artifactId>
</dependency>
<dependency>
<groupId>io.quarkiverse.vault</groupId>
<artifactId>quarkus-vault-deployment</artifactId>
<version>1.0.1</version>
</dependency>
<dependency>
<groupId>io.quarkus</groupId>
<artifactId>quarkus-junit5-internal</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>io.quarkus</groupId>
<artifactId>quarkus-logging-json-deployment</artifactId>
</dependency>
<dependency>
<groupId>io.rest-assured</groupId>
<artifactId>rest-assured</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>io.quarkiverse.vault</groupId>
<artifactId>quarkus-vault-deployment</artifactId>
<version>1.0.1</version>
</dependency>
</dependencies>

<build>
Expand Down
7 changes: 7 additions & 0 deletions quarkus/dist/assembly.xml
Expand Up @@ -79,6 +79,13 @@
<include>*.*</include>
</includes>
</fileSet>
<fileSet>
<directory>src/main/content/data</directory>
<outputDirectory>data</outputDirectory>
<includes>
<include>**/**</include>
</includes>
</fileSet>
<fileSet>
<directory>../../</directory>
<outputDirectory></outputDirectory>
Expand Down
4 changes: 4 additions & 0 deletions quarkus/runtime/pom.xml
Expand Up @@ -79,6 +79,10 @@
<groupId>io.quarkus</groupId>
<artifactId>quarkus-smallrye-metrics</artifactId>
</dependency>
<dependency>
<groupId>io.quarkus</groupId>
<artifactId>quarkus-logging-json</artifactId>
</dependency>
<dependency>
<groupId>org.wildfly.security</groupId>
<artifactId>wildfly-elytron</artifactId>
Expand Down
Expand Up @@ -63,4 +63,12 @@ public static Throwable invalidLogLevel(String logLevel) {
public static Throwable invalidLogCategoryFormat(String category) {
return new IllegalStateException("Invalid log category format: " + category + ". The format is 'category:level' such as 'org.keycloak:debug'.");
}

public static Throwable emptyValueForKey(String key) {
return new IllegalStateException("Value for configuration key '" + key + "' is empty.");
}

public static Throwable notRecognizedValueInList(String key, String values, String expected) {
return new IllegalStateException("Invalid values in list for key: " + key + " Values: " + values + ". Possible values are a combination of: " + expected);
}
}
Expand Up @@ -2,6 +2,8 @@

import static org.keycloak.quarkus.runtime.integration.QuarkusPlatform.addInitializationException;

import java.io.File;
import java.util.List;
import java.util.Locale;
import java.util.function.BiFunction;
import java.util.logging.Level;
Expand All @@ -11,14 +13,25 @@

import io.smallrye.config.ConfigSourceInterceptorContext;

final class LoggingPropertyMappers {
public final class LoggingPropertyMappers {

private static final String DEFAULT_LOG_LEVEL = "info";
private static final String DEFAULT_LOG_HANDLER = "console";
private static final String DEFAULT_LOG_FILENAME = "keycloak.log";
public static final String DEFAULT_LOG_PATH = "data" + File.separator + "log" + File.separator + DEFAULT_LOG_FILENAME;
private static final List<String> AVAILABLE_LOG_HANDLERS = List.of(DEFAULT_LOG_HANDLER,"file");
private static final String DEFAULT_CONSOLE_OUTPUT = "default";

private LoggingPropertyMappers(){}

public static PropertyMapper[] getMappers() {
return new PropertyMapper[] {
builder().from("log")
.defaultValue(DEFAULT_LOG_HANDLER)
.description("Enable one or more log handlers in a comma-separated list. Available log handlers are: " + String.join(",", AVAILABLE_LOG_HANDLERS))
.paramLabel("<handler>")
.expectedValues("console","file","console,file","file,console")
.build(),
builder().from("log-level")
.to("quarkus.log.level")
.transformer(new BiFunction<String, ConfigSourceInterceptorContext, String>() {
Expand Down Expand Up @@ -64,15 +77,96 @@ public String apply(String value, ConfigSourceInterceptorContext configSourceInt
.description("The log level of the root category or a comma-separated list of individual categories and their levels. For the root category, you don't need to specify a category.")
.paramLabel("category:level")
.build(),
builder().from("log-format")
builder().from("log-console-output")
.to("quarkus.log.console.json")
.defaultValue(DEFAULT_CONSOLE_OUTPUT)
.description("Set the log output to JSON or default (plain) unstructured logging.")
.paramLabel("default|json")
.expectedValues(DEFAULT_CONSOLE_OUTPUT,"json")
.transformer((value, context) -> {
if(value.equals(DEFAULT_CONSOLE_OUTPUT)) {
return Boolean.FALSE.toString();
}
return Boolean.TRUE.toString();
})
.build(),
builder().from("log-console-format")
.to("quarkus.log.console.format")
.defaultValue("%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n")
.description("The format of log entries. If the format has spaces in it, you need to escape the value such as \"<format>\".")
.description("The format of unstructured console log entries. If the format has spaces in it, escape the value using \"<format>\".")
.paramLabel("format")
.build(),
builder().from("log-console-color")
.to("quarkus.log.console.color")
.defaultValue(Boolean.FALSE.toString())
.description("Enable or disable colors when logging to console.")
.paramLabel(Boolean.TRUE + "|" + Boolean.FALSE)
.build(),
builder().from("log-console-enabled")
.mapFrom("log")
.to("quarkus.log.console.enable")
.hidden(true)
.transformer(resolveLogHandler(DEFAULT_LOG_HANDLER))
.build(),
builder().from("log-file-enabled")
.mapFrom("log")
.to("quarkus.log.file.enable")
.hidden(true)
.transformer(resolveLogHandler("file"))
.build(),
builder().from("log-file")
.to("quarkus.log.file.path")
.defaultValue(DEFAULT_LOG_PATH)
.description("Set the log file path and filename.")
.paramLabel("<path>/<file-name>.log")
.transformer(LoggingPropertyMappers::resolveFileLogLocation)
.build(),
builder().from("log-file-format")
.to("quarkus.log.file.format")
.defaultValue("%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n")
.description("Set a format specific to file log entries.")
.paramLabel("<format>")
.build()
};
}

private static BiFunction<String, ConfigSourceInterceptorContext, String> resolveLogHandler(String handler) {
return (parentValue, context) -> {

//we want to fall back to console to not have nothing shown up when wrong values are set.
String consoleDependantErrorResult = handler.equals(DEFAULT_LOG_HANDLER) ? Boolean.TRUE.toString() : Boolean.FALSE.toString();

if(parentValue.isBlank()) {
addInitializationException(Messages.emptyValueForKey("log"));
return consoleDependantErrorResult;
}

String[] logHandlerValues = parentValue.split(",");

if (!AVAILABLE_LOG_HANDLERS.containsAll(List.of(logHandlerValues))) {
addInitializationException(Messages.notRecognizedValueInList("log", parentValue, String.join(",", AVAILABLE_LOG_HANDLERS)));
return consoleDependantErrorResult;
}

for (String handlerInput : logHandlerValues) {
if (handlerInput.equals(handler)) {
return Boolean.TRUE.toString();
}
}

return Boolean.FALSE.toString();
};
}

private static String resolveFileLogLocation(String value, ConfigSourceInterceptorContext configSourceInterceptorContext) {
if (value.endsWith(File.separator))
{
return value + DEFAULT_LOG_FILENAME;
}

return value;
}

private static Level toLevel(String categoryLevel) throws IllegalArgumentException {
return LogContext.getLogContext().getLevelForName(categoryLevel.toUpperCase(Locale.ROOT));
}
Expand Down
4 changes: 4 additions & 0 deletions quarkus/runtime/src/main/resources/META-INF/keycloak.conf
Expand Up @@ -22,3 +22,7 @@ metrics-enabled=false
%import_export.hostname-strict=false
%import_export.hostname-strict-https=false
%import_export.cluster=local

#logging defaults
log-console-output=default
log-file=${kc.home.dir:default}data/log/keycloak.log
Expand Up @@ -419,6 +419,24 @@ public void testResolveMetricsOption() {
assertEquals("true", config.getConfigValue("quarkus.datasource.metrics.enabled").getValue());
}

@Test
public void testLogHandlerConfig() {
System.setProperty(CLI_ARGS, "--log=console,file");
SmallRyeConfig config = createConfig();
assertEquals("true", config.getConfigValue("quarkus.log.console.enable").getValue());
assertEquals("true", config.getConfigValue("quarkus.log.file.enable").getValue());

System.setProperty(CLI_ARGS, "--log=file");
SmallRyeConfig config2 = createConfig();
assertEquals("false", config2.getConfigValue("quarkus.log.console.enable").getValue());
assertEquals("true", config2.getConfigValue("quarkus.log.file.enable").getValue());

System.setProperty(CLI_ARGS, "--log=console");
SmallRyeConfig config3 = createConfig();
assertEquals("true", config3.getConfigValue("quarkus.log.console.enable").getValue());
assertEquals("false", config3.getConfigValue("quarkus.log.file.enable").getValue());
}

@Test
public void testOptionValueWithEqualSign() {
System.setProperty(CLI_ARGS, "--db-password=my_secret=");
Expand Down

0 comments on commit c9a48ff

Please sign in to comment.