15. Logging

One of the most common logging tasks is to adjust the log-level of one or more Loggers, or the ROOT Logger. However, a user may only want to adjust the log-level for specific components of his/her Spring Boot application, such as for Apache Geode, by setting the log-level for only the Logger that logs Apache Geode events.

SBDG’s Logback configuration defines 3 Loggers to control the log output from Apache Geode:

Apache Geode Loggers by name. 

<logger name="com.gemstone.gemfire" level="${spring.boot.data.gemfire.log.level:-INFO}"/>
<logger name="org.apache.geode" level="${spring.boot.data.gemfire.log.level:-INFO}"/>
<logger name="org.jgroups" level="${spring.boot.data.gemfire.jgroups.log.level:-ERROR}"/>

The com.gemstone.gemfire Logger is a legacy Logger covering old Pivotal GemFire bits still present in Apache Geode for backwards compatibility reasons. This Logger’s use should be largely unnecessary.

The org.apache.geode Logger is the primary Logger used to control log output from all Apache Geode components during the runtime operation of Apache Geode. Both this Logger and the legacy com.gemstone.gemfire Logger default log output to INFO.

The org.jgroups Logger is used to log output from Apache Geode’s message distribution and membership system. Apache Geode uses JGroups for membership and message distribution between peer members (nodes) in the cluster (distributed system). By default, JGroups log messages are logged at ERROR.

The log-level for the com.gemstone.gemfire and org.apache.geode Loggers are configured with the spring.boot.data.gemfire.log.level property. The org.jgroups Logger is independently configured with the spring.boot.data.gemfire.jgroups.log.level property.

The SBDG logging properties can be set on the command-line as JVM System Properties when running your Spring Boot application:

Setting the log-level from the command-line. 

$ java -classpath ...:/path/to/MySpringBootApplication.jar -Dspring.boot.data.gemfire.log.level=DEBUG
    package.to.MySpringBootApplicationClass

Alternatively, you can configure and control Apache Geode logging in Spring Boot application.properties:

Setting the log-level in application.properties. 

spring.boot.data.gemfire.log.level=DEBUG

For backwards compatibility, SBDG additionally supports the old Spring Data for Apache Geode (SDG) logging properties as well, using either:

spring.data.gemfire.cache.log-level=DEBUG

Or:

spring.data.gemfire.logging.level=DEBUG

If you previously used either of these SDG based logging properties, they will continue to work as designed in SBDG 1.3 or later.

As mentioned earlier, SBDG allows you to compose your own logging configuration from SBDG’s default, provided Logback configuration metadata.

SBDG conveniently bundles the Loggers and Appenders from SBDG’s logging starter into a template file that you can include into your own, custom Logback XML configuration file.

The Logback template file appears as follows:

logback-include.xml. 

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

	<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<pattern>%d %5p %40.40c:%4L - %m%n</pattern>
		</encoder>
	</appender>

	<appender name="delegate" class="org.springframework.geode.logging.slf4j.logback.DelegatingAppender"/>

	<logger name="com.gemstone.gemfire" level="${spring.boot.data.gemfire.log.level:-INFO}"/>
	<logger name="org.apache.geode" level="${spring.boot.data.gemfire.log.level:-INFO}"/>
	<logger name="org.jgroups" level="${spring.boot.data.gemfire.jgroups.log.level:-ERROR}"/>

</included>

Then, this Logback configuration snippet can be included in an application-specific, Logback XML configuration file as follows:

logback.xml. 

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

	<statusListener class="ch.qos.logback.core.status.NopStatusListener"/>

	<include resource="logback-include.xml"/>

	<root level="${logback.root.log.level:-INFO}">
		<appender-ref ref="console"/>
		<appender-ref ref="delegate"/>
	</root>

</configuration>

The org.springframework.geode.logging.slf4j.logback.CompositeAppender class is an implementation of Logback Appender and the Composite Software Design Pattern.

CompositeAppender enables developers to compose multiple Appenders and use them as if they were a single Appender.

For example, you could compose both the Logback ConsoleAppender and FileAppender into one using:

Composing multiple Appenders. 

ConsoleAppender<ILoggingEvent> consoleAppender = ...;

FileAppender<ILoggingEvent> fileAppender = ...;

Appender<ILoggingEvent> compositeAppender = CompositeAppender.compose(consoleAppender, fileAppender);

// do something with the compositeAppender

You could then add the CompositeAppender to a "named" Logger by doing:

Register CompositeAppender on "named" Logger. 

Logger namedLogger = LoggerFactory.getLogger("loggerName");

LogbackSupport.toLogbackLogger(namedLogger)
  .ifPresent(it -> LogbackSupport.addAppender(it, compositeAppender));

In this case, the "named" Logger will log events (or log messages) to both the Console and File Appenders.

It is simple to compose an array or Iterable of Appenders by using either the CompositeAppender.compose(:Appender<T>[]) method or the CompositeAppender.compose(:Iterable<Appender<T>>) method.

The org.springframework.geode.logging.slf4j.logback.DelegatingAppender is a pass-through Logback Appender implementation wrapping another Logback Appender, or collection of Appenders doing actual work, like the ConsoleAppender, a FileAppender or a SocketAppender, etc. By default, the DelegatingAppender delegates to the NOPAppender thereby doing no actual work.

By default, SBDG registers the org.springframework.geode.logging.slfj4.logback.DelegatingAppender with the ROOT Logger, which can be useful for testing purposes.

With a reference to a DelegatingAppender, you can add any Appender as the delegate, even a CompositeAppender:

Add ConsoleAppender as the "delegate" for the DelegatingAppender. 

ConsoleAppender consoleAppender = new ConsoleAppender();

LogbackSupport.resolveLoggerContext().ifPresent(consoleAppender::setContext);

consoleAppender.setImmediateFlush(true);
consoleAppender.start();

LogbackSupport.resolveRootLogger()
  .flatMap(LogbackSupport::toLogbackLogger)
  .flatMap(rootLogger -> LogbackSupport.resolveAppender(rootLogger,
    LogbackSupport.DELEGATE_APPENDER_NAME, DelegatingAppender.class))
  .ifPresent(delegateAppender -> delegateAppender.setAppender(consoleAppender));

The org.springframework.geode.logging.slf4j.logback.StringAppender stores log message in-memory, appended to a String.

The StringAppender is very useful for testing purposes. For instance, you can use the StringAppender to assert that a Logger used by certain application components logged messages at the appropriately configured log level while other log messages were not logged.

For example:

StringAppender in Action. 

class ApplicationComponent {

	private final Logger logger = LoggerFactory.getLogger(getClass());

	public void someMethod() {
		logger.debug("Some debug message");
		// ...
	}

	public void someOtherMethod() {
		logger.info("Some info message");
	}
}

// Assuming the ApplicationComponent Logger was configured with log-level 'INFO', then...
class ApplicationComponentUnitTests {

	private final ApplicationComponent applicationComponent = new ApplicationComponent();

	private final Logger logger = LoggerFactory.getLogger(ApplicationComponent.class);

	private StringAppender stringAppender;

	@Before
    public void setup() {

        LogbackSupport.toLogbackLogger(logger)
            .map(Logger::getLevel)
            .ifPresent(level -> assertThat(level).isEqualTo(Level.INFO));

        stringAppender = new StringAppender.Builder()
            .applyTo(logger)
            .build();
    }

    @Test
    public void someMethodDoesNotLogDebugMessage() {

        applicationComponent.someMethod();

        assertThat(stringAppender.getLogOutput).doesNotContain("Some debug message");
    }

    @Test
    public void someOtherMethodLogsInfoMessage() {

        applicationComponent.someOtherMethod();

        assertThat(stringAppender.getLogOutput()).contains("Some info message");
    }
}

There are many other uses for the StringAppender and it can be used safely in a multi-Threaded context by calling StringAppender.Builder.useSynchronization().

When combined with other SBDG provided Appenders in conjunction with the LogbackSupport class, you have a lot of power both in application code as well as your tests.