Chapter 18. Log

The log:clear command clears the log entries.

The log:display command displays the log entries.

By default, it displays the log entries of the rootLogger:

karaf@root()> log:display
2015-07-01 19:12:46,208 | INFO  | FelixStartLevel  | SecurityUtils                    | 16 - org.apache.sshd.core - 0.12.0 | BouncyCastle not registered, using the default JCE provider
2015-07-01 19:12:47,368 | INFO  | FelixStartLevel  | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Starting JMX OSGi agent

You can also display the log entries from a specific logger, using the logger argument:

karaf@root()> log:display ssh
2015-07-01 19:12:46,208 | INFO  | FelixStartLevel  | SecurityUtils                    | 16 - org.apache.sshd.core - 0.12.0 | BouncyCastle not registered, using the default JCE provider

By default, all log entries will be displayed. It could be very long if your Apache Karaf container is running since a long time. You can limit the number of entries to display using the -n option:

karaf@root()> log:display -n 5
2015-07-01 06:53:24,143 | INFO  | JMX OSGi Agent   | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Registering org.osgi.jmx.framework.BundleStateMBean to MBeanServer com.sun.jmx.mbeanserver.JmxMBeanServer@27cc75cb with name osgi.core:type=bundleState,version=1.7,framework=org.apache.felix.framework,uuid=5335370f-9dee-449f-9b1c-cabe74432ed1
2015-07-01 06:53:24,150 | INFO  | JMX OSGi Agent   | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Registering org.osgi.jmx.framework.PackageStateMBean to MBeanServer com.sun.jmx.mbeanserver.JmxMBeanServer@27cc75cb with name osgi.core:type=packageState,version=1.5,framework=org.apache.felix.framework,uuid=5335370f-9dee-449f-9b1c-cabe74432ed1
2015-07-01 06:53:24,150 | INFO  | JMX OSGi Agent   | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Registering org.osgi.jmx.framework.ServiceStateMBean to MBeanServer com.sun.jmx.mbeanserver.JmxMBeanServer@27cc75cb with name osgi.core:type=serviceState,version=1.7,framework=org.apache.felix.framework,uuid=5335370f-9dee-449f-9b1c-cabe74432ed1
2015-07-01 06:53:24,152 | INFO  | JMX OSGi Agent   | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Registering org.osgi.jmx.framework.wiring.BundleWiringStateMBean to MBeanServer com.sun.jmx.mbeanserver.JmxMBeanServer@27cc75cb with name osgi.core:type=wiringState,version=1.1,framework=org.apache.felix.framework,uuid=5335370f-9dee-449f-9b1c-cabe74432ed1
2015-07-01 06:53:24,501 | INFO  | FelixStartLevel  | RegionsPersistenceImpl           | 78 - org.apache.karaf.region.persist - 4.0.0 | Loading region digraph persistence

You can also limit the number of entries stored and retain using the size property in etc/org.apache.karaf.log.cfg file:

#
# The number of log statements to be displayed using log:display. It also defines the number
# of lines searched for exceptions using log:display exception. You can override this value
# at runtime using -n in log:display.
#
size = 500

By default, each log level is displayed with a different color: ERROR/FATAL are in red, DEBUG in purple, INFO in cyan, etc. You can disable the coloring using the --no-color option.

The log entries format pattern doesn’t use the conversion pattern define in etc/org.ops4j.pax.logging.cfg file. By default, it uses the pattern property defined in etc/org.apache.karaf.log.cfg.

#
# The pattern used to format the log statement when using log:display. This pattern is according
# to the log4j layout. You can override this parameter at runtime using log:display with -p.
#
pattern = %d{ISO8601} | %-5.5p | %-16.16t | %-32.32c{1} | %X{bundle.id} - %X{bundle.name} - %X{bundle.version} | %m%n

You can also change the pattern dynamically (for one execution) using the -p option:

karaf@root()> log:display -p "%d - %c - %m%n"
2015-07-01 07:01:58,007 - org.apache.sshd.common.util.SecurityUtils - BouncyCastle not registered, using the default JCE provider
2015-07-01 07:01:58,725 - org.apache.aries.jmx.core - Starting JMX OSGi agent
2015-07-01 07:01:58,744 - org.apache.aries.jmx.core - Registering MBean with ObjectName [osgi.compendium:service=cm,version=1.3,framework=org.apache.felix.framework,uuid=6361fc65-8df4-4886-b0a6-479df2d61c83] for service with service.id [13]
2015-07-01 07:01:58,747 - org.apache.aries.jmx.core - Registering org.osgi.jmx.service.cm.ConfigurationAdminMBean to MBeanServer com.sun.jmx.mbeanserver.JmxMBeanServer@27cc75cb with name osgi.compendium:service=cm,version=1.3,framework=org.apache.felix.framework,uuid=6361fc65-8df4-4886-b0a6-479df2d61c83

The pattern is a regular Log4j pattern where you can use keywords like %d for the date, %c for the class, %m for the log message, etc.

The log:exception-display command displays the last occurred exception.

As for log:display command, the log:exception-display command uses the rootLogger by default, but you can specify a logger with the logger argument.

