diff --git a/docs/asciidoc/configuration.adoc b/docs/asciidoc/configuration.adoc index bf5c46989a..df878ecf91 100644 --- a/docs/asciidoc/configuration.adoc +++ b/docs/asciidoc/configuration.adoc @@ -157,13 +157,20 @@ Jooby uses **SLF4J**, allowing you to plug in your preferred logging framework. 1. **Add Dependencies:** `log4j-slf4j-impl` and `log4j-core`. 2. **Configure:** Place `log4j2.xml` in your `conf` directory or classpath root. +===== Rainbow Gum + +Add `jooby-rainbowgum` to configure logging directly in `application.conf`, including environment-specific +files. The module includes the SLF4J provider and pattern encoder and handles logging before the +application environment is available. See link:{uiVersion}/modules/rainbowgum[Rainbow Gum] for examples +and configuration updates. + ===== Environment-Aware Logging Logging is also environment-aware. Jooby will look for `logback.[env].xml` or `log4j2.[env].xml` and favor them over the default files. [IMPORTANT] ==== -To ensure environment-specific logging works correctly, avoid using **static** loggers in your main App class before `runApp` is called. Static loggers force the logging framework to initialize before Jooby can apply the environment-specific configuration. Use an instance logger or Jooby's `getLog()` method instead. +With Logback or Log4j2, to ensure environment-specific logging works correctly, avoid using **static** loggers in your main App class before `runApp` is called. Static loggers force the logging framework to initialize before Jooby can apply the environment-specific configuration. Use an instance logger or Jooby's `getLog()` method instead. ==== ==== Application Properties diff --git a/docs/asciidoc/modules/modules.adoc b/docs/asciidoc/modules/modules.adoc index e538064796..f6c1fb16bf 100644 --- a/docs/asciidoc/modules/modules.adoc +++ b/docs/asciidoc/modules/modules.adoc @@ -49,6 +49,9 @@ Modules are distributed as separate dependencies. Below is the catalog of offici * link:{uiVersion}/modules/jackson3[Jackson3]: Jackson3 module for Jooby. * link:{uiVersion}/modules/yasson[Yasson]: JSON-B module for Jooby. +==== Logging + * link:{uiVersion}/modules/rainbowgum[Rainbow Gum]: SLF4J logging configured through the application environment. + ==== Metrics * link:{uiVersion}/modules/metrics[Metrics]: Application metrics from the excellent metrics library. * link:{uiVersion}/modules/opentelemetry[Open Telemetry]: Application metrics using Open Telemetry library. diff --git a/docs/asciidoc/modules/rainbowgum.adoc b/docs/asciidoc/modules/rainbowgum.adoc new file mode 100644 index 0000000000..453d7cf3e2 --- /dev/null +++ b/docs/asciidoc/modules/rainbowgum.adoc @@ -0,0 +1,93 @@ +== Rainbow Gum + +https://jstach.io/rainbowgum/[Rainbow Gum] is an SLF4J implementation for Java 21 and newer. +The `jooby-rainbowgum` module configures it directly from Jooby's resolved Typesafe Config environment. + +=== Usage + +Add the dependency: + +[dependency, artifactId="jooby-rainbowgum"] +. + +Use this module in place of `jooby-logback`, `jooby-log4j`, or another SLF4J provider. +No `install(...)` call or separate logging configuration file is needed. The module includes the +SLF4J provider, pattern encoder and file output support. + +.application.conf +[source, hocon] +---- +logging { + level { + root = info + "com.myapp" = debug + } + appenders = [console] + appender.console { + output.uri = stdout + encoder { + uri = pattern + pattern.pattern = "[%thread] %-5level %logger - %msg%n" + } + } +} +---- + +All Rainbow Gum properties are available, including appenders, encoders, routes and asynchronous +publishers. Native HOCON lists and maps are supported. Quote dotted logger names so they remain +one object member. Use `logging.level.root` for the root level when defining other logger levels +in the same object; HOCON cannot keep `logging.level` as both a scalar and an object. + +Jooby resolves `application.conf`, environment-specific files such as `application.prod.conf`, +substitutions and system properties before passing the environment to Rainbow Gum. Programmatic +environments supplied through `setEnvironment(...)` and `setEnvironmentOptions(...)` also configure +logging. + +Logging is global to the JVM and configured once, from the first environment Jooby loads, as with +Jooby's other logging implementations. Later environments, such as those of additional applications +started by `runApp` or another `setEnvironment(...)` call, do not change it. + +=== Early logging + +A bootstrap Rainbow Gum queues messages emitted before Jooby loads its environment, including messages +from static loggers. When the environment is available, the module installs the configured Rainbow +Gum, replays queued messages through its routes, and moves loggers created during bootstrap to its +levels and routes. It then closes the bootstrap instance. An explicitly installed Rainbow Gum, or one supplied by the application's own +`RainbowGumProvider`, is left under the application's control. + +Caller information and decorators are chosen when a logger is created. For loggers created during +bootstrap, configure these capabilities before startup (for example, +`-Dlogging.caller.logger.root=true`); the later environment configuration does not retrofit them. + +=== Configuration changes + +Jooby core does not watch configuration files or publish configuration-change events. Jooby Run's +development watcher restarts the application but keeps project dependencies loaded, so logging keeps +the configuration from the first start. Restart Jooby Run to apply logging changes. + +Loggers have a fixed level once created. To let existing loggers follow level changes, allow them +with Rainbow Gum's `logging.change.logger` property: + +.application.conf +[source, hocon] +---- +logging.change.logger = level +---- + +The application can then replace the configuration of its environment and reread logger levels +without reopening appenders: + +[source, java] +---- +getEnvironment().setConfig(updatedConfig); +RainbowGum.of().config().changePublisher().publish(); +---- + +=== Server logger muting + +Jooby turns off some server loggers while the server starts and stops. The module allows level +changes for those loggers only: `org.eclipse.jetty.server` for Jetty, and `io.undertow`, `org.xnio` +and `org.jboss.threads` for Undertow. `logging.change.mode = off` turns off all level changes, +including this muting. + +See the https://jstach.io/rainbowgum/[Rainbow Gum guide] for the complete configuration reference. diff --git a/jooby/src/main/java/io/jooby/Jooby.java b/jooby/src/main/java/io/jooby/Jooby.java index 77d758880d..6437386796 100644 --- a/jooby/src/main/java/io/jooby/Jooby.java +++ b/jooby/src/main/java/io/jooby/Jooby.java @@ -151,7 +151,7 @@ public Jooby setRouterOptions(RouterOptions options) { */ public Environment getEnvironment() { if (env == null) { - env = Environment.loadEnvironment(environmentOptions); + setEnvironment(Environment.loadEnvironment(environmentOptions)); } return env; } @@ -213,6 +213,7 @@ public Config getConfig() { */ public Jooby setEnvironment(Environment environment) { this.env = environment; + LoggingService.configure(environment); return this; } @@ -224,9 +225,9 @@ public Jooby setEnvironment(Environment environment) { */ public Environment setEnvironmentOptions(EnvironmentOptions options) { this.environmentOptions = options; - this.env = + setEnvironment( Environment.loadEnvironment( - options.setClassLoader(options.getClassLoader(getClass().getClassLoader()))); + options.setClassLoader(options.getClassLoader(getClass().getClassLoader())))); return this.env; } diff --git a/jooby/src/main/java/io/jooby/LoggingService.java b/jooby/src/main/java/io/jooby/LoggingService.java index 727cceaec0..5a57e46e45 100644 --- a/jooby/src/main/java/io/jooby/LoggingService.java +++ b/jooby/src/main/java/io/jooby/LoggingService.java @@ -18,8 +18,8 @@ import org.jspecify.annotations.Nullable; /** - * Describe the underlying logging system. Jooby provides two implementation: jooby-logback and - * jooby-log4j. You might want to add one of these to your classpath, yet still these are optional. + * Describe the underlying logging system. Jooby provides jooby-logback, jooby-log4j and + * jooby-rainbowgum. These integrations are optional; add one to your classpath. * * @since 3.0.1 */ @@ -32,6 +32,26 @@ public interface LoggingService { */ String getPropertyName(); + /** + * Initializes logging using the application's resolved environment. Called when Jooby loads or + * replaces its environment, including environments supplied programmatically. The default does + * nothing, for logging systems configured by their own files. + * + * @param environment Application environment. + */ + default void initialize(Environment environment) {} + + /** + * Initializes the installed logging service using the application's resolved environment. + * + * @param environment Application environment. + */ + static void configure(Environment environment) { + ServiceLoader.load(LoggingService.class, environment.getClassLoader()) + .findFirst() + .ifPresent(service -> service.initialize(environment)); + } + /** * List of possible names for configuration file. Like: logback.xml, log4j.properties, etc.. * . diff --git a/jooby/src/test/java/io/jooby/LoggingServiceTest.java b/jooby/src/test/java/io/jooby/LoggingServiceTest.java index cfa155f6d0..6538a83f64 100644 --- a/jooby/src/test/java/io/jooby/LoggingServiceTest.java +++ b/jooby/src/test/java/io/jooby/LoggingServiceTest.java @@ -58,6 +58,23 @@ private void restore(String key, String value) { } } + @Test + public void configureResolvedEnvironment() { + var environment = + new Environment( + getClass().getClassLoader(), com.typesafe.config.ConfigFactory.empty(), "test"); + try (MockedStatic serviceLoaderMock = mockStatic(ServiceLoader.class)) { + ServiceLoader loader = mock(ServiceLoader.class); + LoggingService service = mock(LoggingService.class); + when(loader.findFirst()).thenReturn(Optional.of(service)); + serviceLoaderMock + .when(() -> ServiceLoader.load(LoggingService.class, environment.getClassLoader())) + .thenReturn(loader); + LoggingService.configure(environment); + verify(service).initialize(environment); + } + } + @Test public void isBinaryPath() { assertFalse(LoggingService.isBinary(Paths.get("src", "main", "java"))); diff --git a/modules/jooby-bom/pom.xml b/modules/jooby-bom/pom.xml index 600911803b..0c482e0967 100644 --- a/modules/jooby-bom/pom.xml +++ b/modules/jooby-bom/pom.xml @@ -300,6 +300,11 @@ jooby-quartz ${project.version} + + io.jooby + jooby-rainbowgum + ${project.version} + io.jooby jooby-reactor diff --git a/modules/jooby-rainbowgum/NOTE.md b/modules/jooby-rainbowgum/NOTE.md new file mode 100644 index 0000000000..38c12cc733 --- /dev/null +++ b/modules/jooby-rainbowgum/NOTE.md @@ -0,0 +1,83 @@ +# Rainbow Gum integration review notes + +Working notes for this branch. Remove before merging. + +## Public API added outside this module + +Only `io.jooby.LoggingService` changes: + +- `default void initialize(Environment environment)`: a hook for logging systems configured from the + Jooby environment. The default does nothing, so `jooby-logback` and `jooby-log4j` are unchanged. +- `static void configure(Environment environment)`: finds the installed `LoggingService` with the + environment's class loader and calls `initialize`. It is public only because interface static + methods cannot be package private; `Jooby` is its only caller. It overloads the existing + `configure(ClassLoader, List)`. + +`Jooby` keeps its signatures, but `setEnvironment`, `setEnvironmentOptions` and the lazy load in +`getEnvironment` now all go through `setEnvironment`, which calls `LoggingService.configure`. Every +environment Jooby loads or is given now does a `ServiceLoader` lookup. + +The BOM and the parent pom gain `jooby-rainbowgum`, and the parent pom gains `rainbowgum.version`. + +## Changed in review + +- **Bootstrap marker.** The marker that lets Jooby replace the bootstrap Rainbow Gum was added by a + `PropertiesProvider`, which runs for every service loaded `LogConfig`. A Rainbow Gum the + application built from such a config, or supplied by its own `RainbowGumProvider`, was closed and + replaced when the environment loaded. `RainbowGumBootstrap` now builds its own config with the + marker and has the lowest priority. +- **Configured once.** Only the queued bootstrap instance is replaced. Loggers with a fixed level + stay bound to the instance that created them, so rebuilding logging for a later environment left + them writing to a closed instance and their events were lost. Making every logger changeable hid + this. Later environments (`runApp` with several applications, another `setEnvironment(...)`, test + suites starting an application per class) now keep the first configuration, as Logback and Log4j + do. +- **Level changes only where muting needs them.** Defaults allow level changes for the loggers Jetty + and Undertow mute (`org.eclipse.jetty.server`, `io.undertow`, `org.xnio`, `org.jboss.threads`) + instead of every logger, so other loggers keep the fixed level fast path. Rereading levels with + `changePublisher().publish()` is opt in through `logging.change.logger`. + +## Open on this branch + +- **Unbounded queue.** If no Jooby environment is ever loaded (unit tests that never read the + config, command line tools), INFO and above queue in memory for the life of the JVM and are never + written. Only ERROR reaches stderr. Probably needs a Rainbow Gum side fix: a bounded queue or a + flush at shutdown. +- **Muting with an application Rainbow Gum.** Muting levels are only wired into the module's own + config, so `logOff` does nothing when the application installed its own Rainbow Gum. +- **Failed logging setup.** `Jooby.setEnvironment` stores the environment before configuring + logging. If the logging config is invalid the call throws, but `getEnvironment()` then returns that + environment and logging stays queued. +- **Jooby Run.** Dependencies stay loaded across restarts in the default mode, so logging keeps the + first start's configuration (documented). The configured instance also keeps the first + `Environment`, and with it the first project class loader, reachable. With + `useSingleClassLoader` everything reloads, so each restart configures a new instance, but nothing + closes the previous class loader's instance or removes its shutdown hook. This is from reading the + code, not tested. + +## GraalVM native image + +Checked with GraalVM CE 25.0.4 `native-image` on a small Jetty application with a static logger +and a `logging` block in `application.conf`. This module needs no native image metadata: its +service providers are registered from `META-INF/services`, and the native executable printed the +same output as the JVM run (early message replayed through the configured pattern, debug levels +from the config, Jetty startup muted). + +Jooby itself ships no native image metadata. Without it, a classpath `application.conf` is not in +the image, and Jooby silently falls back to defaults (port 8080, default logging). The application +had to add `META-INF/native-image///reachability-metadata.json` with +`{"resources": [{"glob": "application*.conf"}]}`. Jooby could ship that resource entry in its own +jar. + +## Jooby bugs outside this module + +- **Log4j `logOff` does not restore exactly configured loggers.** `Log4jService.setLog4jLevel` reads + `logger.getLevel()` after `Configurator.setLevel`, which sets an existing `LoggerConfig` with that + exact name in place (checked against log4j-core 2.26.1). The saved level is OFF, so a muted logger + configured by name in `log4j2.xml` stays off. The first mute also adds a `LoggerConfig` with that + name, so after one start and stop every muted logger is affected on the next start in the same JVM. + Fix: read the level before setting it. +- **Jetty mutes `org.eclipse.jetty.server.Server` twice.** `JettyServer.getLoggerOff()` lists it + twice. Logback and Log4j `logOff` record the previous level per name, so the second entry records + OFF over the original and the logger stays off after startup. Fix: drop the duplicate, or apply + `distinct()` in `MutedServer`. diff --git a/modules/jooby-rainbowgum/pom.xml b/modules/jooby-rainbowgum/pom.xml new file mode 100644 index 0000000000..e1e44946d7 --- /dev/null +++ b/modules/jooby-rainbowgum/pom.xml @@ -0,0 +1,43 @@ + + + 4.0.0 + + io.jooby + modules + 4.5.5-SNAPSHOT + + jooby-rainbowgum + jooby-rainbowgum + + + io.jooby + jooby + + + io.jstach.rainbowgum + rainbowgum-slf4j + ${rainbowgum.version} + + + io.jstach.rainbowgum + rainbowgum-pattern + ${rainbowgum.version} + + + io.jstach.rainbowgum + rainbowgum-file + ${rainbowgum.version} + + + org.junit.jupiter + junit-jupiter-engine + test + + + org.jacoco + org.jacoco.agent + runtime + test + + + diff --git a/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/ConfigProperties.java b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/ConfigProperties.java new file mode 100644 index 0000000000..3a3a880381 --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/ConfigProperties.java @@ -0,0 +1,89 @@ +/* + * Jooby https://jooby.io + * Apache License Version 2.0 https://jooby.io/LICENSE.txt + * Copyright 2014 Edgar Espina + */ +package io.jooby.rainbowgum; + +import java.util.LinkedHashMap; +import java.util.List; +import java.util.Map; +import java.util.function.Supplier; + +import org.jspecify.annotations.Nullable; + +import com.typesafe.config.Config; +import com.typesafe.config.ConfigList; +import com.typesafe.config.ConfigObject; +import com.typesafe.config.ConfigValue; +import com.typesafe.config.ConfigValueType; +import io.jstach.rainbowgum.LogProperties; + +/** Reads native HOCON objects, including quoted logger names, lists and maps. */ +final class ConfigProperties extends LogProperties.AbstractNested { + private final Supplier config; + + ConfigProperties(Supplier config) { + this.config = config; + } + + @Override + protected ConfigValue doRootNodeOrNull() { + return config.get().root(); + } + + @Override + protected @Nullable ConfigValue doMemberNodeOrNull(ConfigValue node, String name) { + return node instanceof ConfigObject object ? object.get(name) : null; + } + + @Override + protected @Nullable String doValueNodeOrNull(ConfigValue node) { + return switch (node.valueType()) { + case STRING, NUMBER, BOOLEAN -> String.valueOf(node.unwrapped()); + default -> null; + }; + } + + @Override + protected @Nullable List doListNodeOrNull(ConfigValue node) { + if (!(node instanceof ConfigList list)) { + return null; + } + return list.stream().map(this::scalar).toList(); + } + + @Override + protected @Nullable Map doMapNodeOrNull(ConfigValue node) { + if (!(node instanceof ConfigObject object)) { + return null; + } + Map result = new LinkedHashMap<>(); + object.forEach( + (key, value) -> { + if (value.valueType() != ConfigValueType.NULL) { + result.put(key, scalar(value)); + } + }); + return result; + } + + private String scalar(ConfigValue value) { + var scalar = doValueNodeOrNull(value); + if (scalar == null) { + throw new IllegalArgumentException( + "Expected a scalar logging value at " + value.origin().description()); + } + return scalar; + } + + @Override + public int order() { + return 300; + } + + @Override + public String description(String key) { + return "Jooby configuration[" + key + "]"; + } +} diff --git a/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/RainbowGumBootstrap.java b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/RainbowGumBootstrap.java new file mode 100644 index 0000000000..47f246bdd2 --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/RainbowGumBootstrap.java @@ -0,0 +1,40 @@ +/* + * Jooby https://jooby.io + * Apache License Version 2.0 https://jooby.io/LICENSE.txt + * Copyright 2014 Edgar Espina + */ +package io.jooby.rainbowgum; + +import java.util.List; +import java.util.Optional; + +import io.jstach.rainbowgum.LogConfig; +import io.jstach.rainbowgum.LogProperties; +import io.jstach.rainbowgum.RainbowGum; +import io.jstach.rainbowgum.ServiceRegistry; +import io.jstach.rainbowgum.spi.RainbowGumServiceProvider; + +/** Queues logging before Jooby's application environment is available. */ +public final class RainbowGumBootstrap implements RainbowGumServiceProvider.RainbowGumProvider { + /** For service loading. */ + public RainbowGumBootstrap() {} + + @Override + public Optional provide(LogConfig config) { + // Only this queued instance is marked as Jooby's, not every service loaded config. + var registry = ServiceRegistry.of(); + RainbowGumService.markBootstrap(registry); + var properties = + LogProperties.of( + List.of( + LogProperties.StandardProperties.SYSTEM_PROPERTIES, RainbowGumService.DEFAULTS)); + var bootstrap = LogConfig.builder().properties(properties).serviceRegistry(registry).build(); + return Optional.of(RainbowGum.queued(bootstrap)); + } + + @Override + public int priority() { + // Application providers win; their Rainbow Gum is left under the application's control. + return Integer.MIN_VALUE; + } +} diff --git a/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/RainbowGumService.java b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/RainbowGumService.java new file mode 100644 index 0000000000..595980900d --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/RainbowGumService.java @@ -0,0 +1,146 @@ +/* + * Jooby https://jooby.io + * Apache License Version 2.0 https://jooby.io/LICENSE.txt + * Copyright 2014 Edgar Espina + */ +package io.jooby.rainbowgum; + +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.ServiceLoader; +import java.util.concurrent.ConcurrentHashMap; + +import io.jooby.Environment; +import io.jooby.LoggingService; +import io.jooby.SneakyThrows; +import io.jstach.rainbowgum.LogConfig; +import io.jstach.rainbowgum.LogProperties; +import io.jstach.rainbowgum.RainbowGum; +import io.jstach.rainbowgum.ServiceRegistry; +import io.jstach.rainbowgum.spi.RainbowGumServiceProvider; + +/** Configures Rainbow Gum from Jooby's resolved application configuration. */ +public final class RainbowGumService implements LoggingService { + private static final Object LOCK = new Object(); + private static final Map MUTED = new HashMap<>(); + private static final Map LEVELS = new ConcurrentHashMap<>(); + + /* + * Only the loggers servers mute during start and stop can change level, so other loggers keep + * Rainbow Gum's fixed level fast path. + */ + static final LogProperties DEFAULTS = + LogProperties.builder() + .fromProperties( + """ + logging.change.mode=on + logging.change.logger.org.eclipse.jetty.server=level + logging.change.logger.io.undertow=level + logging.change.logger.org.xnio=level + logging.change.logger.org.jboss.threads=level + """) + .description("Jooby logging defaults") + .order(-1000) + .build(); + + enum Bootstrap { + INSTANCE + } + + /** For service loading. */ + public RainbowGumService() {} + + static void markBootstrap(ServiceRegistry registry) { + registry.put(Bootstrap.class, Bootstrap.INSTANCE); + } + + @Override + public void initialize(Environment environment) { + synchronized (LOCK) { + var previous = RainbowGum.getOrNull(); + if (previous != null + && previous.config().serviceRegistry().findOrNull(Bootstrap.class) == null) { + /* + * Logging is configured once per JVM from the first environment, as with Logback and Log4j. + * Loggers with a fixed level stay bound to the instance that created them, so replacing it + * would leave them writing to a closed instance. An explicitly installed Rainbow Gum also + * remains under the application's control. + */ + return; + } + var properties = + LogProperties.of( + List.of( + LogProperties.StandardProperties.SYSTEM_PROPERTIES, + new ConfigProperties(environment::getConfig), + DEFAULTS)); + var config = + LogConfig.builder() + .properties(properties) + .config(LEVELS::get) + .serviceLoader( + ServiceLoader.load(RainbowGumServiceProvider.class, environment.getClassLoader())) + .build(); + // Validate and construct before replacing the working global instance. + var gum = RainbowGum.builder(config).build(); + RainbowGum.set(gum).get(); + if (previous != null) { + previous.close(); + } + } + } + + @Override + public String getPropertyName() { + return "logging.config"; + } + + @Override + public List getLogFileName() { + // Logging is part of the application environment, not a separately discovered file. + return List.of(); + } + + @Override + public void logOff(List loggers, SneakyThrows.Runnable task) { + var names = loggers.stream().map(RainbowGumService::loggerName).distinct().toList(); + synchronized (LOCK) { + for (var name : names) { + MUTED.merge(name, 1, Integer::sum); + LEVELS.put(name, System.Logger.Level.OFF); + } + } + try { + synchronized (LOCK) { + publish(); + } + task.run(); + } finally { + synchronized (LOCK) { + for (var name : names) { + int remaining = MUTED.get(name) - 1; + if (remaining == 0) { + MUTED.remove(name); + LEVELS.remove(name); + } else { + MUTED.put(name, remaining); + } + } + publish(); + } + } + } + + private static String loggerName(String name) { + // SLF4J's root name is ROOT; lowercase root is an ordinary logger name here. + return name.equals("ROOT") ? "" : name; + } + + private static void publish() { + var gum = RainbowGum.getOrNull(); + if (gum != null) { + gum.config().changePublisher().publish(); + } + } +} diff --git a/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/package-info.java b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/package-info.java new file mode 100644 index 0000000000..9f34a531a6 --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/java/io/jooby/rainbowgum/package-info.java @@ -0,0 +1,3 @@ +/** Rainbow Gum logging configured through the Jooby application environment. */ +@org.jspecify.annotations.NullMarked +package io.jooby.rainbowgum; diff --git a/modules/jooby-rainbowgum/src/main/java/module-info.java b/modules/jooby-rainbowgum/src/main/java/module-info.java new file mode 100644 index 0000000000..01727321a6 --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/java/module-info.java @@ -0,0 +1,25 @@ +import io.jooby.LoggingService; +import io.jooby.rainbowgum.RainbowGumBootstrap; +import io.jooby.rainbowgum.RainbowGumService; +import io.jstach.rainbowgum.spi.RainbowGumServiceProvider; + +/** Rainbow Gum logging system. */ +module io.jooby.rainbowgum { + exports io.jooby.rainbowgum; + + requires io.jooby; + requires static org.jspecify; + requires org.slf4j; + requires typesafe.config; + requires io.jstach.rainbowgum; + requires io.jstach.rainbowgum.slf4j; + requires io.jstach.rainbowgum.pattern; + requires io.jstach.rainbowgum.file; + + uses RainbowGumServiceProvider; + + provides LoggingService with + RainbowGumService; + provides RainbowGumServiceProvider with + RainbowGumBootstrap; +} diff --git a/modules/jooby-rainbowgum/src/main/resources/META-INF/services/io.jooby.LoggingService b/modules/jooby-rainbowgum/src/main/resources/META-INF/services/io.jooby.LoggingService new file mode 100644 index 0000000000..db4cf4e74b --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/resources/META-INF/services/io.jooby.LoggingService @@ -0,0 +1 @@ +io.jooby.rainbowgum.RainbowGumService diff --git a/modules/jooby-rainbowgum/src/main/resources/META-INF/services/io.jstach.rainbowgum.spi.RainbowGumServiceProvider b/modules/jooby-rainbowgum/src/main/resources/META-INF/services/io.jstach.rainbowgum.spi.RainbowGumServiceProvider new file mode 100644 index 0000000000..c82eba5097 --- /dev/null +++ b/modules/jooby-rainbowgum/src/main/resources/META-INF/services/io.jstach.rainbowgum.spi.RainbowGumServiceProvider @@ -0,0 +1 @@ +io.jooby.rainbowgum.RainbowGumBootstrap diff --git a/modules/jooby-rainbowgum/src/test/java/io/jooby/rainbowgum/RainbowGumServiceTest.java b/modules/jooby-rainbowgum/src/test/java/io/jooby/rainbowgum/RainbowGumServiceTest.java new file mode 100644 index 0000000000..79046bb28f --- /dev/null +++ b/modules/jooby-rainbowgum/src/test/java/io/jooby/rainbowgum/RainbowGumServiceTest.java @@ -0,0 +1,291 @@ +/* + * Jooby https://jooby.io + * Apache License Version 2.0 https://jooby.io/LICENSE.txt + * Copyright 2014 Edgar Espina + */ +package io.jooby.rainbowgum; + +import static org.junit.jupiter.api.Assertions.*; + +import java.lang.System.Logger.Level; +import java.nio.file.Files; +import java.nio.file.Path; +import java.util.List; +import java.util.Map; +import java.util.ServiceLoader; + +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; +import org.slf4j.LoggerFactory; + +import com.typesafe.config.Config; +import com.typesafe.config.ConfigFactory; +import com.typesafe.config.ConfigValueFactory; +import io.jooby.Environment; +import io.jooby.EnvironmentOptions; +import io.jooby.Jooby; +import io.jooby.LoggingService; +import io.jstach.rainbowgum.LogConfig; +import io.jstach.rainbowgum.LogRouter; +import io.jstach.rainbowgum.RainbowGum; +import io.jstach.rainbowgum.spi.RainbowGumServiceProvider; + +class RainbowGumServiceTest { + @TempDir Path directory; + + @BeforeEach + @AfterEach + void closeLogging() { + var gum = RainbowGum.getOrNull(); + if (gum != null) { + gum.close(); + } + } + + private Environment environment(Config config) { + return new Environment(getClass().getClassLoader(), config, "test"); + } + + private Config configuration(String root) { + return ConfigFactory.parseString( + """ + logging.level.root = %s + logging.level."com.example" = debug + logging.appenders = [capture] + logging.appender.capture.output.uri = "%s" + logging.appender.capture.encoder.uri = pattern + logging.appender.capture.encoder.pattern.pattern = "%%msg%%n" + """ + .formatted(root, directory.resolve("application.log").toUri())); + } + + // Lines, because %n is the platform line separator. + private List output() throws Exception { + return Files.readAllLines(directory.resolve("application.log")); + } + + @Test + void discoversServicesAndReplaysEarlyLoggingIntoConfiguredOutput() throws Exception { + assertInstanceOf( + RainbowGumService.class, + ServiceLoader.load(LoggingService.class).findFirst().orElseThrow()); + var bootstrap = RainbowGum.of(); + assertSame(LogRouter.global(), bootstrap.router()); + var early = LoggerFactory.getLogger("early.logger"); + early.info("before-environment"); + var app = new Jooby().setEnvironment(environment(configuration("debug"))); + assertNotSame(bootstrap, RainbowGum.of()); + assertTrue(early.isDebugEnabled()); + early.debug("after-environment"); + assertEquals(List.of("before-environment", "after-environment"), output()); + assertSame(app.getEnvironment(), app.getEnvironment()); + } + + @Test + void readsQuotedAndUnquotedLoggerNamesAndNativeValues() { + var config = + ConfigFactory.parseString( + """ + logging.level { + root = warn + "com.example" = debug + org.dotted = error + "tc.image@sha256:abc..." = trace + } + logging.groups = [database] + logging.group.database = [org.postgresql] + logging.level.database = info + logging.change.logger."com.example" = [level] + logging.caller.logger."com.example" = true + logging.extra = { "user.name" = alice, retries = 3, active = true, unset = null } + logging.nullValue = null + """); + var properties = new ConfigProperties(() -> config); + assertEquals(List.of("database"), properties.listOrNull("logging.groups")); + assertEquals( + Map.of("user.name", "alice", "retries", "3", "active", "true"), + properties.mapOrNull("logging.extra")); + assertNull(properties.valueOrNull("logging.nullValue")); + var gum = new RainbowGumService(); + gum.initialize(environment(config)); + var levels = RainbowGum.of().config().levelResolver(); + assertEquals(Level.WARNING, levels.resolveLevel("other")); + assertEquals(Level.DEBUG, levels.resolveLevel("com.example.Child")); + assertEquals(Level.ERROR, levels.resolveLevel("org.dotted.Child")); + assertEquals(Level.TRACE, levels.resolveLevel("tc.image@sha256:abc...")); + assertEquals(Level.INFO, levels.resolveLevel("org.postgresql.Driver")); + assertTrue(RainbowGum.of().config().changePublisher().callerInfoEnabled("com.example.Child")); + } + + @Test + void applicationProfilesAndEnvironmentOptionsConfigureLogging() throws Exception { + Files.writeString(directory.resolve("application.conf"), configuration("warn").root().render()); + Files.writeString(directory.resolve("application.test.conf"), "logging.level.root=error"); + var app = new Jooby(); + app.setEnvironmentOptions( + new EnvironmentOptions().setBasedir(directory).setActiveNames("test")); + assertEquals(Level.ERROR, RainbowGum.of().config().levelResolver().resolveLevel("other")); + assertEquals(Level.DEBUG, RainbowGum.of().config().levelResolver().resolveLevel("com.example")); + } + + @Test + void lazyEnvironmentInitializesLoggingOnce() { + var bootstrap = RainbowGum.of(); + var app = new Jooby(); + assertSame(bootstrap, RainbowGum.getOrNull()); + var environment = app.getEnvironment(); + var configured = RainbowGum.of(); + assertNotSame(bootstrap, configured); + assertNotSame(LogRouter.global(), configured.router()); + assertSame(environment, app.getEnvironment()); + assertSame(configured, RainbowGum.of()); + } + + @Test + void publishRereadsLevelsFromTheCurrentEnvironmentConfig() throws Exception { + var env = + environment( + configuration("warn") + .withValue("logging.change.logger", ConfigValueFactory.fromAnyRef("level"))); + new Jooby().setEnvironment(env); + var logger = LoggerFactory.getLogger("reload.logger"); + assertFalse(logger.isDebugEnabled()); + var gum = RainbowGum.of(); + env.setConfig( + env.getConfig().withValue("logging.level.root", ConfigValueFactory.fromAnyRef("debug"))); + gum.config().changePublisher().publish(); + assertSame(gum, RainbowGum.of()); + assertTrue(logger.isDebugEnabled()); + logger.debug("reloaded"); + assertEquals(List.of("reloaded"), output()); + } + + @Test + void laterEnvironmentsKeepTheFirstConfigurationAndExistingLoggersWorking() throws Exception { + var app = new Jooby().setEnvironment(environment(configuration("warn"))); + var first = RainbowGum.of(); + var logger = LoggerFactory.getLogger("replacement.logger"); + app.setEnvironment(environment(configuration("debug"))); + new Jooby().setEnvironment(environment(configuration("debug"))); + assertSame(first, RainbowGum.of()); + assertFalse(logger.isDebugEnabled()); + logger.warn("kept"); + assertEquals(List.of("kept"), output()); + } + + @Test + void logOffRestoresInheritedLevelsEvenWhenNestedTaskThrows() throws Exception { + new Jooby().setEnvironment(environment(configuration("debug"))); + var logger = LoggerFactory.getLogger("io.undertow.Undertow"); + var service = new RainbowGumService(); + assertEquals( + io.jstach.rainbowgum.LogConfig.ChangePublisher.ChangeMode.ON, + RainbowGum.of().config().globals().changeMode()); + assertEquals( + java.util.Set.of(io.jstach.rainbowgum.LogConfig.ChangePublisher.ChangeType.LEVEL), + RainbowGum.of().config().changePublisher().allowedChanges("io.undertow.Undertow")); + assertEquals( + java.util.Set.of(), + RainbowGum.of().config().changePublisher().allowedChanges("com.example.Service")); + assertThrows( + IllegalStateException.class, + () -> + service.logOff( + List.of("io.undertow.Undertow"), + () -> { + assertEquals( + Level.OFF, + RainbowGum.of() + .config() + .levelResolver() + .resolveLevel("io.undertow.Undertow")); + assertFalse(logger.isErrorEnabled()); + service.logOff( + List.of("io.undertow.Undertow"), () -> assertFalse(logger.isErrorEnabled())); + assertFalse(logger.isErrorEnabled()); + logger.error("hidden"); + throw new IllegalStateException("expected"); + })); + assertTrue(logger.isDebugEnabled()); + logger.debug("restored"); + assertEquals(List.of("restored"), output()); + } + + @Test + void mutingLiteralRootDoesNotMuteUnrelatedLoggers() { + new Jooby() + .setEnvironment( + environment( + configuration("debug") + .withValue( + "logging.change.logger.root", ConfigValueFactory.fromAnyRef("level")))); + var root = LoggerFactory.getLogger("root"); + var other = LoggerFactory.getLogger("unrelated.logger"); + new RainbowGumService() + .logOff( + List.of("root"), + () -> { + assertFalse(root.isErrorEnabled()); + assertTrue(other.isDebugEnabled()); + }); + assertTrue(root.isDebugEnabled()); + } + + @Test + void muteSurvivesBootstrapReplacementDuringServerStartup() { + RainbowGum.of(); + var service = new RainbowGumService(); + service.logOff( + List.of("org.xnio.Xnio"), + () -> { + new Jooby().setEnvironment(environment(configuration("debug"))); + assertEquals( + Level.OFF, RainbowGum.of().config().levelResolver().resolveLevel("org.xnio.Xnio")); + assertFalse(LoggerFactory.getLogger("org.xnio.Xnio").isErrorEnabled()); + }); + assertTrue(LoggerFactory.getLogger("org.xnio.Xnio").isDebugEnabled()); + } + + @Test + void invalidConfigurationKeepsQueueingUntilAValidEnvironment() throws Exception { + var bootstrap = RainbowGum.of(); + /* + * An invalid output rather than an invalid encoder: Rainbow Gum 0.16.2 opens the output before + * resolving the encoder and does not close it when that fails, and Windows cannot delete the + * temp directory while the log file is open. + */ + var invalid = + configuration("debug") + .withValue( + "logging.appender.capture.output.uri", + ConfigValueFactory.fromAnyRef("missing-output:///")); + var app = new Jooby(); + assertThrows(RuntimeException.class, () -> app.setEnvironment(environment(invalid))); + assertFalse(Files.exists(directory.resolve("application.log"))); + assertSame(bootstrap, RainbowGum.of()); + LoggerFactory.getLogger("still.queued").info("still-queued"); + app.setEnvironment(environment(configuration("debug"))); + assertNotSame(bootstrap, RainbowGum.of()); + assertEquals(List.of("still-queued"), output()); + } + + @Test + void doesNotReplaceAnExplicitlyInstalledRainbowGum() { + var custom = RainbowGum.builder(LogConfig.builder().build()).set(); + new Jooby().setEnvironment(environment(configuration("debug"))); + assertSame(custom, RainbowGum.of()); + } + + @Test + void doesNotReplaceAnExplicitlyInstalledServiceLoadedRainbowGum() { + var config = + LogConfig.builder() + .serviceLoader(ServiceLoader.load(RainbowGumServiceProvider.class)) + .build(); + var custom = RainbowGum.builder(config).set(); + new Jooby().setEnvironment(environment(configuration("debug"))); + assertSame(custom, RainbowGum.of()); + } +} diff --git a/modules/pom.xml b/modules/pom.xml index a294ea167a..fad3dbe0be 100644 --- a/modules/pom.xml +++ b/modules/pom.xml @@ -20,6 +20,7 @@ jooby-logback jooby-log4j + jooby-rainbowgum jooby-conscrypt diff --git a/pom.xml b/pom.xml index 7c622061a1..2a7a0d8e1d 100644 --- a/pom.xml +++ b/pom.xml @@ -90,6 +90,7 @@ 1.85.1 + 0.16.2 1.6.5 2.26.1 2.0.20 @@ -290,6 +291,11 @@ ${jooby.version} + + io.jooby + jooby-rainbowgum + ${jooby.version} + io.jooby