Managing logs

Log messages in IG and third-party dependencies are recorded using the Logback implementation of the Simple Logging Facade for Java (SLF4J) API. The following log levels are supported: TRACE, DEBUG, INFO, WARN, ERROR, ALL, and OFF. For a full description of the options for logging, see the Logback website.

Default logging behavior

By default, log messages are recorded with the following configuration:

When IG starts, log messages for IG and third-party dependencies, such as the ForgeRock Common Audit framework, are displayed on the console and written to $HOME/.openig/logs/route-system.log, where $HOME/.openig is the instance directory.
When a route is accessed, log messages for requests and responses passing through the route are written to a log file in $HOME/.openig/logs, and named by the route name or filename, where $HOME/.openig is the instance directory.

For more information, see Capturing Log Messages for Routes and CaptureDecorator.
By default, log messages with the level INFO or higher are recorded, with the titles and the top line of the stack trace. Messages on the console are highlighted with a color related to their log level.

The content and format of logs in IG is defined by the reference logback.xml delivered with IG. This file defines the following configuration items for logs:

A root logger to set the overall log level, and to write all log messages to the SIFT and STDOUT appenders.
A STDOUT appender to define the format of log messages on the console.
A SIFT appender to separate log messages according to the key routeId, to define when log files are rolled, and to define the format of log messages in the file.
An exception logger, called LogAttachedExceptionFilter, to write log messages for exceptions attached to responses.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

  <!--
    Prevent log flow attacks, by limiting repeated log messages.

    Configuration properties:
     * AllowedRepetitions (int): Threshold above which repeated messages are no longer logged.
     * CacheSize (int): When CacheSize is reached, remove the oldest entry.
  -->
  <!--<turboFilter class="ch.qos.logback.classic.turbo.DuplicateMessageFilter" />-->

  <!-- Allow configuration of JUL loggers within this file, without performance impact -->
  <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%nopex[%thread] %highlight(%-5level) %boldWhite(%logger{35}) @%mdc{routeId:-system} - %replace(%message){'([\r\n])(.)', '$1[CONTINUED]$2'}%n%highlight(%replace(%rootException{short}){'(^|[\r\n])(.)', '$1[CONTINUED]$2'})</pattern>
    </encoder>
  </appender>

  <appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
    <discriminator>
      <key>routeId</key>
      <defaultValue>system</defaultValue>
    </discriminator>
    <sift>
      <!-- Create a separate log file for each <key> -->
      <appender name="FILE-${routeId}" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${instance.dir}/logs/route-${routeId}.log</file>

        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
          <!-- Rotate files daily -->
          <fileNamePattern>${instance.dir}/logs/route-${routeId}-%d{yyyy-MM-dd}.%i.log</fileNamePattern>

          <!-- each file should be at most 100MB, keep 30 days worth of history, but at most 3GB -->
          <maxFileSize>100MB</maxFileSize>
          <maxHistory>30</maxHistory>
          <totalSizeCap>3GB</totalSizeCap>
        </rollingPolicy>

        <encoder>
          <pattern>%nopex%date{"yyyy-MM-dd'T'HH:mm:ss,SSSXXX", UTC} | %-5level | %thread | %logger{20} | @%mdc{routeId:-system} | %replace(%message%n%xException){'([\r\n])(.)', '$1[CONTINUED]$2'}</pattern>
        </encoder>
      </appender>
    </sift>
  </appender>

  <!-- Disable logs of exceptions attached to responses by defining 'level' to OFF -->
  <logger name="org.forgerock.openig.filter.LogAttachedExceptionFilter" level="INHERITED" />

  <root level="${ROOT_LOG_LEVEL:-INFO}">
    <appender-ref ref="SIFT" />
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

Using a custom Logback file

To change the logging behavior, create a new logback file at $HOME/.openig/config/logback.xml, and restart IG. The custom Logback file overrides the default configuration.

To take into account edits to logback.xml, stop and restart IG, or edit the configuration parameter to add a scan and an interval:

<configuration scan="true" scanPeriod="5 seconds">

The logback.xml file is scanned after both of the following criteria are met:

The specified number of logging operations have occurred, where the default is 16.
The scanPeriod has elapsed.