The log:get command show the current log level of a logger.

By default, the log level showed is the one from the root logger:

karaf@root()> log:get
Logger | Level
--------------
ROOT   | INFO

You can specify a particular logger using the logger argument:

karaf@root()> log:get ssh
Logger | Level
--------------
ssh    | INFO

The logger argument accepts the ALL keyword to display the log level of all logger (as a list).

For instance, if you have defined your own logger in etc/org.ops4j.pax.logging.cfg file like this:

log4j.logger.my.logger = DEBUG

you can see the list of loggers with the corresponding log level:

karaf@root()> log:get ALL
Logger    | Level
-----------------
ROOT      | INFO
my.logger | DEBUG

The log:list command is an alias to log:get ALL.

The log:log command allows you to manually add a message in the log. It’s interesting when you create Apache Karaf scripts:

karaf@root()> log:log "Hello World"
karaf@root()> log:display
2015-07-01 07:20:16,544 | INFO  | Local user karaf | command                          | 59 - org.apache.karaf.log.command - 4.0.0 | Hello World

By default, the log level is INFO, but you can specify a different log level using the -l option:

karaf@root()> log:log -l ERROR "Hello World"
karaf@root()> log:display
2015-07-01 07:21:38,902 | ERROR | Local user karaf | command                          | 59 - org.apache.karaf.log.command - 4.0.0 | Hello World

The log:set command sets the log level of a logger.

By default, it changes the log level of the rootLogger:

karaf@root()> log:set DEBUG
karaf@root()> log:get
Logger | Level
--------------
ROOT   | DEBUG

You can specify a particular logger using the logger argument, after the level one:

karaf@root()> log:set INFO my.logger
karaf@root()> log:get my.logger
Logger    | Level
-----------------
my.logger | INFO

The level argument accepts any Log4j log level: TRACE, DEBUG, INFO, WARN, ERROR, FATAL.

By it also accepts the DEFAULT special keyword.

The purpose of the DEFAULT keyword is to delete the current level of the logger (and only the level, the other properties like appender are not deleted) in order to use the level of the logger parent (logger are hierarchical).

For instance, you have defined the following loggers (in etc/org.ops4j.pax.logging.cfg file):

rootLogger=INFO,out,osgi:*
my.logger=INFO,appender1
my.logger.custom=DEBUG,appender2

You can change the level of my.logger.custom logger:

karaf@root()> log:set INFO my.logger.custom

Now we have:

rootLogger=INFO,out,osgi:*
my.logger=INFO,appender1
my.logger.custom=INFO,appender2

You can use the DEFAULT keyword on my.logger.custom logger to remove the level:

karaf@root()> log:set DEFAULT my.logger.custom

Now we have:

rootLogger=INFO,out,osgi:*
my.logger=INFO,appender1
my.logger.custom=appender2

It means that, at runtime, the my.logger.custom logger uses the level of its parent my.logger, so INFO.

Now, if we use DEFAULT keyword with the my.logger logger:

karaf@root()> log:set DEFAULT my.logger

We have:

rootLogger=INFO,out,osgi:*
my.logger=appender1
my.logger.custom=appender2

So, both my.logger.custom and my.logger use the log level of the parent rootLogger.

It’s not possible to use DEFAULT keyword with the rootLogger and it doesn’t have parent.

The log:tail is exactly the same as log:display but it continuously displays the log entries.

You can use the same options and arguments as for the log:display command.

By default, it displays the entries from the rootLogger:

karaf@root()> log:tail
2015-07-01 07:40:28,152 | INFO  | FelixStartLevel  | SecurityUtils                    | 16 - org.apache.sshd.core - 0.9.0 | BouncyCastle not registered, using the default JCE provider
2015-07-01 07:40:28,909 | INFO  | FelixStartLevel  | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Starting JMX OSGi agent
2015-07-01 07:40:28,928 | INFO  | FelixStartLevel  | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Registering MBean with ObjectName [osgi.compendium:service=cm,version=1.3,framework=org.apache.felix.framework,uuid=b44a44b7-41cd-498f-936d-3b12d7aafa7b] for service with service.id [13]
2015-07-01 07:40:28,936 | INFO  | JMX OSGi Agent   | core                             | 68 - org.apache.aries.jmx.core - 1.1.1 | Registering org.osgi.jmx.service.cm.ConfigurationAdminMBean to MBeanServer com.sun.jmx.mbeanserver.JmxMBeanServer@27cc75cb with name osgi.compendium:service=cm,version=1.3,framework=org.apache.felix.framework,uuid=b44a44b7-41cd-498f-936d-3b12d7aafa7b

To exit from the log:tail command, just type CTRL-C.

You can use filters on appender. Filters allow log events to be evaluated to determine if or how they should be published.

Log4j provides ready to use filters:

The filter is defined directly on the appender, in the etc/org.ops4j.pax.logging.cfg configuration file.

The format to use it:

log4j.appender.[appender-name].filter.[filter-name]=[filter-class]
log4j.appender.[appender-name].filter.[filter-name].[option]=[value]

For instance, you can use the f1 LevelRangeFilter on the out default appender:

log4j.appender.out.filter.f1=org.apache.log4j.varia.LevelRangeFilter
log4j.appender.out.filter.f1.LevelMax=FATAL
log4j.appender.out.filter.f1.LevelMin=DEBUG

Thanks to this filter, the log files generated by the out appender will contain only log messages with a level between DEBUG and FATAL (the log events with TRACE as level are rejected).

A nested appender is a special kind of appender that you use "inside" another appender. It allows you to create some kind of "routing" between a chain of appenders.

The most used "nested compliant" appender are:

This kind of appender accepts an appenders property in the appender definition:

log4j.appender.[appender-name].appenders=[comma-separated-list-of-appender-names]

For instance, you can create a AsyncAppender named async and asynchronously dispatch the log events to a JMS appender:

log4j.appender.async=org.apache.log4j.AsyncAppender
log4j.appender.async.appenders=jms

log4j.appender.jms=org.apache.log4j.net.JMSAppender
...

Sometime, appenders can fail. For instance, a RollingFileAppender tries to write on the filesystem but the filesystem is full, or a JMS appender tries to send a message but the JMS broker is not there.

As log can be very critical to you, you have to be inform that the log appender failed.

It’s the purpose of the error handlers. Appenders may delegate their error handling to error handlers, giving a chance to react to this appender errors.

You have two error handlers available:

You can define the error handler that you want to use for each appender using the errorhandler property on the appender definition itself:

log4j.appender.[appender-name].errorhandler=[error-handler-class]
log4j.appender.[appender-name].errorhandler.root-ref=[true|false]
log4j.appender.[appender-name].errorhandler.logger-ref=[logger-ref]
log4j.appender.[appender-name].errorhandler.appender-ref=[appender-ref]

The sift appender is a OSGi oriented appender allowing you to split the log events based on MDC (Mapped Diagnostic Context) attributes.

MDC allows you to distinguish the different source of log events.

The sift appender provides OSGi oritend MDC attributes by default:

You can use these MDC properties to create a log file per bundle:

log4j.appender.sift=org.apache.log4j.sift.MDCSiftingAppender
log4j.appender.sift.key=bundle.name
log4j.appender.sift.default=karaf
log4j.appender.sift.appender=org.apache.log4j.FileAppender
log4j.appender.sift.appender.layout=org.apache.log4j.PatternLayout
log4j.appender.sift.appender.layout.ConversionPattern=%d{ABSOLUTE} | %-5.5p | %-16.16t | %-32.32c{1} | %-32.32C %4L | %m%n
log4j.appender.sift.appender.file=${karaf.data}/log/$\\{bundle.name\\}.log
log4j.appender.sift.appender.append=true

By default, Apache Karaf provides a special stack trace renderer, adding some OSGi specific specific information.

In the stack trace, in addition of the class throwing the exception, you can find a pattern [id:name:version] at the end of each stack trace line, where:

It’s very helpful to diagnosing the source of an issue.

For instance, in the following IllegalArgumentException stack trace, we can see the OSGi details about the source of the exception:

java.lang.IllegalArgumentException: Command not found:  *:foo
	at org.apache.felix.gogo.runtime.shell.Closure.execute(Closure.java:225)[21:org.apache.karaf.shell.console:4.0.0]
	at org.apache.felix.gogo.runtime.shell.Closure.executeStatement(Closure.java:162)[21:org.apache.karaf.shell.console:4.0.0]
	at org.apache.felix.gogo.runtime.shell.Pipe.run(Pipe.java:101)[21:org.apache.karaf.shell.console:4.0.0]
	at org.apache.felix.gogo.runtime.shell.Closure.execute(Closure.java:79)[21:org.apache.karaf.shell.console:4.0.0]
	at org.apache.felix.gogo.runtime.shell.CommandSessionImpl.execute(CommandSessionImpl.java:71)[21:org.apache.karaf.shell.console:4.0.0]
	at org.apache.karaf.shell.console.jline.Console.run(Console.java:169)[21:org.apache.karaf.shell.console:4.0.0]
	at java.lang.Thread.run(Thread.java:637)[:1.7.0_21]

You can use your own appenders in Apache Karaf.

The easiest way to do that is to package your appender as an OSGi bundle and attach it as a fragment of the org.ops4j.pax.logging.pax-logging-service bundle.

For instance, you create MyAppender:

public class MyAppender extends AppenderSkeleton {
...
}

You compile and package as an OSGi bundle containing a MANIFEST looking like:

Manifest:
Bundle-SymbolicName: org.mydomain.myappender
Fragment-Host: org.ops4j.pax.logging.pax-logging-service
...

Copy your bundle in the Apache Karaf system folder. The system folder uses a standard Maven directory layout: groupId/artifactId/version.

In the etc/startup.properties configuration file, you define your bundle in the list before the pax-logging-service bundle.

You have to restart Apache Karaf with a clean run (purging the data folder) in order to reload the system bundles. You can now use your appender directly in etc/org.ops4j.pax.logging.cfg configuration file.