Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Build time minimum log level #13376

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .github/native-tests.json
Original file line number Diff line number Diff line change
Expand Up @@ -95,7 +95,7 @@
{
"category": "Misc1",
"timeout": 65,
"test-modules": "maven jackson jsonb jsch jgit quartz qute consul-config"
"test-modules": "maven jackson jsonb jsch jgit quartz qute consul-config logging-min-level-unset logging-min-level-set"
},
{
"category": "Misc2",
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3,19 +3,24 @@
import java.util.List;
import java.util.Map;
import java.util.Optional;
import java.util.function.BiFunction;
import java.util.function.Consumer;
import java.util.function.Supplier;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.stream.Collectors;

import org.jboss.logmanager.EmbeddedConfigurator;
import org.objectweb.asm.Opcodes;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.deployment.GeneratedClassGizmoAdaptor;
import io.quarkus.deployment.annotations.BuildProducer;
import io.quarkus.deployment.annotations.BuildStep;
import io.quarkus.deployment.annotations.ExecutionTime;
import io.quarkus.deployment.annotations.Record;
import io.quarkus.deployment.builditem.ConsoleFormatterBannerBuildItem;
import io.quarkus.deployment.builditem.GeneratedClassBuildItem;
import io.quarkus.deployment.builditem.LogCategoryBuildItem;
import io.quarkus.deployment.builditem.LogConsoleFormatBuildItem;
import io.quarkus.deployment.builditem.LogHandlerBuildItem;
Expand All @@ -27,14 +32,35 @@
import io.quarkus.deployment.builditem.nativeimage.ServiceProviderBuildItem;
import io.quarkus.deployment.metrics.MetricsCapabilityBuildItem;
import io.quarkus.deployment.metrics.MetricsFactoryConsumerBuildItem;
import io.quarkus.deployment.pkg.steps.NativeBuild;
import io.quarkus.gizmo.AnnotationCreator;
import io.quarkus.gizmo.BranchResult;
import io.quarkus.gizmo.BytecodeCreator;
import io.quarkus.gizmo.ClassCreator;
import io.quarkus.gizmo.ClassOutput;
import io.quarkus.gizmo.FieldCreator;
import io.quarkus.gizmo.FieldDescriptor;
import io.quarkus.gizmo.MethodCreator;
import io.quarkus.gizmo.MethodDescriptor;
import io.quarkus.gizmo.ResultHandle;
import io.quarkus.runtime.RuntimeValue;
import io.quarkus.runtime.logging.CategoryBuildTimeConfig;
import io.quarkus.runtime.logging.LogBuildTimeConfig;
import io.quarkus.runtime.logging.LogConfig;
import io.quarkus.runtime.logging.LogMetricsHandlerRecorder;
import io.quarkus.runtime.logging.LoggingSetupRecorder;

public final class LoggingResourceProcessor {

private static final String LOGMANAGER_LOGGER_CLASS_NAME = "io.quarkus.runtime.generated.Target_org_jboss_logmanager_Logger";
private static final String LOGGING_LOGGER_CLASS_NAME = "io.quarkus.runtime.generated.Target_org_jboss_logging_Logger";
private static final String LOGGER_NODE_CLASS_NAME = "io.quarkus.runtime.generated.Target_org_jboss_logmanager_LoggerNode";

private static final String MIN_LEVEL_COMPUTE_CLASS_NAME = "io.quarkus.runtime.generated.MinLevelCompute";
private static final MethodDescriptor IS_MIN_LEVEL_ENABLED = MethodDescriptor.ofMethod(MIN_LEVEL_COMPUTE_CLASS_NAME,
"isMinLevelEnabled",
boolean.class, int.class, String.class);

@BuildStep
void setupLogFilters(BuildProducer<LogCleanupFilterBuildItem> filters) {
filters.produce(new LogCleanupFilterBuildItem("org.jboss.threads", "JBoss Threads version"));
Expand Down Expand Up @@ -93,7 +119,7 @@ void miscSetup(

@BuildStep
@Record(ExecutionTime.RUNTIME_INIT)
LoggingSetupBuildItem setupLoggingRuntimeInit(LoggingSetupRecorder recorder, LogConfig log,
LoggingSetupBuildItem setupLoggingRuntimeInit(LoggingSetupRecorder recorder, LogConfig log, LogBuildTimeConfig buildLog,
List<LogHandlerBuildItem> handlerBuildItems,
List<NamedLogHandlersBuildItem> namedHandlerBuildItems, List<LogConsoleFormatBuildItem> consoleFormatItems,
Optional<ConsoleFormatterBannerBuildItem> possibleBannerBuildItem) {
Expand All @@ -111,7 +137,7 @@ LoggingSetupBuildItem setupLoggingRuntimeInit(LoggingSetupRecorder recorder, Log
if (bannerBuildItem != null) {
possibleSupplier = bannerBuildItem.getBannerSupplier();
}
recorder.initializeLogging(log, handlers, namedHandlers,
recorder.initializeLogging(log, buildLog, handlers, namedHandlers,
consoleFormatItems.stream().map(LogConsoleFormatBuildItem::getFormatterValue).collect(Collectors.toList()),
possibleSupplier);
return new LoggingSetupBuildItem();
Expand Down Expand Up @@ -140,4 +166,182 @@ void registerMetrics(LogMetricsHandlerRecorder recorder, LogBuildTimeConfig log,
logHandler.produce(new LogHandlerBuildItem(recorder.getLogHandler()));
}
}

@BuildStep(onlyIf = NativeBuild.class)
void setUpMinLevelLogging(LogBuildTimeConfig log,
final BuildProducer<GeneratedClassBuildItem> generatedTraceLogger) {
ClassOutput output = new GeneratedClassGizmoAdaptor(generatedTraceLogger, false);
if (log.categories.isEmpty() || allMinLevelInfoOrHigher(log.categories)) {
generateDefaultLoggers(output);
} else {
generateCategoryMinLevelLoggers(log.categories, log.minLevel, output);
}
}

private static boolean allMinLevelInfoOrHigher(Map<String, CategoryBuildTimeConfig> categories) {
return categories.values().stream()
.allMatch(categoryConfig -> categoryConfig.minLevel.getLevel().intValue() >= org.jboss.logmanager.Level.INFO
.intValue());
}

private static void generateDefaultLoggers(ClassOutput output) {
generateDefaultLoggingLogger(output);
generateDefaultLoggerNode(output);
generateLogManagerLogger(output, LoggingResourceProcessor::generateMinLevelDefault);
}

private static void generateCategoryMinLevelLoggers(Map<String, CategoryBuildTimeConfig> categories, Level minLevel,
ClassOutput output) {
generateMinLevelCompute(categories, minLevel.toString(), output);
generateDefaultLoggerNode(output);
generateLogManagerLogger(output, LoggingResourceProcessor::generateMinLevelCheckCategory);
}

private static BranchResult generateMinLevelCheckCategory(MethodCreator method, FieldDescriptor nameAliasDescriptor) {
final ResultHandle levelIntValue = getParamLevelIntValue(method);
final ResultHandle nameAlias = method.readInstanceField(nameAliasDescriptor, method.getThis());
return method.ifTrue(method.invokeStaticMethod(IS_MIN_LEVEL_ENABLED, levelIntValue, nameAlias));
}

private static void generateMinLevelCompute(Map<String, CategoryBuildTimeConfig> categories, String defaultMinLevelName,
ClassOutput output) {
try (ClassCreator cc = ClassCreator.builder().setFinal(true)
.className(MIN_LEVEL_COMPUTE_CLASS_NAME)
.classOutput(output).build()) {

try (MethodCreator mc = cc.getMethodCreator(IS_MIN_LEVEL_ENABLED)) {
mc.setModifiers(Opcodes.ACC_STATIC);

final ResultHandle level = mc.getMethodParam(0);
final ResultHandle name = mc.getMethodParam(1);

BytecodeCreator current = mc;
for (Map.Entry<String, CategoryBuildTimeConfig> entry : categories.entrySet()) {
final String category = entry.getKey();
final int categoryLevelIntValue = entry.getValue().minLevel.getLevel().intValue();

ResultHandle equalsResult = current.invokeVirtualMethod(
MethodDescriptor.ofMethod(Object.class, "equals", boolean.class, Object.class),
name, current.load(category));

BranchResult equalsBranch = current.ifTrue(equalsResult);
try (BytecodeCreator false1 = equalsBranch.falseBranch()) {
ResultHandle startsWithResult = false1.invokeVirtualMethod(
MethodDescriptor.ofMethod(String.class, "startsWith", boolean.class, String.class),
name, false1.load(category));

BranchResult startsWithBranch = false1.ifTrue(startsWithResult);

final BytecodeCreator startsWithTrue = startsWithBranch.trueBranch();
final BranchResult levelCompareBranch = startsWithTrue.ifIntegerGreaterEqual(level,
startsWithTrue.load(categoryLevelIntValue));
levelCompareBranch.trueBranch().returnValue(levelCompareBranch.trueBranch().load(true));
levelCompareBranch.falseBranch().returnValue(levelCompareBranch.falseBranch().load(false));

current = startsWithBranch.falseBranch();
}

equalsBranch.trueBranch().returnValue(equalsBranch.trueBranch().load(true));
}

final ResultHandle infoLevelIntValue = getLogManagerLevelIntValue(defaultMinLevelName, current);
final BranchResult isInfoOrHigherBranch = current.ifIntegerGreaterEqual(level, infoLevelIntValue);
isInfoOrHigherBranch.trueBranch().returnValue(isInfoOrHigherBranch.trueBranch().load(true));
isInfoOrHigherBranch.falseBranch().returnValue(isInfoOrHigherBranch.falseBranch().load(false));
}
}
}

private static void generateDefaultLoggerNode(ClassOutput output) {
try (ClassCreator cc = ClassCreator.builder().setFinal(true)
.className(LOGGER_NODE_CLASS_NAME)
.classOutput(output).build()) {

AnnotationCreator targetClass = cc.addAnnotation("com.oracle.svm.core.annotate.TargetClass");
targetClass.addValue("className", "org.jboss.logmanager.LoggerNode");

final MethodCreator isLoggableLevelMethod = cc.getMethodCreator("isLoggableLevel", boolean.class, int.class);
isLoggableLevelMethod.addAnnotation("com.oracle.svm.core.annotate.Alias");
isLoggableLevelMethod.returnValue(isLoggableLevelMethod.load(false));
}
}

private static void generateLogManagerLogger(ClassOutput output,
BiFunction<MethodCreator, FieldDescriptor, BranchResult> isMinLevelEnabledFunction) {
try (ClassCreator cc = ClassCreator.builder().setFinal(true)
.className(LOGMANAGER_LOGGER_CLASS_NAME)
.classOutput(output).build()) {

AnnotationCreator targetClass = cc.addAnnotation("com.oracle.svm.core.annotate.TargetClass");
targetClass.addValue("className", "org.jboss.logmanager.Logger");

FieldCreator nameAlias = cc.getFieldCreator("name", String.class);
nameAlias.addAnnotation("com.oracle.svm.core.annotate.Alias");

FieldCreator loggerNodeAlias = cc.getFieldCreator("loggerNode", LOGGER_NODE_CLASS_NAME);
loggerNodeAlias.addAnnotation("com.oracle.svm.core.annotate.Alias");

final MethodCreator isLoggableMethod = cc.getMethodCreator("isLoggable", boolean.class,
java.util.logging.Level.class);
isLoggableMethod.addAnnotation("com.oracle.svm.core.annotate.Substitute");

final ResultHandle levelIntValue = getParamLevelIntValue(isLoggableMethod);

final BranchResult levelBranch = isMinLevelEnabledFunction.apply(isLoggableMethod, nameAlias.getFieldDescriptor());

final BytecodeCreator levelTrue = levelBranch.trueBranch();
levelTrue.returnValue(
levelTrue.invokeVirtualMethod(
MethodDescriptor.ofMethod(LOGGER_NODE_CLASS_NAME, "isLoggableLevel", boolean.class, int.class),
levelTrue.readInstanceField(loggerNodeAlias.getFieldDescriptor(), levelTrue.getThis()),
levelIntValue));

final BytecodeCreator levelFalse = levelBranch.falseBranch();
levelFalse.returnValue(levelFalse.load(false));
}
}

private static ResultHandle getParamLevelIntValue(MethodCreator method) {
final ResultHandle level = method.getMethodParam(0);
return method
.invokeVirtualMethod(MethodDescriptor.ofMethod(Level.class, "intValue", int.class), level);
}

private static BranchResult generateMinLevelDefault(MethodCreator method, FieldDescriptor nameAliasDescriptor) {
final ResultHandle levelIntValue = getParamLevelIntValue(method);
final ResultHandle infoLevelIntValue = getLogManagerLevelIntValue("INFO", method);
return method.ifIntegerGreaterEqual(levelIntValue, infoLevelIntValue);
}

private static ResultHandle getLogManagerLevelIntValue(String levelName, BytecodeCreator method) {
final ResultHandle infoLevel = method.readStaticField(
FieldDescriptor.of(org.jboss.logmanager.Level.class, levelName, org.jboss.logmanager.Level.class));
return method
.invokeVirtualMethod(MethodDescriptor.ofMethod(Level.class, "intValue", int.class), infoLevel);
}

private static void generateDefaultLoggingLogger(ClassOutput output) {
try (ClassCreator cc = ClassCreator.builder().setFinal(true)
.className(LOGGING_LOGGER_CLASS_NAME)
.classOutput(output).build()) {

AnnotationCreator targetClass = cc.addAnnotation("com.oracle.svm.core.annotate.TargetClass");
targetClass.addValue("className", "org.jboss.logging.Logger");

// Constant fold these methods to return false,
// since the build time log level is above this level.
generateFalseFoldMethod("isTraceEnabled", cc);
generateFalseFoldMethod("isDebugEnabled", cc);
}
}

/**
* Generates a method that is constant-folded to always return false.
*/
private static void generateFalseFoldMethod(String name, ClassCreator cc) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This requires a comment to explain why it's there?

MethodCreator method = cc.getMethodCreator(name, boolean.class);
method.addAnnotation("com.oracle.svm.core.annotate.Substitute");
method.addAnnotation("org.graalvm.compiler.api.replacements.Fold");
method.returnValue(method.load(false));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -168,6 +168,7 @@ public NativeImageBuildItem build(NativeConfig nativeConfig, NativeImageSourceJa
command.add(
"-H:InitialCollectionPolicy=com.oracle.svm.core.genscavenge.CollectionPolicy$BySpaceAndTime"); //the default collection policy results in full GC's 50% of the time
command.add("-H:+JNI");
command.add("-H:+AllowFoldMethods");
command.add("-jar");
command.add(runnerJarName);

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,22 @@
package io.quarkus.runtime.logging;

import io.quarkus.runtime.annotations.ConfigGroup;
import io.quarkus.runtime.annotations.ConfigItem;

@ConfigGroup
public class CategoryBuildTimeConfig {
/**
* The minimum log level for this category.
* By default all categories are configured with <code>INFO</code> minimum level.
*
* To get runtime logging below <code>INFO</code>, e.g. <code>DEBUG</code> or <code>TRACE</code>,
* the minimum level has to be adjusted at build time, the right log level needs to be provided at runtime.
*
* As an example, to get <code>TRACE</code> logging,
* minimum level needs to be at <code>TRACE</code> and the runtime log level needs to match that.
* To get <code>DEBUG</code> logging,
* minimum level needs to be set at <code>DEBUG</code> or <code>TRACE</code> (as well as runtime log level).
*/
@ConfigItem(defaultValue = "inherit")
public InheritableLevel minLevel;
}
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,10 @@
public class CategoryConfig {

/**
* The log level level for this category
* The log level for this category.
*
* Note that to get log levels below <code>INFO</code>,
* the minimum level build time configuration option needs to be adjusted as well.
*/
@ConfigItem(defaultValue = "inherit")
InheritableLevel level;
Expand Down
Original file line number Diff line number Diff line change
@@ -1,5 +1,9 @@
package io.quarkus.runtime.logging;

import java.util.Map;
import java.util.logging.Level;

import io.quarkus.runtime.annotations.ConfigDocSection;
import io.quarkus.runtime.annotations.ConfigItem;
import io.quarkus.runtime.annotations.ConfigPhase;
import io.quarkus.runtime.annotations.ConfigRoot;
Expand All @@ -12,4 +16,21 @@ public class LogBuildTimeConfig {
*/
@ConfigItem(name = "metrics.enabled", defaultValue = "false")
public boolean metricsEnabled;

/**
* The default minimum log level.
*/
@ConfigItem(defaultValue = "INFO")
public Level minLevel;

/**
* Minimum logging categories.
* <p>
* Logging is done on a per-category basis. Each category can be independently configured.
* A configuration which applies to a category will also apply to all sub-categories of that category,
* unless there is a more specific matching sub-category configuration.
*/
@ConfigItem(name = "category")
@ConfigDocSection
public Map<String, CategoryBuildTimeConfig> categories;
}
Original file line number Diff line number Diff line change
Expand Up @@ -33,15 +33,6 @@ public final class LogConfig {
@ConfigItem(defaultValue = "INFO")
public Level level;

/**
* The default minimum log level
*
* @deprecated this functionality was never implemented, it may be deleted or implemented in a future release.
*/
@ConfigItem(defaultValue = "INFO")
@Deprecated
public Level minLevel;

/**
* Console logging.
* <p>
Expand Down
Loading