Skip to content

Commit

Permalink
Display DevServices logs at build time
Browse files Browse the repository at this point in the history
  • Loading branch information
@stuartwdouglas
stuartwdouglas committed Feb 23, 2021
1 parent 8c6d022 commit ebea896
Show file tree
Hide file tree
Showing 11 changed files with 327 additions and 42 deletions.
30 changes: 29 additions & 1 deletion core/deployment/src/main/java/io/quarkus/deployment/logging/LoggingResourceProcessor.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@
import org.jboss.logmanager.EmbeddedConfigurator;
import org.objectweb.asm.Opcodes;

import io.quarkus.bootstrap.classloading.QuarkusClassLoader;
import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.deployment.GeneratedClassGizmoAdaptor;
import io.quarkus.deployment.annotations.BuildProducer;
Expand All @@ -22,6 +23,7 @@
import io.quarkus.deployment.annotations.Record;
import io.quarkus.deployment.builditem.ConsoleFormatterBannerBuildItem;
import io.quarkus.deployment.builditem.GeneratedClassBuildItem;
import io.quarkus.deployment.builditem.LaunchModeBuildItem;
import io.quarkus.deployment.builditem.LogCategoryBuildItem;
import io.quarkus.deployment.builditem.LogConsoleFormatBuildItem;
import io.quarkus.deployment.builditem.LogHandlerBuildItem;
Expand All @@ -44,10 +46,14 @@
import io.quarkus.gizmo.MethodCreator;
import io.quarkus.gizmo.MethodDescriptor;
import io.quarkus.gizmo.ResultHandle;
import io.quarkus.runtime.LaunchMode;
import io.quarkus.runtime.RuntimeValue;
import io.quarkus.runtime.configuration.ConfigInstantiator;
import io.quarkus.runtime.logging.CategoryBuildTimeConfig;
import io.quarkus.runtime.logging.CleanupFilterConfig;
import io.quarkus.runtime.logging.InheritableLevel;
import io.quarkus.runtime.logging.LogBuildTimeConfig;
import io.quarkus.runtime.logging.LogCleanupFilterElement;
import io.quarkus.runtime.logging.LogConfig;
import io.quarkus.runtime.logging.LogMetricsHandlerRecorder;
import io.quarkus.runtime.logging.LoggingSetupRecorder;
Expand Down Expand Up @@ -124,7 +130,9 @@ void miscSetup(
LoggingSetupBuildItem setupLoggingRuntimeInit(LoggingSetupRecorder recorder, LogConfig log, LogBuildTimeConfig buildLog,
List<LogHandlerBuildItem> handlerBuildItems,
List<NamedLogHandlersBuildItem> namedHandlerBuildItems, List<LogConsoleFormatBuildItem> consoleFormatItems,
Optional<ConsoleFormatterBannerBuildItem> possibleBannerBuildItem) {
Optional<ConsoleFormatterBannerBuildItem> possibleBannerBuildItem,
LaunchModeBuildItem launchModeBuildItem,
List<LogCleanupFilterBuildItem> logCleanupFilters) {
final List<RuntimeValue<Optional<Handler>>> handlers = handlerBuildItems.stream()
.map(LogHandlerBuildItem::getHandlerValue)
.collect(Collectors.toList());
Expand All @@ -142,6 +150,26 @@ LoggingSetupBuildItem setupLoggingRuntimeInit(LoggingSetupRecorder recorder, Log
recorder.initializeLogging(log, buildLog, handlers, namedHandlers,
consoleFormatItems.stream().map(LogConsoleFormatBuildItem::getFormatterValue).collect(Collectors.toList()),
possibleSupplier);
if (launchModeBuildItem.getLaunchMode() != LaunchMode.NORMAL) {
LogConfig logConfig = new LogConfig();
ConfigInstantiator.handleObject(logConfig);
for (LogCleanupFilterBuildItem i : logCleanupFilters) {
CleanupFilterConfig value = new CleanupFilterConfig();
LogCleanupFilterElement filterElement = i.getFilterElement();
value.ifStartsWith = filterElement.getMessageStarts();
value.targetLevel = filterElement.getTargetLevel() == null ? org.jboss.logmanager.Level.DEBUG
: filterElement.getTargetLevel();
logConfig.filters.put(filterElement.getLoggerName(), value);
}
LoggingSetupRecorder.initializeBuildTimeLogging(logConfig, buildLog);
((QuarkusClassLoader) Thread.currentThread().getContextClassLoader()).addCloseTask(new Runnable() {
@Override
public void run() {
InitialConfigurator.DELAYED_HANDLER.buildTimeComplete();
}
});
}

return new LoggingSetupBuildItem();
}

Expand Down
9 changes: 5 additions & 4 deletions core/deployment/src/main/java/io/quarkus/deployment/steps/MainClassBuildStep.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -25,9 +25,9 @@
import org.jboss.jandex.MethodInfo;
import org.jboss.jandex.Type;
import org.jboss.logging.Logger;
import org.jboss.logmanager.handlers.DelayedHandler;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;
import io.quarkus.bootstrap.runner.Timing;
import io.quarkus.builder.Version;
import io.quarkus.deployment.GeneratedClassGizmoAdaptor;
Expand Down Expand Up @@ -288,13 +288,14 @@ void build(List<StaticBytecodeRecorderBuildItem> staticInitTasks,

// an exception was thrown before logging was actually setup, we simply dump everything to the console
ResultHandle delayedHandler = cb
.readStaticField(FieldDescriptor.of(InitialConfigurator.class, "DELAYED_HANDLER", DelayedHandler.class));
ResultHandle isActivated = cb.invokeVirtualMethod(ofMethod(DelayedHandler.class, "isActivated", boolean.class),
.readStaticField(FieldDescriptor.of(InitialConfigurator.class, "DELAYED_HANDLER", QuarkusDelayedHandler.class));
ResultHandle isActivated = cb.invokeVirtualMethod(ofMethod(QuarkusDelayedHandler.class, "isActivated", boolean.class),
delayedHandler);
BytecodeCreator isActivatedFalse = cb.ifNonZero(isActivated).falseBranch();
ResultHandle handlersArray = isActivatedFalse.newArray(Handler.class, 1);
isActivatedFalse.writeArrayValue(handlersArray, 0, isActivatedFalse.newInstance(ofConstructor(ConsoleHandler.class)));
isActivatedFalse.invokeVirtualMethod(ofMethod(DelayedHandler.class, "setHandlers", Handler[].class, Handler[].class),
isActivatedFalse.invokeVirtualMethod(
ofMethod(QuarkusDelayedHandler.class, "setHandlers", Handler[].class, Handler[].class),
delayedHandler, handlersArray);
isActivatedFalse.breakScope();

Expand Down
4 changes: 2 additions & 2 deletions core/runtime/src/main/java/io/quarkus/runtime/graal/LoggingSubstitutions.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@
import java.util.logging.Handler;

import org.jboss.logmanager.LogContext;
import org.jboss.logmanager.handlers.DelayedHandler;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

Expand All @@ -13,6 +12,7 @@
import com.oracle.svm.core.annotate.TargetClass;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;

/**
*/
Expand All @@ -38,7 +38,7 @@ public static Logger getLogger(Class<?> clazz) {
final class Target_io_quarkus_runtime_logging_InitialConfigurator {
@RecomputeFieldValue(kind = RecomputeFieldValue.Kind.FromAlias)
@Alias
public static DelayedHandler DELAYED_HANDLER = new DelayedHandler();
public static QuarkusDelayedHandler DELAYED_HANDLER = new QuarkusDelayedHandler();
}

@TargetClass(java.util.logging.Logger.class)
Expand Down
4 changes: 2 additions & 2 deletions core/runtime/src/main/java/io/quarkus/runtime/logging/CleanupFilterConfig.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,11 +12,11 @@ public class CleanupFilterConfig {
* The message starts to match
*/
@ConfigItem(defaultValue = "inherit")
List<String> ifStartsWith;
public List<String> ifStartsWith;

/**
* The new log level for the filtered message, defaults to DEBUG
*/
@ConfigItem(defaultValue = "DEBUG")
Level targetLevel;
public Level targetLevel;
}
64 changes: 61 additions & 3 deletions core/runtime/src/main/java/io/quarkus/runtime/logging/LoggingSetupRecorder.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -178,7 +178,65 @@ public void initializeLogging(LogConfig config, LogBuildTimeConfig buildConfig,
InitialConfigurator.DELAYED_HANDLER.setHandlers(handlers.toArray(EmbeddedConfigurator.NO_HANDLERS));
}

private Level getLogLevel(String categoryName, CategoryConfig categoryConfig, Map<String, CategoryConfig> categories,
public static void initializeBuildTimeLogging(LogConfig config, LogBuildTimeConfig buildConfig) {

final Map<String, CategoryConfig> categories = config.categories;
final LogContext logContext = LogContext.getLogContext();
final Logger rootLogger = logContext.getLogger("");

rootLogger.setLevel(config.level);

ErrorManager errorManager = new OnlyOnceErrorManager();
final Map<String, CleanupFilterConfig> filters = config.filters;
List<LogCleanupFilterElement> filterElements = new ArrayList<>(filters.size());
for (Entry<String, CleanupFilterConfig> entry : filters.entrySet()) {
filterElements.add(
new LogCleanupFilterElement(entry.getKey(), entry.getValue().targetLevel, entry.getValue().ifStartsWith));
}

final ArrayList<Handler> handlers = new ArrayList<>(3);

if (config.console.enable) {
final Handler consoleHandler = configureConsoleHandler(config.console, errorManager, filterElements,
Collections.emptyList(), new RuntimeValue<>(Optional.empty()));
errorManager = consoleHandler.getErrorManager();
handlers.add(consoleHandler);
}

Map<String, Handler> namedHandlers = createNamedHandlers(config, Collections.emptyList(), errorManager, filterElements);

for (Map.Entry<String, CategoryConfig> entry : categories.entrySet()) {
final CategoryBuildTimeConfig buildCategory = isSubsetOf(entry.getKey(), buildConfig.categories);
final Level logLevel = getLogLevel(entry.getKey(), entry.getValue(), categories, buildConfig.minLevel);
final Level minLogLevel = buildCategory == null
? buildConfig.minLevel
: buildCategory.minLevel.getLevel();

if (logLevel.intValue() < minLogLevel.intValue()) {
log.warnf("Log level %s for category '%s' set below minimum logging level %s, promoting it to %s", logLevel,
entry.getKey(), minLogLevel, minLogLevel);

entry.getValue().level = InheritableLevel.of(minLogLevel.toString());
}
}

for (Map.Entry<String, CategoryConfig> entry : categories.entrySet()) {
final String name = entry.getKey();
final Logger categoryLogger = logContext.getLogger(name);
final CategoryConfig categoryConfig = entry.getValue();
if (!categoryConfig.level.isInherited()) {
categoryLogger.setLevel(categoryConfig.level.getLevel());
}
categoryLogger.setUseParentHandlers(categoryConfig.useParentHandlers);
if (categoryConfig.handlers.isPresent()) {
addNamedHandlersToCategory(categoryConfig, namedHandlers, categoryLogger, errorManager);
}
}
InitialConfigurator.DELAYED_HANDLER.setAutoFlush(false);
InitialConfigurator.DELAYED_HANDLER.setBuildTimeHandlers(handlers.toArray(EmbeddedConfigurator.NO_HANDLERS));
}

private static Level getLogLevel(String categoryName, CategoryConfig categoryConfig, Map<String, CategoryConfig> categories,
Level rootMinLevel) {
if (Objects.isNull(categoryConfig))
return rootMinLevel;
Expand All @@ -195,7 +253,7 @@ private Level getLogLevel(String categoryName, CategoryConfig categoryConfig, Ma
return getLogLevel(parent, categories.get(parent), categories, rootMinLevel);
}

private CategoryBuildTimeConfig isSubsetOf(String categoryName, Map<String, CategoryBuildTimeConfig> categories) {
private static CategoryBuildTimeConfig isSubsetOf(String categoryName, Map<String, CategoryBuildTimeConfig> categories) {
return categories.entrySet().stream()
.filter(buildCategoryEntry -> categoryName.startsWith(buildCategoryEntry.getKey()))
.map(Entry::getValue)
Expand Down Expand Up @@ -233,7 +291,7 @@ private static void addToNamedHandlers(Map<String, Handler> namedHandlers, Handl
namedHandlers.put(handlerName, handler);
}

private void addNamedHandlersToCategory(CategoryConfig categoryConfig, Map<String, Handler> namedHandlers,
private static void addNamedHandlersToCategory(CategoryConfig categoryConfig, Map<String, Handler> namedHandlers,
Logger categoryLogger,
ErrorManager errorManager) {
for (String categoryNamedHandler : categoryConfig.handlers.get()) {
Expand Down
4 changes: 2 additions & 2 deletions ...-extension/deployment/src/test/java/io/quarkus/logging/CategoryConfiguredHandlerTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,14 +7,14 @@

import org.jboss.logmanager.formatters.PatternFormatter;
import org.jboss.logmanager.handlers.ConsoleHandler;
import org.jboss.logmanager.handlers.DelayedHandler;
import org.jboss.logmanager.handlers.FileHandler;
import org.jboss.shrinkwrap.api.ShrinkWrap;
import org.jboss.shrinkwrap.api.spec.JavaArchive;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;
import io.quarkus.test.QuarkusUnitTest;

public class CategoryConfiguredHandlerTest {
Expand All @@ -30,7 +30,7 @@ public void consoleOutputTest() {
LogManager logManager = LogManager.getLogManager();
assertThat(logManager).isInstanceOf(org.jboss.logmanager.LogManager.class);

DelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
QuarkusDelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
assertThat(Logger.getLogger("").getHandlers()).contains(delayedHandler);

Handler handler = Arrays.stream(delayedHandler.getHandlers()).filter(h -> (h instanceof ConsoleHandler))
Expand Down
4 changes: 2 additions & 2 deletions core/test-extension/deployment/src/test/java/io/quarkus/logging/LoggingTestsHelper.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,18 +9,18 @@
import java.util.logging.LogManager;
import java.util.logging.Logger;

import org.jboss.logmanager.handlers.DelayedHandler;
import org.junit.jupiter.api.Assertions;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;

public class LoggingTestsHelper {

public static Handler getHandler(Class clazz) {
LogManager logManager = LogManager.getLogManager();
assertThat(logManager).isInstanceOf(org.jboss.logmanager.LogManager.class);

DelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
QuarkusDelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
assertThat(Logger.getLogger("").getHandlers()).contains(delayedHandler);
assertThat(delayedHandler.getLevel()).isEqualTo(Level.ALL);

Expand Down
4 changes: 2 additions & 2 deletions ...json/deployment/src/test/java/io/quarkus/logging/json/JsonFormatterDefaultConfigTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,11 +14,11 @@
import org.jboss.logmanager.formatters.JsonFormatter;
import org.jboss.logmanager.formatters.StructuredFormatter;
import org.jboss.logmanager.handlers.ConsoleHandler;
import org.jboss.logmanager.handlers.DelayedHandler;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;
import io.quarkus.test.QuarkusUnitTest;

public class JsonFormatterDefaultConfigTest {
Expand All @@ -43,7 +43,7 @@ public static JsonFormatter getJsonFormatter() {
LogManager logManager = LogManager.getLogManager();
assertThat(logManager).isInstanceOf(org.jboss.logmanager.LogManager.class);

DelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
QuarkusDelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
assertThat(Logger.getLogger("").getHandlers()).contains(delayedHandler);
assertThat(delayedHandler.getLevel()).isEqualTo(Level.ALL);

Expand Down
4 changes: 2 additions & 2 deletions ...s/logging-sentry/deployment/src/test/java/io/quarkus/logging/sentry/SentryLoggerTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,11 +8,11 @@
import java.util.logging.LogManager;
import java.util.logging.Logger;

import org.jboss.logmanager.handlers.DelayedHandler;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;

import io.quarkus.bootstrap.logging.InitialConfigurator;
import io.quarkus.bootstrap.logging.QuarkusDelayedHandler;
import io.quarkus.test.QuarkusUnitTest;
import io.sentry.HubAdapter;
import io.sentry.Sentry;
Expand Down Expand Up @@ -41,7 +41,7 @@ public static Handler getSentryHandler() {
LogManager logManager = LogManager.getLogManager();
assertThat(logManager).isInstanceOf(org.jboss.logmanager.LogManager.class);

DelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
QuarkusDelayedHandler delayedHandler = InitialConfigurator.DELAYED_HANDLER;
assertThat(Logger.getLogger("").getHandlers()).contains(delayedHandler);
assertThat(delayedHandler.getLevel()).isEqualTo(Level.ALL);

Expand Down
23 changes: 1 addition & 22 deletions ...ects/bootstrap/runner/src/main/java/io/quarkus/bootstrap/logging/InitialConfigurator.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,34 +6,13 @@
import org.jboss.logmanager.EmbeddedConfigurator;
import org.jboss.logmanager.formatters.PatternFormatter;
import org.jboss.logmanager.handlers.ConsoleHandler;
import org.jboss.logmanager.handlers.DelayedHandler;

/**
*
*/
public final class InitialConfigurator implements EmbeddedConfigurator {

public static final DelayedHandler DELAYED_HANDLER;

static {
//a hack around class loading
//this is always loaded in the root class loader with jboss-logmanager,
//however it may also be loaded in an isolated CL when running in dev
//or test mode. If it is in an isolated CL we load the handler from
//the class on the system class loader so they are equal
//TODO: should this class go in its own module and be excluded from isolated class loading?
DelayedHandler handler = new DelayedHandler();
ClassLoader cl = InitialConfigurator.class.getClassLoader();
try {
Class<?> root = Class.forName(InitialConfigurator.class.getName(), false, ClassLoader.getSystemClassLoader());
if (root.getClassLoader() != cl) {
handler = (DelayedHandler) root.getDeclaredField("DELAYED_HANDLER").get(null);
}
} catch (Exception e) {
//ignore, happens on native image build
}
DELAYED_HANDLER = handler;
}
public static final QuarkusDelayedHandler DELAYED_HANDLER = new QuarkusDelayedHandler();

@Override
public Level getMinimumLevelOf(final String loggerName) {
Expand Down
Loading

0 comments on commit ebea896

Please sign in to comment.