Java Agents 2023.11.2

Logging

Logs in Java Agent and third-party dependencies are recorded using the Logback implementation of the Simple Logging Facade for Java (SLF4J) API.

By default, the logback configuration is stored in /path/to/java_agents/agent_type/Agent_n/config/agent-logback.xml. For information about how to change the location, refer to Agent configuration.

The agent supports the following log levels:

  • TRACE

  • INFO

  • WARN

  • ERROR

  • ON (deprecated, this setting uses the TRACE log level)

  • OFF (deprecated, this setting uses the ERROR log level)

For a full description of logging options, refer to the Logback website.

Setting the log level

The agent maintains the last log level it reads from either agent-logback.xml or Agent Debug Level.

To debug code during the property-reading phase of startup, set the log level in agent-logback.xml to TRACE.

Remote configuration mode

In remote configuration mode, the agent sets the log level as follows:

  • At start up, the agent reads agent-logback.xml, and uses the configured log level.

  • When the agent receives the first request, it reads AgentBootstrap.properties. If org.forgerock.agents.debug.level specifies a different log level, the agent changes the log level.

  • The agent then reads the AM properties. If Agent Debug Level specifies different log level, the agent changes the log level.

  • While the agent is running, if either of the following events occurs the agent changes the log level to the value configured by the event:

Local configuration mode

In local configuration mode, the agent sets the log level as follows:

  • At start up, the agent reads agent-logback.xml, and uses the configured log level.

  • When the agent receives the first request, it reads AgentBootstrap.properties and then AgentConfiguration.properties.

    • If either file specifies a log level in org.forgerock.agents.debug.level, the agent uses that log level.

    • If both files specify a log level, the agent uses the last log level it reads, from AgentConfiguration.properties.

  • While the agent is running, if either of the following events occurs the agent changes the log level to the value configured by the event:

Default logging in agent-logback.xml

By default, agent-logback.xml is configured as follows:

  • When the agent starts, log messages are recorded for the agent.

  • Log messages are written to a text file in /path/to/java_agents/agent_type/Agent_n/logs/debug, where /path/to/java_agents/agent_type/Agent_n is the installation directory.

  • The log level is ERROR.

  • Logs are rolled over once a day, or more frequently if the file reaches 100 MB.

All aspects of the logs are defined by the following reference agent-logback.xml deployed by the agent installer:

<configuration debug="true" scan="true" scanPeriod="60 seconds">
    <appender name="ROLLING" class="org.forgerock.agents.shaded.ch.qos.logback.core.rolling.RollingFileAppender">

        <file>/full/path/to/logs/debug/directory/log.txt</file>
        <rollingPolicy class="org.forgerock.agents.shaded.ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">

            <!-- rollover daily -->
            <fileNamePattern>log-%d{yyyy-MM-dd}.%i.txt</fileNamePattern>

            <!-- each file should be at most 100MB, keep 30 days worth of history, but at most 10GB -->
            <maxFileSize>100MB</maxFileSize>
            <maxHistory>30</maxHistory>
            <totalSizeCap>10GB</totalSizeCap>
        </rollingPolicy>
        <encoder>
            <pattern>%level %msg%n</pattern>
        </encoder>
    </appender>

    <root level="ERROR">
        <appender-ref ref="ROLLING" />
    </root>
</configuration>

Changing agent-logback.xml

To change the logging behavior, update agent-logback.xml.

To take the change into account, stop and restart the agent, or include a scan and an interval configuration in agent-logback.xml. In the following example, agent-logback.xml is scanned every 60 seconds:

<configuration scan="true" scanPeriod="60 seconds" ... >
  ...

For a full description of the options for logging, refer to the Logback website.

Use shaded Logback classnames, to ensure that the agent uses a unique classname compared to other deployed filters and web applications in the container. For example, use

org.forgerock.agents.shaded.ch.qos.logback.core.rolling.RollingFileAppender

instead of

ch.qos.logback.core.rolling.RollingFileAppender

Managing errors in agent-logback.xml

If agent-logback.xml is removed and not replaced, or if a replacement agent-logback.xml contains errors, logs are written to the standard output for the container. For example, Tomcat logs are written to catalina.out.

To log an error when agent-logback.xml fails to load, include a debug configuration:

<configuration debug="true" ... >
  ...

When agent-logback.xml contains errors, messages like these written to the standard output for the container.

ERROR in ch.qos.logback.core.joran.spi.Interpreter@20:72 …​
ERROR in ch.qos.logback.core.joran.action.AppenderRefAction …​

Changing the log level in agent-logback.xml

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

<root level="ERROR">

To change the global log level, configure the same line with another log level and take the changed file into account, as described in Changing agent-logback.xml.

To change the log level for a single object type without changing it for the rest of the configuration, add a logger defined by the shaded classname of the object, and set its log level.

The following line in agent-logback.xml changes the log level for evaluating not-enforced rules, but does not change the log level of other classes or packages:

<logger name="org.forgerock.agents.shaded.com.sun.identity.agents.common.NotEnforcedRuleHelper" level="TRACE" />

Changing the character set and format of log messages

By default, logs use the system default character set where the agent is running. To use a different character set, or change the pattern of the log messages, edit agent-logback.xml to change the encoder configuration.

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>

Limiting repeated log messages

To keep log files clean and readable, and to prevent log overflow attacks, limit the number of repeat log messages. Add a custom agent-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, holds the following 10 repeated messages in the cache, and then discards subsequent repeated messages:

<turboFilter class="org.forgerock.agents.shaded.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 some non-identical messages are considered as repetition.

    For example, when the agent is running at TRACE level, the following message is written to the logs every 20 seconds when there is no other activity over the Websocket:

    TRACE 08:22:00 (20) Sending ping to check connection is still alive

    This message is produced by the logging statement:

    logger.trace("{} ({}) Sending ping to check connection is still alive", timeStamp, lastSent.getSeconds());

    Because the message text {} ({}) Sending ping to check connection is still alive is always the same, it is considered as repeat. Only the first 5 repeats are logged.

  • 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.

Changing the log level in the AM admin UI

To change the log level in the AM admin UI

  1. In the AM admin UI, go to Realms > realm name > Applications > Agents > Java, and select your Java Agent.

  2. On the Global tab, select Agent Debug Level, and select a level.

Alternatively, set Agent Debug Level as a custom property.