--- layout: developer-doc title: Logging Service category: infrastructure tags: [infrastructure, logging, debug] order: 6 --- # Logging The Enso project features a centralised logging service to allow for the aggregation of logs from multiple components. This service can be started with one of the main components, allowing other components to connect to it. The service aggregates all logs in one place for easier analysis of the interaction between components. Components can also log to console or files directly without involving the centralized logging service. - [Configuration](#configuration) - [Custom Log Levels](#custom-log-levels) - [Appenders](#appenders) - [Format](#format) - [File](#file-appender) - [Network](#socket-appender) - [Sentry.io](#sentry-appender) - [JVM Architecture](#jvm-architecture) - [SLF4J Interface](#slf4j-interface) - [Setting Up Logging](#setting-up-logging) - [Log Masking](#log-masking) - [Logging in Tests](#logging-in-tests) - [Logging to file](#logging-to-file) ## Configuration 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. 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: - [custom log levels](#custom-log-levels) - [applications' appenders](#appenders) (also known as configuration of log events output target) During component's setup, its `application.conf` config file is parsed. The config's keys and values are validated and, if correct, the parsed representation is available as an instance of `org.enso.logging.config.LoggingServiceConfig` class. The class encapsulates the `logging-service` section of `application.conf` file and is used to programmatically initialize loggers. As per [configuration schema](https://github.com/lightbend/config) any key can be defined with a default value that can be overridden by an environment variable. For example ``` { host = localhost host = $ENSO_HOST } ``` defines a `host` key once, except that `ENSO_HOST` values takes a precedence if it is defined during loading of the config file. ### Custom Log Levels 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 { akka.actor = info akka.event = error akka.io = error slick { jdbc.JdbcBackend.statement = debug "*" = error } } ``` For example, the config above limits all `akka.actor.*` loggers to the info level logging, and `akka.event.*` loggers can emit only the error level messages. Config supports globs (`*`). For example, the config above sets `jdbc.JdbcBackend.statement` SQL statements logging to debug level, and the rest of the slick loggers to error level. Additionally, custom log events can be provided during runtime via system properties, without re-packaging the updated config file. For example ```typescript akka.actor = info; ``` is equivalent to ```typescript -Dakka.actor.Logger.level=info ``` Any custom log level is therefore defined with `-Dx.y.Z.Logger.level` where `x`, `y` and `Z` refer to the package elements and class name, respectively. System properties always have a higher priority over those defined in the `application.conf` file. ### Appenders 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. Currently supported are - console appender - the most basic appender that prints log events to stdout - [file appender](#file-appender) - appender that writes log events to a file, with optional rolling file policy - [socket appender](#socket-appender) - appender that forwards log events to some logging server - [sentry.io appender](#sentry-appender) - appender that forwards log events to a sentry.io service The appenders are defined by the `logging-service.appenders`. Currently only a 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) and the logs output can be overwritten by `ENSO_LOGSERVER_APPENDER` env variable - `ensoup` or `enso` - the default log output can be overwritten by defining the `ENSO_APPENDER_DEFAULT` env variable For example, for the project manager to output to `console` one simply executes ``` ENSO_LOGSERVER_APPENDER=console ./project-manager ``` #### Format The pattern follows the classic's [PatternLayout](https://logback.qos.ch/manual/layouts.html#ClassicPatternLayout) format. Appenders that store/display log events can specify the format of the log message via `pattern` field e.g. ```typescript appenders = [ { name = "console" pattern = "[%level{lowercase=true}] [%d{yyyy-MM-dd'T'HH:mm:ssXXX}] [%logger] %msg%n%nopex" } ... ] ``` 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. File appender directs all log events to a log file: ``` { name = "file" append = immediate-flush = pattern = rolling-policy { max-file-size = max-history = max-total-size = } } ``` Rolling policy is a fully optional property of File Appender that would trigger automatic log rotation. All properties are optional with some reasonable defaults if missing (defined in `org.enso.logging.config.FileAppender` config class). #### Socket Appender Enabled with `ENSO_APPENDER_DEFAULT=socket` environment variable. Configuration ``` { name = "socket" hostname = port = } ``` The two fields can be overridden via environment variables: - `hostname` has an equivalent `$ENSO_LOGSERVER_HOSTNAME` variable - `port` has an equivalent `$ENSO_LOGSERVER_PORT` variable #### Sentry Appender Enabled with `ENSO_APPENDER_DEFAULT=sentry` environment variable. ``` { name = "sentry" dsn = flush-timeout = debug = } ``` Sentry's Appender has a single required field, `dsn`. The `dsn` value can be provided via an environment variable `ENSO_APPENDER_SENTRY_DSN`. `flush-timeout` determines how often logger should send its collected events to sentry.io service. If `debug` value is `true`, logging will print to stdout additional trace information of the logging process itself. ## JVM Architecture Enso's logging makes use of two logging APIs - `java.util.logging` and `org.slf4j`. The former is being used by the Truffle runtime, which itself relies on `jul`, while the latter is used everywhere else. The implementation of the logging is using off the shelf `Logback` implementation with some custom setup methods. The two APIss cooperate by essentially forwarding log messages from the former to the latter. While typically any SLF4J customization would be performed via custom `LoggerFactory` and `Logger` implementation that is returned via a `StaticLoggerBinder` instance, this is not possible for our use-case: - file logging requires Enso-specific directory which is only known during runtime - centralized logging - modifying log levels without recompilation ### SLF4J Interface The user code must not be calling any of the underlying implementations, such as Log4J or Logback, and should only request loggers via factory methods. One can use the `org.slf4j.LoggerFactory` directly to retrieve class-specific logger. For Scala code, it is recommended to use the `com.typesafe.scalalogging.Logger` instead which wraps the SLF4J logger with macros that compute the log messages only if the given logging level is enabled, and allows much prettier initialisation. ```java package foo; import org.slf4j.Logger; import org.slf4j.LoggerFactory; public class Foo { private Logger logger = LoggerFactory.getLogger(Foo.class); public void bar() { logger.info("Hello world!"); } } ``` ### Setting Up Logging The `org.slf4j.Logger` instances have to know where to send log events. This setting is typically performed once, when the service starts, and applies globally during its execution. Currently, it is not possible to dynamically change where log events are being stored. The main (abstract) class used for setting up logging is `org.enso.logging.config.LoggerSetup`. An instance of that class can be retrieved with the thread-safe `org.enso.logging.config.LoggerSetup.get` factory method. `org.enso.logging.config.LoggerSetup` provides a number of `setupXYZAppender` methods that will direct loggers to send log events to an `XYZ` appender. Setting a specific hard-coded appender programmatically should however be avoided by the users. Instead, one should invoke one of the overloaded `setup` variants that initialize loggers based on the provided `logging-service` configuration. ```java package foo; import org.enso.logging.config.LoggerSetup; import org.slf4j.event.Level; public class MyService { private Logger logger = LoggerFactory.getLogger(Foo.class); ... public void start(Level logLevel) { LoggerSetup.get().setup(logLevel); logger.info("My service is starting..."); ... } ... } ``` `org.enso.logging.service.LoggingSetupHelper` class was introduced to help with the most common use cases - establishing a file-based logging in the Enso's dedicated directories or connecting to an existing logging server once it starts accepting connections. That is why services don't call `LoggerSetup` directly but instead provide a service-specific implementation of `org.enso.logging.service.LoggingSetupHelper`. `LoggingSetupHelper` and `LoggerSetup` provide `teardown` methods to properly dispose of log events. ### Log Masking Logs should not contain personally identifiable information (PII). The following is considered PII: - User code - Values of executed expressions - Values of user environment variables. Although variable names are not considered PII and can be logged. - File paths inside the user project directory. System and distribution paths and a path to the user project can be logged. Project logging library implements masking of PII. To utilize it 1. Logged object should implement an interface that defines custom log-string representation of this object 2. The logging should be performed by supplying a template string with `{}` placeholders, and the arguments ```scala log.debug("Created {} at [{}].", obj, path) ``` String interpolation in log statements `s"Created $obj"` should be avoided because it uses default `toString` implementation and can leak critical information even if the object implements custom interface for masked logging. ### Logging in Tests The Logging Service provides a helper function `TestLogger.gatherLogs` that will execute the closure and collect all logs reported in the specified class. That 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 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 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. # 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.