From ae905a8e0c357c2bf6e45661b48bd3fa8f05a43f Mon Sep 17 00:00:00 2001 From: Hubert Plociniczak Date: Fri, 1 Nov 2024 21:46:09 +0100 Subject: [PATCH 1/4] Fix logging in CLI Previously, unless `--logger-connect` was used, CLI would always fallback to console logging. In addition it would be misconfigured if `application.conf` was provided with logging configuration. This change makes sure that CLI uses the same logging infrastructure as the rest of the system. As a result, CLI will now by default not only log to the console and respect the provided configuration but also log to the file system. --- build.sbt | 1 + .../src/main/java/org/enso/runner/Main.java | 10 +++--- .../org/enso/runner/RunnerEnvironment.java | 5 +++ .../java/org/enso/runner/RunnerLogging.java | 32 ++++++++++++++--- .../src/main/resources/application.conf | 34 +++++++++++++++++++ 5 files changed, 74 insertions(+), 8 deletions(-) create mode 100644 engine/runner/src/main/java/org/enso/runner/RunnerEnvironment.java create mode 100644 engine/runner/src/main/resources/application.conf diff --git a/build.sbt b/build.sbt index ded00875bb31..30305e2c09d5 100644 --- a/build.sbt +++ b/build.sbt @@ -3683,6 +3683,7 @@ lazy val `engine-runner` = project .dependsOn(cli) .dependsOn(`profiling-utils`) .dependsOn(`library-manager`) + .dependsOn(`distribution-manager`) .dependsOn(`edition-updater`) .dependsOn(`runtime-parser`) .dependsOn(`logging-service`) diff --git a/engine/runner/src/main/java/org/enso/runner/Main.java b/engine/runner/src/main/java/org/enso/runner/Main.java index 46cbcc39583c..fd99d8486c83 100644 --- a/engine/runner/src/main/java/org/enso/runner/Main.java +++ b/engine/runner/src/main/java/org/enso/runner/Main.java @@ -101,6 +101,8 @@ public class Main { private static final String WARNINGS_LIMIT = "warnings-limit"; private static final String SYSTEM_PROPERTY = "vm.D"; + private static final String DEFAULT_MAIN_METHOD_NAME = "main"; + private static final org.slf4j.Logger logger = LoggerFactory.getLogger(Main.class); Main() {} @@ -854,20 +856,20 @@ private void runPackage( java.util.List additionalArgs) { var topScope = context.getTopScope(); var mainModule = topScope.getModule(mainModuleName); - runMain(mainModule, projectPath, additionalArgs, "main"); + runMain(mainModule, projectPath, additionalArgs, DEFAULT_MAIN_METHOD_NAME); } private void runSingleFile( PolyglotContext context, File file, java.util.List additionalArgs) { var mainModule = context.evalModule(file); - runMain(mainModule, file, additionalArgs, "main"); + runMain(mainModule, file, additionalArgs, DEFAULT_MAIN_METHOD_NAME); } private void runMain( Module mainModule, File rootPkgPath, java.util.List additionalArgs, - String mainMethodName // = "main" + String mainMethodName // = DEFAULT_MAIN_METHOD_NAME ) { try { var mainType = mainModule.getAssociatedType(); @@ -881,7 +883,7 @@ private void runMain( throw exitFail(); } var main = mainFun.get(); - if (!"main".equals(mainMethodName)) { + if (!DEFAULT_MAIN_METHOD_NAME.equals(mainMethodName)) { main.execute(join(mainType, nil())); } else { // Opportunistically parse arguments and convert to ints. diff --git a/engine/runner/src/main/java/org/enso/runner/RunnerEnvironment.java b/engine/runner/src/main/java/org/enso/runner/RunnerEnvironment.java new file mode 100644 index 000000000000..8136bd50e49d --- /dev/null +++ b/engine/runner/src/main/java/org/enso/runner/RunnerEnvironment.java @@ -0,0 +1,5 @@ +package org.enso.runner; + +import org.enso.distribution.Environment; + +public class RunnerEnvironment implements Environment {} diff --git a/engine/runner/src/main/java/org/enso/runner/RunnerLogging.java b/engine/runner/src/main/java/org/enso/runner/RunnerLogging.java index 24b1169f7f90..da8f93560e61 100644 --- a/engine/runner/src/main/java/org/enso/runner/RunnerLogging.java +++ b/engine/runner/src/main/java/org/enso/runner/RunnerLogging.java @@ -4,6 +4,7 @@ import java.util.concurrent.ExecutionException; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; +import org.enso.distribution.DistributionManager; import org.enso.logger.masking.Masking; import org.enso.logging.config.LoggerSetup; import org.slf4j.Logger; @@ -14,6 +15,8 @@ final class RunnerLogging { private RunnerLogging() {} private static final Logger logger = LoggerFactory.getLogger(RunnerLogging.class); + private static final DistributionManager distributionManager = + new DistributionManager(new RunnerEnvironment()); /** * Sets up the runner's logging service. @@ -49,7 +52,6 @@ private static void setupImpl( var success = future.get(); if (success) { logger.trace("Connected to logging service at [{}]", connectionUri); - return; } else { throw new RuntimeException("Failed to connect to logging service"); } @@ -57,9 +59,31 @@ private static void setupImpl( System.err.println( "Failed to connect to the logging service server, " + "falling back to local logging."); } - } - if (!setupConsoleAppender(logLevel, executorService, loggerSetup)) { - System.err.println("Failed to initialize logging infrastructure"); + } else { + var future = + executorService.submit( + () -> + loggerSetup.setup( + logLevel, + distributionManager.detectPaths().logs(), + "enso-cli", + loggerSetup.getConfig())); + try { + var success = future.get(); + if (!success) { + System.err.println("Failed to initialize logging from the configuration"); + } else { + return; + } + } catch (InterruptedException | ExecutionException e) { + System.err.println( + "Failed to initialize logging from the configuration due to internal exception: " + + e.getMessage()); + } + System.err.println("Attempting to fallback logging to console only"); + if (!setupConsoleAppender(logLevel, executorService, loggerSetup)) { + System.err.println("Failed to initialize logging infrastructure"); + } } } diff --git a/engine/runner/src/main/resources/application.conf b/engine/runner/src/main/resources/application.conf new file mode 100644 index 000000000000..0dc97e0a7ab9 --- /dev/null +++ b/engine/runner/src/main/resources/application.conf @@ -0,0 +1,34 @@ +## Launcher's application.conf + +akka { + loggers = ["akka.event.slf4j.Slf4jLogger"] + logging-filter = "akka.event.slf4j.Slf4jLoggingFilter" + stdout-loglevel = "ERROR" +} + +logging-service { + logger { + akka.actor = info + akka.event = error + akka.io = error + akka.stream = error + } + appenders = [ + { + name = "file", + pattern = "[%level{lowercase=true}] [%d{yyyy-MM-dd'T'HH:mm:ssXXX}] [%logger] %msg%n" + }, + { + name = "console" + pattern = "[%level{lowercase=true}] [%d{yyyy-MM-dd'T'HH:mm:ssXXX}] [%logger] %msg%n%nopex" + } + ] + default-appender = console + default-appender = ${?ENSO_APPENDER_DEFAULT} + log-to-file { + enable = true + enable = ${?ENSO_LOG_TO_FILE} + log-level = trace + log-level = ${?ENSO_LOG_TO_FILE_LOG_LEVEL} + } +} From 03fac31d6025ca7e3e39117cb23f72f9a48f12fb Mon Sep 17 00:00:00 2001 From: Hubert Plociniczak Date: Mon, 4 Nov 2024 17:20:28 +0100 Subject: [PATCH 2/4] Update docs --- docs/infrastructure/logging.md | 58 +++++++++++++++++++++++----------- 1 file changed, 39 insertions(+), 19 deletions(-) diff --git a/docs/infrastructure/logging.md b/docs/infrastructure/logging.md index ec993c963b7d..d1d2bcb9b718 100644 --- a/docs/infrastructure/logging.md +++ b/docs/infrastructure/logging.md @@ -35,13 +35,17 @@ involving the centralized logging service. ## Configuration -The logging settings should be placed under the `logging-service` key of the -`application.conf` config. Each of the main components can customize format and -output target via section in `application.conf` configuration file. The +All logging settings are configured via the `logging-service` section of the +`application.conf` config file. Each of the main components can customize format +and output target via section in `application.conf` configuration file. The configuration is using HOCON-style, as defined by [lightbend/config](https://github.com/lightbend/config). Individual values accepted in the config are inspired by SLF4J's properties, formatting and -implementations. +implementations. Currently 3 components define logging configuration: + +- [`project-manager`](../../lib/scala/project-manager/src/main/resources/application.conf) +- [`launcher`](../../engine/launcher/src/main/resources/application.conf) +- [CLI](../../engine/runner/src/main/resources/application.conf) The configuration has two main sections: @@ -57,8 +61,8 @@ representation is available as an instance of programmatically initialize loggers. As per [configuration schema](https://github.com/lightbend/config) any key can -have a default value that can be overridden by an environment variable. For -example +be defined with a default value that can be overridden by an environment +variable. For example ``` { @@ -72,10 +76,18 @@ it is defined during loading of the config file. ### Custom Log Levels -The `logging-service.logger` configuration provides an ability to override the -default application log level for particular loggers. In the `logger` subconfig -the key specifies the logger name (or it's prefix) and the value specifies the -log level for that logger. +Possible log level values are (in the order of precedence): + +- `error` +- `warn` +- `info` +- `debug` +- `trace` + +The `logging-service.logger` configuration section provides an ability to +override the default application log level for particular loggers. In the +`logger` subconfig the key specifies the logger name (or it's prefix) and the +value specifies the log level for that logger. ``` logging-service.logger { @@ -117,7 +129,7 @@ properties always have a higher priority over those defined in the ### Appenders -Log output target is also configured in the `application.conf` files in the +Log output target is configured in the `application.conf` files in the "appenders" section ("appender" is equivalent to `java.util.logging.Handler` semantics). Each appender section can provide further required and optional key/value pairs, to better customize the log target output. @@ -133,8 +145,10 @@ Currently supported are a sentry.io service The appenders are defined by the `logging-service.appenders`. Currently only a -single appender can be selected at a time. The selection may also be done via an -environmental variable but it depends on which component we are executing. +single appender can be selected at a time, although additional +[logging to file](#logging-to-file) is supported. The selection may also be done +via an environmental variable but it depends on which component we are +executing. - `project-manager` - project manager by default starts a centralized logging server that collects logs (as defined in `logging-service.server` config key) @@ -352,18 +366,24 @@ way it can verify that all logs are being reported within the provided code. ### Logging to file By default Enso will attempt to persist (verbose) logs into a designated log -file. This means that even though a user might be shown `WARNING` level logs in -the console, logs with up to `DEBUG` level will be dumped into the log file. A -user can disable this parallel logging to a file by setting the environment -variable: +file. This means that even though a user might be shown only `WARNING` level +logs in the console, logs with up to `DEBUG` or `TRACE` level, including full +stacktraces, can be dumped into the log file. A user can disable this parallel +logging to a file by setting the environment variable: ``` ENSO_LOG_TO_FILE=false project-manager ... ``` -Users can also modify the default maximal log level, `DEBUG`, used when logging -to a log file by setting the environment variable: +Users can fully control the maximal log level used when logging to a log file by +setting the environment variable: ``` ENSO_LOG_TO_FILE_LOG_LEVEL=trace project-manager ... ``` + +For example, in the above example `project-manager` will log events of up-to +`trace` in the log file. + +**Note** Logging to a file requires presence of the `file` +[appender](#file-appender) in the `logging-service.appenders` section. From 7434319b1364334385055859f955782c7d673153 Mon Sep 17 00:00:00 2001 From: Hubert Plociniczak Date: Mon, 4 Nov 2024 17:22:00 +0100 Subject: [PATCH 3/4] c&p error --- engine/runner/src/main/resources/application.conf | 8 +------- 1 file changed, 1 insertion(+), 7 deletions(-) diff --git a/engine/runner/src/main/resources/application.conf b/engine/runner/src/main/resources/application.conf index 0dc97e0a7ab9..33d055c6df79 100644 --- a/engine/runner/src/main/resources/application.conf +++ b/engine/runner/src/main/resources/application.conf @@ -1,10 +1,4 @@ -## Launcher's application.conf - -akka { - loggers = ["akka.event.slf4j.Slf4jLogger"] - logging-filter = "akka.event.slf4j.Slf4jLoggingFilter" - stdout-loglevel = "ERROR" -} +# CLI's application.conf logging-service { logger { From 8a1e716e220a291e7b5e1b75f3974fa7da9916e5 Mon Sep 17 00:00:00 2001 From: Hubert Plociniczak Date: Tue, 5 Nov 2024 13:40:30 +0100 Subject: [PATCH 4/4] More examples --- docs/infrastructure/logging.md | 70 ++++++++++++++++++++++++++++++++++ 1 file changed, 70 insertions(+) diff --git a/docs/infrastructure/logging.md b/docs/infrastructure/logging.md index d1d2bcb9b718..24509714b5f8 100644 --- a/docs/infrastructure/logging.md +++ b/docs/infrastructure/logging.md @@ -183,6 +183,17 @@ message via `pattern` field e.g. ] ``` +In the above example `%logger` format will be substituted with a class name for +which the logger was created with. + +By default, console pattern includes `%nopex` formatter which means that any +stacktrace attached to the log message will always be ignored. By default other +appenders do not have such formatting key. This means that if an exception is +included in the logged messaged, a full stacktrace will be attached, if present. + +For a full list of formatting keys please refer to the concrete implementation's +[manual](https://logback.qos.ch/manual/layouts.html#ClassicPatternLayout). + #### File Appender Enabled with `ENSO_APPENDER_DEFAULT=file` environment variable. @@ -387,3 +398,62 @@ For example, in the above example `project-manager` will log events of up-to **Note** Logging to a file requires presence of the `file` [appender](#file-appender) in the `logging-service.appenders` section. + +# How to use logging + +Logging infrastructure uses a popular SLF4J interface which most of developers +should be familiar with. In this section we include a only small number of +examples, full user manual is available at SLF4J's +[website](https://www.slf4j.org/manual.html). + +## Log a simple INFO message + +``` +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class HelloWorld { + + public static void main(String[] args) { + Logger logger = LoggerFactory.getLogger(HelloWorld.class); + logger.info("Hello World"); + } +} +``` + +## Log a simple INFO message only if TRACE is enabled + +``` +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class HelloWorld { + + public static void main(String[] args) { + Logger logger = LoggerFactory.getLogger(HelloWorld.class); + if (logger.isTraceEnabled()) { + logger.info("Hello World"); + } + } +} +``` + +## Log an exception + +``` +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +public class HelloWorld { + + public static void main(String[] args) { + Logger logger = LoggerFactory.getLogger(HelloWorld.class); + Throwable ex = new RuntimeException("foo") + logger.error("Hello World", ex); + } +} +``` + +Note that in order for the full stacktrace to be printed, pattern in the desired +appender must not contain `%nopex` formatting key. See [formatting](#format) for +details.