Initial logging support

Closes #9901
This commit is contained in:
Pedro Igor 2022-02-02 11:53:29 -03:00 committed by Stian Thorgersen
parent 9cb0cc8f8a
commit ec49695a98
14 changed files with 243 additions and 30 deletions

View file

@ -19,7 +19,7 @@ if "%OS%" == "Windows_NT" (
set DIRNAME=.\
)
set "SERVER_OPTS=-Djava.util.logging.manager=org.jboss.logmanager.LogManager"
set "SERVER_OPTS=-Djava.util.logging.manager=org.jboss.logmanager.LogManager -Dquarkus-log-max-startup-records=10000"
set DEBUG_MODE=false
set DEBUG_PORT_VAR=8787

View file

@ -23,7 +23,7 @@ fi
GREP="grep"
DIRNAME=`dirname "$RESOLVED_NAME"`
SERVER_OPTS="-Dkc.home.dir=$DIRNAME/../ -Djboss.server.config.dir=$DIRNAME/../conf -Djava.util.logging.manager=org.jboss.logmanager.LogManager"
SERVER_OPTS="-Dkc.home.dir=$DIRNAME/../ -Djboss.server.config.dir=$DIRNAME/../conf -Djava.util.logging.manager=org.jboss.logmanager.LogManager -Dquarkus-log-max-startup-records=10000"
DEBUG_MODE="${DEBUG:-false}"
DEBUG_PORT="${DEBUG_PORT:-8787}"

View file