If the custom logback.xml contains errors, messages like these are displayed on the console but log messages are not recorded:

14:38:59,667 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@20:72 …
14:38:59,690 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction …

Changing the global log level

The global log level is set by default to INFO by the following line of the default logback.xml:

<root level="${ROOT_LOG_LEVEL:-INFO}">

The log level set in logback.xml supercedes the log level set by environment variables. When the global log level is not set in logback.xml, and IG is running in standalone mode, set the global log level as follows:

To persist the log level for all future IG instances:
- Add an environment variable in $HOME/.openig/bin/env.sh, where $HOME/.openig is the instance directory:
  export ROOT_LOG_LEVEL=DEBUG
- Alternatively, add a system property in $HOME/.openig/bin/env.sh, where $HOME/.openig is the instance directory:
  export JAVA_OPTS="-DROOT_LOG_LEVEL=DEBUG"
  If both an environment variable and system property is set, the system property takes precedence.

To persist the log level for IG instances launched from the same shell, add an environment variable in the shell before you start IG:

Linux
Windows

$ export ROOT_LOG_LEVEL=DEBUG
$ /path/to/identity-gateway/bin/start.sh $HOME/.openig

C:\set ROOT_LOG_LEVEL=DEBUG
C:\path\to\identity-gateway\bin\start.bat %appdata%\OpenIG

To persist the log level for a single IG instance:

Linux
Windows

$ export ROOT_LOG_LEVEL=DEBUG /path/to/identity-gateway/bin/start.sh $HOME/.openig

C:\set ROOT_LOG_LEVEL=DEBUG
C:\path\to\identity-gateway\bin\start.bat %appdata%\OpenIG

When IG is running in web container mode, add an environment variable on the command line when you start the web container:

Linux
Windows

$ export ROOT_LOG_LEVEL=DEBUG

C:\set ROOT_LOG_LEVEL=DEBUG

Changing the log level for different object types

To change the log level for a single object type without changing it for the rest of the configuration, edit logback.xml to add a logger defined by the fully qualified class name or package name of the object, and set its log level.

The following line in logback.xml sets the ClientHandler log level to ERROR, but does not change the log level of other classes or packages:

<logger name="org.forgerock.openig.handler.ClientHandler" level="ERROR" />

To facilitate debugging, in logback.xml add loggers defined by the fully qualified package name or class name of the object. For example, add loggers for the following areas:

Expression resolution

org.forgerock.openig.el org.forgerock.openig.resolver

WebSocket notifications

org.forgerock.openig.tools.notifications.ws

Session management with JwtSession

org.forgerock.openig.jwt

OAuth 2.0 and OpenID Connect and token resolution and validation

org.forgerock.openig.filter.oauth2

AM policies, SSO, CDSSO, and user profiles

org.forgerock.openig.openam org.forgerock.openig.tools

SAML

org.forgerock.openig.handler.saml

UMA

org.forgerock.openig.uma

WebSocket tunnelling

org.forgerock.openig.websocket

Secret resolution

org.forgerock.secrets.propertyresolver org.forgerock.secrets.jwkset org.forgerock.secrets.keystore org.forgerock.secrets.oauth2 org.forgerock.openig.secrets.Base64EncodedSecretStore

AllowOnlyFilter

org.forgerock.openig.filter.allow.AllowOnlyFilter.<filter_name>

Condition of a route

org.forgerock.openig.handler.router.RouterHandler

Header field size

io.vertx.core.http.impl.HttpServerImpl

Change the character set and format of log messages

By default, logs use the system default character set where IG is running. To use a different character set, or change the pattern of the log messages, edit logback.xml to change the encoder part of the SIFT appender.

The following lines add the date to log messages, and change the character set:

<encoder>
   <pattern>%d{yyyyMMdd-HH:mm:ss} | %-5level | %thread | %logger{20} | %message%n%xException</pattern>
   <charset>UTF-8</charset>
</encoder>

For more information about what information you can include in the logs, and its format, see PatternLayoutEncoder and Layouts in the Logback documentation.

Logging in scripts

The logger object provides access to a unique SLF4J logger instance for scripts. Events are logged as defined in by a dedicated logger in logback.xml, and are included in the logs with the name of with the scriptable object.

To log events for scripts:

