From 214051e4b5f12ff3f2626a8e535614f40b61ff02 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lu=C3=ADs=20Duarte?= Date: Fri, 16 Dec 2022 20:20:16 +0000 Subject: [PATCH] Ensure Logback is refreshed before application starts (#8238) --- .../loggers/impl/LogbackLoggingSystem.java | 28 +++ .../io/micronaut/logging/LoggingSystem.java | 7 + .../logging/LoggingSystemException.java | 49 +++++ .../PropertiesLoggingLevelsConfigurer.java | 10 +- .../logging/impl/LogbackLoggingSystem.java | 30 +++ .../micronaut-runtime/reflect-config.json | 180 ++++++++++++++++++ .../LogbackLogLevelConfigurerSpec.groovy | 74 +++++-- .../src/test/resources/logback-env-test.xml | 14 ++ 8 files changed, 370 insertions(+), 22 deletions(-) create mode 100644 runtime/src/main/java/io/micronaut/logging/LoggingSystemException.java create mode 100644 runtime/src/main/resources/META-INF/native-image/io.micronaut/micronaut-runtime/reflect-config.json create mode 100644 runtime/src/test/resources/logback-env-test.xml diff --git a/management/src/main/java/io/micronaut/management/endpoint/loggers/impl/LogbackLoggingSystem.java b/management/src/main/java/io/micronaut/management/endpoint/loggers/impl/LogbackLoggingSystem.java index 30d1a61fd15..4f0ef79d681 100644 --- a/management/src/main/java/io/micronaut/management/endpoint/loggers/impl/LogbackLoggingSystem.java +++ b/management/src/main/java/io/micronaut/management/endpoint/loggers/impl/LogbackLoggingSystem.java @@ -18,17 +18,24 @@ import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.util.ContextInitializer; +import ch.qos.logback.core.joran.spi.JoranException; +import io.micronaut.context.annotation.Property; import io.micronaut.context.annotation.Replaces; import io.micronaut.context.annotation.Requires; import io.micronaut.core.annotation.NonNull; import io.micronaut.logging.LogLevel; +import io.micronaut.logging.LoggingSystemException; import io.micronaut.management.endpoint.loggers.LoggerConfiguration; import io.micronaut.management.endpoint.loggers.LoggersEndpoint; import io.micronaut.management.endpoint.loggers.ManagedLoggingSystem; import jakarta.inject.Singleton; import org.slf4j.LoggerFactory; +import java.net.URL; import java.util.Collection; +import java.util.Objects; +import java.util.Optional; import java.util.stream.Collectors; /** @@ -42,6 +49,10 @@ @Requires(classes = ch.qos.logback.classic.LoggerContext.class) @Replaces(io.micronaut.logging.impl.LogbackLoggingSystem.class) public class LogbackLoggingSystem implements ManagedLoggingSystem, io.micronaut.logging.LoggingSystem { + private static final String DEFAULT_LOGBACK_LOCATION = "logback.xml"; + + @Property(name = "logger.config") + private Optional logbackXmlLocation; @Override @NonNull @@ -106,4 +117,21 @@ private static Level toLevel(LogLevel logLevel) { return Level.valueOf(logLevel.name()); } } + + @Override + public void refresh() { + LoggerContext context = getLoggerContext(); + context.reset(); + String logbackXml = logbackXmlLocation.orElse(DEFAULT_LOGBACK_LOCATION); + URL resource = getClass().getClassLoader().getResource(logbackXml); + if (Objects.isNull(resource)) { + throw new LoggingSystemException("Resource " + logbackXml + " not found"); + } + + try { + new ContextInitializer(context).configureByResource(resource); + } catch (JoranException e) { + throw new LoggingSystemException("Error while refreshing Logback", e); + } + } } diff --git a/runtime/src/main/java/io/micronaut/logging/LoggingSystem.java b/runtime/src/main/java/io/micronaut/logging/LoggingSystem.java index ba0fbb4e1ea..6a490aaea23 100644 --- a/runtime/src/main/java/io/micronaut/logging/LoggingSystem.java +++ b/runtime/src/main/java/io/micronaut/logging/LoggingSystem.java @@ -38,4 +38,11 @@ public interface LoggingSystem { */ void setLogLevel(@NotBlank String name, @NotNull LogLevel level); + /** + * Refreshes Logging System with the goal of cleaning its internal caches. + * + */ + default void refresh() { + + } } diff --git a/runtime/src/main/java/io/micronaut/logging/LoggingSystemException.java b/runtime/src/main/java/io/micronaut/logging/LoggingSystemException.java new file mode 100644 index 00000000000..d4cff1c77a8 --- /dev/null +++ b/runtime/src/main/java/io/micronaut/logging/LoggingSystemException.java @@ -0,0 +1,49 @@ +/* + * Copyright 2017-2022 original authors + * + * 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 + * + * https://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 io.micronaut.logging; + +/** + * Thrown when something goes wrong on Logging System. + * + * @author Luis Duarte + * @since 3.8 + */ +public class LoggingSystemException extends RuntimeException { + + /** + * Create exception with detailed message and cause. + * + * @param message the detail message (which is saved for later retrieval + * by the {@link #getMessage()} method). + * @param cause the cause (which is saved for later retrieval by the + * {@link #getCause()} method). (A {@code null} value is + * permitted, and indicates that the cause is nonexistent or + * unknown.) + */ + public LoggingSystemException(String message, Throwable cause) { + super(message, cause); + } + + /** + * Create exception with detailed message and cause. + * + * @param message the detail message (which is saved for later retrieval + * by the {@link #getMessage()} method). + */ + public LoggingSystemException(String message) { + super(message); + } +} diff --git a/runtime/src/main/java/io/micronaut/logging/PropertiesLoggingLevelsConfigurer.java b/runtime/src/main/java/io/micronaut/logging/PropertiesLoggingLevelsConfigurer.java index 729903b807a..ab4f4401d67 100644 --- a/runtime/src/main/java/io/micronaut/logging/PropertiesLoggingLevelsConfigurer.java +++ b/runtime/src/main/java/io/micronaut/logging/PropertiesLoggingLevelsConfigurer.java @@ -64,6 +64,7 @@ final class PropertiesLoggingLevelsConfigurer implements ApplicationEventListene public PropertiesLoggingLevelsConfigurer(Environment environment, List loggingSystems) { this.environment = environment; this.loggingSystems = loggingSystems; + initLogging(); configureLogLevels(); } @@ -74,9 +75,12 @@ public PropertiesLoggingLevelsConfigurer(Environment environment, List key.startsWith(LOGGER_LEVELS_PROPERTY_PREFIX))) { - configureLogLevels(); - } + initLogging(); + configureLogLevels(); + } + + private void initLogging() { + this.loggingSystems.forEach(LoggingSystem::refresh); } private void configureLogLevels() { diff --git a/runtime/src/main/java/io/micronaut/logging/impl/LogbackLoggingSystem.java b/runtime/src/main/java/io/micronaut/logging/impl/LogbackLoggingSystem.java index 9a7cf719bf3..5c984f0c3c0 100644 --- a/runtime/src/main/java/io/micronaut/logging/impl/LogbackLoggingSystem.java +++ b/runtime/src/main/java/io/micronaut/logging/impl/LogbackLoggingSystem.java @@ -15,12 +15,20 @@ */ package io.micronaut.logging.impl; +import java.net.URL; +import java.util.Objects; +import java.util.Optional; + import ch.qos.logback.classic.Level; import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.util.ContextInitializer; +import ch.qos.logback.core.joran.spi.JoranException; +import io.micronaut.context.annotation.Property; import io.micronaut.context.annotation.Requires; import io.micronaut.core.annotation.Internal; import io.micronaut.logging.LogLevel; import io.micronaut.logging.LoggingSystem; +import io.micronaut.logging.LoggingSystemException; import jakarta.inject.Singleton; import org.slf4j.LoggerFactory; @@ -35,11 +43,33 @@ @Internal public final class LogbackLoggingSystem implements LoggingSystem { + private static final String DEFAULT_LOGBACK_LOCATION = "logback.xml"; + + @Property(name = "logger.config") + private Optional logbackXmlLocation; + @Override public void setLogLevel(String name, LogLevel level) { getLoggerContext().getLogger(name).setLevel(toLevel(level)); } + @Override + public void refresh() { + LoggerContext context = getLoggerContext(); + context.reset(); + String logbackXml = logbackXmlLocation.orElse(DEFAULT_LOGBACK_LOCATION); + URL resource = getClass().getClassLoader().getResource(logbackXml); + if (Objects.isNull(resource)) { + throw new LoggingSystemException("Resource " + logbackXml + " not found"); + } + + try { + new ContextInitializer(context).configureByResource(resource); + } catch (JoranException e) { + throw new LoggingSystemException("Error while refreshing Logback", e); + } + } + /** * @return The logback {@link LoggerContext} */ diff --git a/runtime/src/main/resources/META-INF/native-image/io.micronaut/micronaut-runtime/reflect-config.json b/runtime/src/main/resources/META-INF/native-image/io.micronaut/micronaut-runtime/reflect-config.json new file mode 100644 index 00000000000..7eac1203c1e --- /dev/null +++ b/runtime/src/main/resources/META-INF/native-image/io.micronaut/micronaut-runtime/reflect-config.json @@ -0,0 +1,180 @@ +[ + { + "name": "org.slf4j.impl.StaticLoggerBinder", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.DateConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.MessageConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ThrowableProxyConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.NopThrowableInformationConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ContextNameConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldYellowCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.LoggerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.ReplacingCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldBlueCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.CyanCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.RedCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.WhiteCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.PropertyConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ExtendedThrowableProxyConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.RootCauseFirstThrowableProxyConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.MethodOfCallerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.LevelConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.IdentityCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldWhiteCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.MarkerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldCyanCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldMagentaCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.RelativeTimeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.MagentaCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ClassOfCallerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.LineOfCallerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.FileOfCallerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldGreenCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.LocalSequenceNumberConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.YellowCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ExtendedThrowableProxyConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.color.HighlightingCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.GrayCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.MDCConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ClassOfCallerConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BoldRedCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.GreenCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.pattern.color.BlackCompositeConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.ThreadConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.pattern.LineSeparatorConverter", + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.classic.encoder.PatternLayoutEncoder", + "allPublicMethods":true, + "allDeclaredConstructors": true + }, + { + "name": "ch.qos.logback.core.ConsoleAppender", + "allPublicMethods":true, + "allDeclaredConstructors": true + }, + { + "name": "com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl", + "allDeclaredConstructors": true + } +] \ No newline at end of file diff --git a/runtime/src/test/groovy/io/micronaut/logging/LogbackLogLevelConfigurerSpec.groovy b/runtime/src/test/groovy/io/micronaut/logging/LogbackLogLevelConfigurerSpec.groovy index e836f362897..949225d8974 100644 --- a/runtime/src/test/groovy/io/micronaut/logging/LogbackLogLevelConfigurerSpec.groovy +++ b/runtime/src/test/groovy/io/micronaut/logging/LogbackLogLevelConfigurerSpec.groovy @@ -2,6 +2,10 @@ package io.micronaut.logging import ch.qos.logback.classic.Level import ch.qos.logback.classic.Logger +import ch.qos.logback.classic.LoggerContext +import ch.qos.logback.classic.spi.ILoggingEvent +import ch.qos.logback.core.Appender +import ch.qos.logback.core.ConsoleAppender import com.github.stefanbirkner.systemlambda.SystemLambda import io.micronaut.context.ApplicationContext import io.micronaut.context.env.PropertySource @@ -17,22 +21,17 @@ class LogbackLogLevelConfigurerSpec extends Specification { @Unroll void 'test that log levels on logger "#loggerName" can be configured via properties'() { given: - ((Logger) LoggerFactory.getLogger('foo.bar1')).setLevel(Level.DEBUG) - ((Logger) LoggerFactory.getLogger('foo.bar2')).setLevel(Level.DEBUG) - ((Logger) LoggerFactory.getLogger('foo.bar3')).setLevel(Level.ERROR) - ((Logger) LoggerFactory.getLogger('foo.barBaz')).setLevel(Level.WARN) - ((Logger) LoggerFactory.getLogger('ignoring.error')).setLevel(Level.INFO) + def loggerLevels = [ + 'logger.levels.aaa.bbb.ccc' : 'ERROR', + 'logger.levels.foo.bar1' : 'DEBUG', + 'logger.levels.foo.bar2' : 'INFO', + 'logger.levels.foo.bar3' : '', + 'logger.levels.foo.barBaz' : 'INFO', + 'logger.levels.ignoring.error': 'OFF', + ] when: - ApplicationContext context = ApplicationContext.run( - [ - 'logger.levels.aaa.bbb.ccc' : 'ERROR', - 'logger.levels.foo.bar2' : 'INFO', - 'logger.levels.foo.bar3' : '', - 'logger.levels.foo.barBaz' : 'INFO', - 'logger.levels.ignoring.error': 'OFF', - ] - ) + ApplicationContext context = ApplicationContext.run(loggerLevels) then: ((Logger) LoggerFactory.getLogger(loggerName)).getLevel() == expectedLevel @@ -89,13 +88,11 @@ logger: } void 'test that log levels can be configured via environment variables'() { - given: - ((Logger) LoggerFactory.getLogger('foo.bar1')).setLevel(Level.DEBUG) - ((Logger) LoggerFactory.getLogger('foo.bar2')).setLevel(Level.DEBUG) - when: ApplicationContext context = ApplicationContext.builder().build() - SystemLambda.withEnvironmentVariable("LOGGER_LEVELS_FOO_BAR2", "INFO") + SystemLambda + .withEnvironmentVariable("LOGGER_LEVELS_FOO_BAR1", "DEBUG") + .and("LOGGER_LEVELS_FOO_BAR2", "INFO") .execute(() -> { context.start() }) @@ -142,4 +139,43 @@ logger: 'foo.bar3' | Level.INFO } + void 'logging refresh is properly called on application start'() { + given: + def map = new YamlPropertySourceLoader().read("application.yml", ''' +logger: + config: logback-env-test.xml + levels: + foo.bar4: ERROR +'''.bytes) + + ApplicationContext context = ApplicationContext.builder() + .propertySources(PropertySource.of("application", map, YamlPropertySourceLoader.DEFAULT_POSITION)) + .build() + + when: + SystemLambda.withEnvironmentVariable("SOME_ENV_VAR", "FOO") + .execute(() -> { + context.start() + LoggerFactory.getLogger("foo.bar4").error("Some error") + }) + + ConsoleAppender consoleAppender + for (Logger logger : ((LoggerContext)LoggerFactory.getILoggerFactory()).getLoggerList()) { + for (Iterator> index = logger.iteratorForAppenders(); index.hasNext();) { + Appender appender = index.next() + if (appender.getName() == "STDOUT") { + consoleAppender = (ConsoleAppender) appender + break + } + } + } + + then: + consoleAppender != null + consoleAppender.getEncoder().getProperties()["pattern"].contains("[FOO]") + + cleanup: + context.close() + } + } diff --git a/runtime/src/test/resources/logback-env-test.xml b/runtime/src/test/resources/logback-env-test.xml new file mode 100644 index 00000000000..06019fc984f --- /dev/null +++ b/runtime/src/test/resources/logback-env-test.xml @@ -0,0 +1,14 @@ + + + + + + %d{HH:mm:ss.SSS} [%thread][${SOME_ENV_VAR}] %-5level %logger{36} - %msg%n + + + + + + +