@ -17,6 +17,11 @@
package org.keycloak.quarkus.runtime;
import java.util.Arrays;
import java.util.Set;
import java.util.stream.Collectors;
import org.jboss.logging.Logger;
import picocli.CommandLine;
public final class Messages {
@ -49,4 +54,13 @@ public final class Messages {
public static String devProfileNotAllowedError(String cmd) {
return String.format("You can not '%s' the server using the '%s' configuration profile. Please re-build the server first, using 'kc.sh build' for the default production profile, or using 'kc.sh build --profile=<profile>' with a profile more suitable for production.%n", cmd, Environment.DEV_PROFILE_VALUE);
}
public static Throwable invalidLogLevel(String logLevel) {
Set<String> values = Arrays.stream(Logger.Level.values()).map(Logger.Level::name).map(String::toLowerCase).collect(Collectors.toSet());
return new IllegalStateException("Invalid log level: " + logLevel + ". Possible values are: " + String.join(", ", values) + ".");
}
public static Throwable invalidLogCategoryFormat(String category) {
return new IllegalStateException("Invalid log category format: " + category + ". The format is 'category:level' such as 'org.keycloak:debug'.");
}
}

View file

@ -35,6 +35,7 @@ public class MicroProfileConfigProvider implements Config.ConfigProvider {
public static final String NS_KEYCLOAK = "kc";
public static final String NS_KEYCLOAK_PREFIX = NS_KEYCLOAK + ".";
public static final String NS_QUARKUS = "quarkus";
public static final String NS_QUARKUS_PREFIX = "quarkus" + ".";
private final org.eclipse.microprofile.config.Config config;

View file

@ -10,6 +10,7 @@ public enum ConfigCategory {
METRICS("Metrics", 60),
PROXY("Proxy", 70),
VAULT("Vault", 80),
LOGGING("Logging", 90),
GENERAL("General", 999);
private final String heading;

View file

@ -0,0 +1,87 @@
package org.keycloak.quarkus.runtime.configuration.mappers;
import static org.keycloak.quarkus.runtime.integration.QuarkusPlatform.addInitializationException;
import java.util.Locale;
import java.util.function.BiFunction;
import java.util.logging.Level;
import org.jboss.logmanager.LogContext;
import org.keycloak.quarkus.runtime.Messages;
import io.smallrye.config.ConfigSourceInterceptorContext;
final class LoggingPropertyMappers {
private static final String DEFAULT_LOG_LEVEL = "info";
private LoggingPropertyMappers(){}
public static PropertyMapper[] getMappers() {
return new PropertyMapper[] {
builder().from("log-level")
.to("quarkus.log.level")
.transformer(new BiFunction<String, ConfigSourceInterceptorContext, String>() {
@Override
public String apply(String value, ConfigSourceInterceptorContext configSourceInterceptorContext) {
String rootLevel = DEFAULT_LOG_LEVEL;
for (String level : value.split(",")) {
String[] parts = level.split(":");
String category = null;
String categoryLevel;
if (parts.length == 1) {
categoryLevel = parts[0];
} else if (parts.length == 2) {
category = parts[0];
categoryLevel = parts[1];
} else {
addInitializationException(Messages.invalidLogCategoryFormat(level));
return rootLevel;
}
Level levelType;
try {
levelType = toLevel(categoryLevel);
} catch (IllegalArgumentException iae) {
addInitializationException(Messages.invalidLogLevel(categoryLevel));
return rootLevel;
}
if (category == null) {
rootLevel = levelType.getName();
} else {
setCategoryLevel(category, levelType.getName());
}
}
return rootLevel;
}
})
.defaultValue(DEFAULT_LOG_LEVEL)
.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")
.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>\".")
.paramLabel("format")
.build()
};
}
private static Level toLevel(String categoryLevel) throws IllegalArgumentException {
return LogContext.getLogContext().getLevelForName(categoryLevel.toUpperCase(Locale.ROOT));
}
private static void setCategoryLevel(String category, String level) {
LogContext.getLogContext().getLogger(category).setLevel(toLevel(level));
}
private static PropertyMapper.Builder builder() {
return PropertyMapper.builder(ConfigCategory.LOGGING);
}
}

View file

@ -30,6 +30,7 @@ public final class PropertyMappers {
MAPPERS.addAll(ProxyPropertyMappers.getProxyPropertyMappers());
MAPPERS.addAll(VaultPropertyMappers.getVaultPropertyMappers());
MAPPERS.addAll(FeaturePropertyMappers.getMappers());
MAPPERS.addAll(LoggingPropertyMappers.getMappers());
}
public static ConfigValue getValue(ConfigSourceInterceptorContext context, String name) {
@ -50,7 +51,7 @@ public final class PropertyMappers {
}
public static boolean isBuildTimeProperty(String name) {
if (isFeaturesBuildTimeProperty(name) || isSpiBuildTimeProperty(name) || name.startsWith(MicroProfileConfigProvider.NS_QUARKUS)) {
if (isFeaturesBuildTimeProperty(name) || isSpiBuildTimeProperty(name) || name.startsWith(MicroProfileConfigProvider.NS_QUARKUS_PREFIX)) {
return true;
}

View file

@ -18,7 +18,6 @@
# Default options that rely on Quarkus specific options and lacking proper support in Keycloak
# Logging configuration. INFO is the default level for most of the categories
quarkus.log.level = INFO
quarkus.log.category."org.jboss.resteasy.resteasy_jaxrs.i18n".level=WARN
quarkus.log.category."org.infinispan.transaction.lookup.JBossStandaloneJTAManagerLookup".level=WARN

View file

@ -0,0 +1,80 @@
/*
* Copyright 2021 Red Hat, Inc. and/or its affiliates
* and other contributors as indicated by the @author tags.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.keycloak.it.cli.dist;
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertTrue;
import org.junit.jupiter.api.MethodOrderer.OrderAnnotation;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.TestMethodOrder;
import org.keycloak.it.junit5.extension.CLIResult;
import org.keycloak.it.junit5.extension.DistributionTest;
import org.keycloak.it.junit5.extension.RawDistOnly;
import io.quarkus.test.junit.main.Launch;
import io.quarkus.test.junit.main.LaunchResult;
@DistributionTest(reInstall = DistributionTest.ReInstall.NEVER)
@RawDistOnly(reason = "Too verbose for docker and enough to check raw dist")
@TestMethodOrder(OrderAnnotation.class)
public class LoggingDistTest {
@Test
@Launch({ "start-dev", "--log-level=debug" })
void testSetRootLevel(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
assertTrue(cliResult.getOutput().contains("DEBUG [org.hibernate"));
cliResult.assertStartedDevMode();
}
@Test
@Launch({ "start-dev", "--log-level=org.keycloak:debug" })
void testSetCategoryLevel(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
assertFalse(cliResult.getOutput().contains("DEBUG [org.hibernate"));
assertTrue(cliResult.getOutput().contains("DEBUG [org.keycloak"));
cliResult.assertStartedDevMode();
}
@Test
@Launch({ "start-dev", "--log-level=off,org.keycloak:debug,org.infinispan:info" })
void testRootAndCategoryLevels(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
assertFalse(cliResult.getOutput().contains("INFO [io.quarkus"));
assertTrue(cliResult.getOutput().contains("DEBUG [org.keycloak"));
assertTrue(cliResult.getOutput().contains("INFO [org.infinispan.CONTAINER]"));
}
@Test
@Launch({ "start-dev", "--log-level=off,org.keycloak:warn,debug" })
void testSetLastRootLevelIfMultipleSet(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
assertTrue(cliResult.getOutput().contains("DEBUG [org.hibernate"));
assertFalse(cliResult.getOutput().contains("INFO [org.keycloak"));
cliResult.assertStartedDevMode();
}
@Test
@Launch({ "start-dev", "--log-format=\"%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c{1.}] %s%e%n\"" })
void testSetLogFormat(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
assertFalse(cliResult.getOutput().contains("(keycloak-cache-init)"));
cliResult.assertStartedDevMode();
}
}

View file

@ -35,7 +35,7 @@ import io.quarkus.test.junit.main.Launch;
import io.quarkus.test.junit.main.LaunchResult;
@DistributionTest(reInstall = DistributionTest.ReInstall.NEVER)
@BeforeStartDistribution(QuarkusPropertiesAutoBuildDistTest.SetDebugLogLevel.class)
@BeforeStartDistribution(QuarkusPropertiesAutoBuildDistTest.DisableConsoleLogHandler.class)
@RawDistOnly(reason = "Containers are immutable")
@TestMethodOrder(OrderAnnotation.class)
public class QuarkusPropertiesAutoBuildDistTest {
@ -46,8 +46,7 @@ public class QuarkusPropertiesAutoBuildDistTest {
void testReAugOnFirstRun(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertBuild();
cliResult.assertMessage("DEBUG [");
cliResult.assertStarted();
assertFalse(cliResult.getOutput().contains("INFO [io.quarkus]"));
}
@Test
@ -56,33 +55,32 @@ public class QuarkusPropertiesAutoBuildDistTest {
void testSecondStartDoNotTriggerReAug(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertNoBuild();
cliResult.assertMessage("DEBUG [");
cliResult.assertStarted();
assertFalse(cliResult.getOutput().contains("INFO [io.quarkus]"));
}
@Test
@BeforeStartDistribution(SetInfoLogLevel.class)
@BeforeStartDistribution(EnableConsoleLogHandler.class)
@Launch({ "start", "--auto-build", "--http-enabled=true", "--hostname-strict=false", "--cache=local" })
@Order(3)
void testReAugAfterChangingProperty(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertBuild();
assertFalse(cliResult.getOutput().contains("DEBUG ["));
assertTrue(cliResult.getOutput().contains("INFO [io.quarkus]"));
}
public static class SetDebugLogLevel implements Consumer<KeycloakDistribution> {
public static class DisableConsoleLogHandler implements Consumer<KeycloakDistribution> {
@Override
public void accept(KeycloakDistribution distribution) {
distribution.setQuarkusProperty("quarkus.log.level", "DEBUG");
distribution.setQuarkusProperty("quarkus.log.console.enable", "false");
}
}
public static class SetInfoLogLevel implements Consumer<KeycloakDistribution> {
public static class EnableConsoleLogHandler implements Consumer<KeycloakDistribution> {
@Override
public void accept(KeycloakDistribution distribution) {
distribution.setQuarkusProperty("quarkus.log.level", "INFO");
distribution.setQuarkusProperty("quarkus.log.console.enable", "true");
}
}

View file

@ -18,6 +18,7 @@
package org.keycloak.it.cli.dist;
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertTrue;
import java.util.function.Consumer;
import org.junit.jupiter.api.MethodOrderer.OrderAnnotation;
@ -34,7 +35,7 @@ import io.quarkus.test.junit.main.Launch;
import io.quarkus.test.junit.main.LaunchResult;
@DistributionTest(reInstall = DistributionTest.ReInstall.NEVER)
@BeforeStartDistribution(QuarkusPropertiesDistTest.SetDebugLogLevel.class)
@BeforeStartDistribution(QuarkusPropertiesDistTest.DisableConsoleLogHandler.class)
@RawDistOnly(reason = "Containers are immutable")
@TestMethodOrder(OrderAnnotation.class)
public class QuarkusPropertiesDistTest {
@ -44,7 +45,7 @@ public class QuarkusPropertiesDistTest {
@Order(1)
void testBuildWithPropertyFromQuarkusProperties(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertMessage("DEBUG [");
assertFalse(cliResult.getOutput().contains("INFO"));
cliResult.assertBuild();
}
@ -53,52 +54,50 @@ public class QuarkusPropertiesDistTest {
@Order(2)
void testPropertyEnabledAtRuntime(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertMessage("DEBUG [");
cliResult.assertStarted();
assertFalse(cliResult.getOutput().contains("INFO"));
}
@Test
@Launch({ "-Dquarkus.log.level=INFO", "start", "--http-enabled=true", "--hostname-strict=false" })
@Launch({ "-Dquarkus.log.console.enabled=true", "start", "--http-enabled=true", "--hostname-strict=false" })
@Order(3)
void testIgnoreQuarkusSystemPropertiesAtStart(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertMessage("DEBUG [");
cliResult.assertStarted();
assertFalse(cliResult.getOutput().contains("INFO"));
}
@Test
@Launch({ "-Dquarkus.log.level=INFO", "build" })
@Launch({ "-Dquarkus.log.console.enabled=true", "build" })
@Order(4)
void testIgnoreQuarkusSystemPropertyAtBuild(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
cliResult.assertMessage("DEBUG [");
assertFalse(cliResult.getOutput().contains("INFO"));
cliResult.assertBuild();
}
@Test
@BeforeStartDistribution(SetDebugLogLevelInKeycloakConf.class)
@BeforeStartDistribution(DisableConsoleLogHandlerInKeycloakConf.class)
@Launch({ "build" })
@Order(5)
void testIgnoreQuarkusPropertyFromKeycloakConf(LaunchResult result) {
CLIResult cliResult = (CLIResult) result;
assertFalse(cliResult.getOutput().contains("DEBUG ["));
assertTrue(cliResult.getOutput().contains("INFO"));
cliResult.assertBuild();
}
public static class SetDebugLogLevel implements Consumer<KeycloakDistribution> {
public static class DisableConsoleLogHandler implements Consumer<KeycloakDistribution> {
@Override
public void accept(KeycloakDistribution distribution) {
distribution.setQuarkusProperty("quarkus.log.level", "DEBUG");
distribution.setQuarkusProperty("quarkus.log.console.enable", "false");
}
}
public static class SetDebugLogLevelInKeycloakConf implements Consumer<KeycloakDistribution> {
public static class DisableConsoleLogHandlerInKeycloakConf implements Consumer<KeycloakDistribution> {
@Override
public void accept(KeycloakDistribution distribution) {
distribution.deleteQuarkusProperties();
distribution.setProperty("quarkus.log.level", "DEBUG");
distribution.setProperty("quarkus.log.console.enable", "false");
}
}
}

View file

@ -100,6 +100,17 @@ Vault:
--vault-dir <dir> If set, secrets can be obtained by reading the content of files within the
given directory.
Logging:
--log-format <format>
The format of log entries. If the format has spaces in it, you need to escape
the value such as "<format>". Default: %d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c]
(%t) %s%e%n.
--log-level <category:level>
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. Default: info.
Do NOT start the server using this command when deploying to production.
Use 'kc.sh start-dev --help-all' to list all available options, including build

View file

@ -130,6 +130,17 @@ Vault:
--vault-dir <dir> If set, secrets can be obtained by reading the content of files within the
given directory.
Logging:
--log-format <format>
The format of log entries. If the format has spaces in it, you need to escape
the value such as "<format>". Default: %d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c]
(%t) %s%e%n.
--log-level <category:level>
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. Default: info.
Do NOT start the server using this command when deploying to production.
Use 'kc.sh start-dev --help-all' to list all available options, including build

View file

@ -103,6 +103,17 @@ Vault:
--vault-dir <dir> If set, secrets can be obtained by reading the content of files within the
given directory.
Logging:
--log-format <format>
The format of log entries. If the format has spaces in it, you need to escape
the value such as "<format>". Default: %d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c]
(%t) %s%e%n.
--log-level <category:level>
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. Default: info.
You may use the "--auto-build" option when starting the server to avoid running
the "build" command everytime you need to change a static property: