Debug Techniques - Configuring the application logger

4747
0
06-14-2019 05:45 PM
RJSunderman
Esri Regular Contributor
4 0 4,747

This blog is one in a series of blogs discussing debugging techniques you can use when working to identify the root cause of an issue with a GeoEvent Server deployment or configuration. Click any link in the quick list below to jump to another blog in the series.

In this blog I will discuss GeoEvent Manager's user interface for viewing logged messages, the location of the actual log file on disk, and how logging can be configured -- specifically how to control the size of the log file and its rollover properties.

The GeoEvent Manager Logging Interface

ArcGIS GeoEvent Server uses Apache Karaf, a lightweight flexible container to support its Java runtime environment. A powerful logging system, based on OPS4j Pax Logging, is included with Apache Karaf.

The GeoEvent Manager web application includes a simple user-interface for the ops4j logging system. You can use this interface to see the most recent messages logged by different components of ArcGIS GeoEvent Server. The UI illustrated below caches up to 500 logged messages and allows you to scroll through logged messages specifying how many messages should be listed on a page, select a specific type of logged message (e.g. DEBUG, INFO, WARN, or ERROR) as well as perform keyword searches.

GeoEvent Manager Logging User Interface

A significant limitation of this logging interface is that only the most recent 500 logged messages are maintained in its cache, so review and keyword searches you perform are limited to recently logged messages. This means that the velocity and volume of event records being processed as well as the number of GeoEvent Services, inputs, and outputs you have configured can affect (and limit) your ability to isolate logged messages of interest. A valuable debugging technique is to locate the actual log file on disk and open it in a text editor.

Location of the log file on disk

On a Windows platform, assuming your ArcGIS GeoEvent Server has been installed in the default folder beneath C:\Program Files, you should be able to locate the following system folder which contains the actual system log files.

C:\Program Files\ArcGIS\Server\GeoEvent\data\log

In this folder you will find one or more files with a base name karaf.log – these files can be opened in a text editor of your choice for content review and search. You can also use command-line utilities like tail, string processing utilities like sed, grep, and awk, as well as regular expressions to help isolate logged messages. Examples using these are included in other blogs in this series.

Only one log file, the file named karaf.log, is actively being written at any one time. When this file's size has grown as large as the system configuration allows, the file will automatically rollover and a new karaf.log file will be created. Log files which have rolled over will have a numeric suffix (e.g. karaf.log.1) and the file's last updated date/time will be older than the karaf.log currently being written.

If you open the karaf.log in a text editor you should treat the file as read-only as the logging system is actively writing to this file. Be sure to periodically reload the file's content in your text editor to make sure you are reviewing the latest file.

How to specify an allowed log file size and rollover properties

Locate the org.ops4j.pax.logging.cfg configuration file in the ArcGIS GeoEvent Server's \etc folder:

C:\Program Files\ArcGIS\Server\GeoEvent\etc

Using a text editor run as an administrator, because the file is located beneath C:\Program Files, you can edit properties of the system log such the default logging level for all loggers (a "logger" in this context is any of several components that are actively logging messages, such as the outbound feature adapter or the inbound TCP transport).

For example, at the 10.7 release a change was made to quiet the system logs by reducing the ROOT logging level from INFO to WARN so that only warnings are logged by default. You can see this specified in the following line in the org.ops4j.pax.logging.cfg configuration file:

# Root logger

log4j2.rootLogger.level = WARN

Searching the configuration file for the keyword "rolling" you will find lines which specify the karaf.log file's allowed size and rollover policy. Be careful -- not all of the lines specifying the rollover policy are necessarily in the same section of the log file; some may be located deeper in the file:

# Rolling file appender

log4j2.appender.rolling.type = RollingRandomAccessFile

log4j2.appender.rolling.name = RollingFile

log4j2.appender.rolling.fileName = ${karaf.data}/log/karaf.log

log4j2.appender.rolling.filePattern = ${karaf.data}/log/karaf.log.%i

log4j2.appender.rolling.append = true

log4j2.appender.rolling.layout.type = PatternLayout

log4j2.appender.rolling.layout.pattern = ${log4j2.pattern}

log4j2.appender.rolling.policies.type = Policies

log4j2.appender.rolling.policies.size.type = SizeBasedTriggeringPolicy

log4j2.appender.rolling.policies.size.size = 16MB

log4j2.appender.rolling.strategy.type = DefaultRolloverStrategy

log4j2.appender.rolling.strategy.max = 10

The settings above reflect defaults for the 10.7 release which specify that the karaf.log should rollover when it reaches 16MB and up to 10 indexed files will be used to archive older logged messages.

The anatomy of a logged message

Before we conclude our discussion on configuring the application logger I would like to briefly discuss the format of logged messages. The logged message format is configurable and logged messages by default have six parts. Each part is separated by a pipe ( | ) character.

Logged messages have six parts

The thread identifier default specification (see illustration below) has a minimum of 16 characters but no maximum length; some thread identifiers can be quite long. The class identifier spec includes a precision which limits the identifier to the most significant part of the class name. In the illustration above the fully-qualified class identifier com.esri.ges.fabric.core.ZKSerializer has been shortened to simply ZKSerializer. We will discuss the impact of this more in a later blog.

You can edit the org.ops4j.pax.logging.cfg configuration file to specify different patterns for the appender. You should refer to https://logging.apache.org/log4j/2.x/manual/layouts.html#PatternLayout in the Apache logging services on-line help before modifying the default appender pattern layout illustrated below.

# Common pattern layout for appenders

log4j2.pattern = %d{ISO8601} | %-5p | %-16t | %-32c{1} | %geoeventBundleID - %geoeventBundleName - %geoeventBundleVersion | %m%n

log4j2.out.pattern = \u001b[90m%d{HH:mm:ss\.SSS}\u001b[0m %highlight{%-5level}{FATAL=${color.fatal}, ERROR=${color.error}, WARN=${color.warn}, INFO=${color.info}, DEBUG=${color.debug}, TRACE=${color.trace}} \u001b[90m[%t]\u001b[0m %msg%n%throwable

Conclusion

Using the logging interface provided by GeoEvent Manger is a quick, simple way of reviewing logged messages recently produced by system components as they ingest, process, and disseminate event data. Event record velocity and volume can of course increase the number of messages being logged. Increasing the logging level from ERROR or WARN to INFO or DEBUG can drastically increase the volume of logged messages. If running components are frequently logging messages in the system's log file only the most recent the messages will be displayed in the GeoEvent Manager user-interface. Messages which have been pushed out of the cache can be reviewed by editing the karaf.log in a text editor. This is a key debugging technique, but you must be aware that the karaf.log is actively being written and will rollover as it grows beyond a specified size.

As you make and save changes to the system logging, for example, to request DEBUG logging on a specific logger, the changes will immediately be reflected in the org.ops4j.pax.logging.cfg configuration file. You can edit this file as an administrator and any changes you save will be picked up immediately; you do not have to stop and restart the ArcGIS GeoEvent Server service.