Add logger objects to the script to enable logging at different levels. For example, add some of the following logger objects:
```
logger.error("ERROR")
logger.warn("WARN")
logger.info("INFO")
logger.debug("DEBUG")
logger.trace("TRACE")
```
Add a logger to logback.xml to reference the scriptable object and set the log level. The logger is defined by the type and name of the scriptable object that references the script, as follows:
- ScriptableFilter: org.forgerock.openig.filter.ScriptableFilter.filter_name
- ScriptableHandler: org.forgerock.openig.handler.ScriptableHandler.handler_name
- ScriptableThrottlingPolicy: org.forgerock.openig.filter.throttling.ScriptableThrottlingPolicy.throttling_policy_name
- ScriptableAccessTokenResolver: org.forgerock.openig.filter.oauth2.ScriptableAccessTokenResolver.access_token_resolver_name

For example, the following logger logs trace-level messages for a ScriptableFilter named cors_filter:

<logger name="org.forgerock.openig.filter.ScriptableFilter.cors_filter" level="TRACE" />

The resulting messages in the logs contain the name of the scriptable object:

14:54:38:307 | TRACE | http-nio-8080-exec-6 | o.f.o.f.S.cors_filter | TRACE

Logging the BaseUriDecorator

During setup and configuration, it can be helpful to display log messages from the BaseUriDecorator. To record a log message each time a request URI is rebased , edit logback.xml to add a logger defined by the fully qualified class name of the BaseUriDecorator appended by the name of the baseURI decorator:

<logger name="org.forgerock.openig.decoration.baseuri.BaseUriDecorator.baseURI" level="TRACE" />

Each time a request URI is rebased, a log message similar to this is created:

12:27:40| TRACE | http-nio-8080-exec-3 | o.f.o.d.b.B.b.{Router}/handler| Rebasing request to http://app.example.com:8081

Switching off exception logging

To stop recording log messages for exceptions, edit logback.xml to set the level to OFF:

<logger name="org.forgerock.openig.filter.LogAttachedExceptionFilter" level="OFF" />

Capturing the context or entity of messages for routes

To capture the context or entity of inbound and outbound messages for a route, or for an individual handler or filter in the route, configure a CaptureDecorator. Captured information is written to SLF4J logs.

During debugging, consider using a CaptureDecorator to capture the entity and context of requests and responses. However, increased logging consumes resources, such as disk space, and can cause performance issues. In production, reduce logging by disabling the CaptureDecorator properties captureEntity and captureContext, or setting maxEntityLength.

For more information about the decorator configuration, see CaptureDecorator.

Studio provides an easy way to capture messages while developing your configuration. The following image illustrates the capture points where you can log messages on a route:

Capture points for requests and responses passing through a route.

Figure 1. Capturing log messages for routes

Capture messages on a route in Studio

In Studio, select ROUTES, and then select a route with the icon.
On the left side of the screen, select Capture, and then select capture options. You can capture the body and context of messages passing to and from the user agent, the protected application, and the ForgeRock Identity Platform.
Select Deploy to push the route to the IG configuration.

You can check the $HOME/.openig/config/routes folder to see that the route is there.
Access the route, and then check $HOME/.openig/logs for a log file named by the route, where $HOME/.openig is the instance directory. The log file should contain the messages defined by your capture configuration.

Limit repetitive log messages

To keep log files clean and readable, and to prevent log flow attacks, limit the number of repeat log messages. Add a custom logback.xml with a DuplicateMessageFilter. This filter detects duplicate messages, and after the specified number of repetitions, drops repeated messages.

The following example allows 5 repetitions of a log message, and holds the last 10 repeated messages in the cache:

<turboFilter class="ch.qos.logback.classic.turbo.DuplicateMessageFilter" allowedRepetitions="5" CacheSize="10" />

The DuplicateMessageFilter has the following limitations:

Filters out all duplicate messages. It does not filter per logger, or logger instance, or logger name.
Detects repetition of raw messages, meaning that the following example messages are considered as repetition:
```
logger.debug("Hello {}.", name0);
logger.debug("Hello {}.", name1);
```
Does not limit the lifespan of the cache. After the specified number of repetitions is reached, the repeated log messages never appear again, even if they are frequently hit.

Identity Gateway 7.2