Integrate Logback with Spring ApplicationContext

How to call a Spring Bean from a custom Logback appender class - Spring Digma 3

The default logging framework in Spring Boot is Logback, which autoconfigures when we use the spring-boot-starter-parent in our Spring Boot project. The problem is that although Spring Boot is responsible for detecting, initializing, and configuring Logback in a Spring Boot application, Logback-related classes such as appenders are not beans and are not managed by the Spring ApplicationContext.

In this article, we’ll dive deep into this problem and provide three solutions for fixing the issue.

A bit of background:

Before offering solutions, let’s provide some background on Logback and Spring Boot logging.

What is Logback?

Logback is a logging framework for Java applications designed to be faster and more feature-rich than its predecessor, Log4j 1.x.

By offering a new generic architecture, Logback is applicable to a wide range of use cases.

It is famous for its performance and flexibility. These are some main advantages of Logback:

  • Flexible configuration: Logback configuration can be either XML or Groovy configuration files. It also supports automatic reloading of configuration files.
  • Powerful filtering: Logback event filtering allows us to control the log messages that are captured and processed.
  • Modularity and extensibility: Logback is modular and extensible, so adding custom appenders, filters, and other components is easy.
  • Support for multiple logging APIs: Logback supports several logging APIs in Java, including SLF4JCommons Logging, and the Java Util Logging API.

All the above features have caused Logback to become a popular framework among others in the Java ecosystem, and Spring Boot is no exception.

What are other options for logging in the Spring Boot?

As mentioned before, Logback is the default logging framework in Spring Boot, and we don’t need to configure it to use it. Usually, default configurations are good enough to start.

Another important aspect of logging in Spring Boot is that SLF4J is used as a facade layer on top of the Logback or any other logging framework that we want to use in Spring Boot.

So, switching between the different logging frameworks is easy. Also, since Spring Boot uses Commons Logging API for all internal logging, it is easier for us to choose other logging frameworks. Other options are:

How to call a Spring Bean from a custom Logback appender class - image 15

Spring Boot Logging

How is Spring Boot initializing and configuring Logback?

Since Logback supports both XML or Groovy syntax in configuration files, Spring Boot will pick files with these names (logback-spring.xmllogback-spring.groovylogback.xml, or logback.groovy) from the root of the classpath or a location specified by the logging.config Spring config.

It is worth mentioning that the Spring team recommends using the “-spring" variants file name for the logging configuration files.

The reason that the Logback configuration can not be specified as the Spring configuration described in the Spring Boot documentation:

Since logging is initialized before the ApplicationContext is created, it is not possible to control logging from @PropertySources in Spring @Configuration files. The only way to change the logging system or disable it entirely is through System properties.

The file names for other logging frameworks in Spring Boot are:

  • log4j2-spring.xml or log4j2.xml for Log4J2
  • logging.properties for Java Util Logging

What is a Logback Appender?

The three main components in Logback architecture are: LoggerAppender, and Layout. In very simple terms:

Logger is an interface for creating log messages. An Appender sends log messages to a target, and a Logger can have several appenders. Finally, As it turns out, a Layout is responsible for formatting the log message before it is sent to the target.

Logback provides several different appenders out of the box, such as ConsoleAppenderFileAppender, or RollingFileAppender. We can also easily implement our own custom appender and register it to Logback in the configuration file.

How to call a Spring Bean from a custom Logback appender class - image 16

Access to Spring ApplicationContext from a custom Logback appender

After a brief introduction about Logback and Spring Boot logging, let’s dive into the code and see what the root of the problem is. In my case, I have a custom Logback appender (NotificationAppender) that is supposed to send a notification (for example, email, push notification, or…) under certain circumstances (for example, the occurrence of a specific number of error logs or finding a specific text in the logs, or…).

To send that notification, the NotificationAppender needs to access a Spring bean called Notifier, but as we mentioned before, Logback is not managed by the Spring ApplicationContext, so it does not access ApplicationContext, and we can not inject the Notifier bean in our custom appender (NotificationAppender), it means this code will not work:

public class NotificationAppender extends AppenderBase<ILoggingEvent> {

    @Autowired
    private  Notifier notifier;

    @Override
    protected void append(ILoggingEvent loggingEvent) {
        notifier.notify(loggingEvent.getFormattedMessage());
    }
}

I registered the NotificationAppender in the logback-spring.xml:

<configuration debug="true">
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

    <appender name="NOTIFY" class="com.saeed.springlogbackappender.NotificationAppender"/>

    <logger name="org.springframework.web" level="DEBUG"/>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="NOTIFY" />
    </root>
</configuration>

We will get errors like this because, as I mentioned, Logback does not access the ApplicationContext:

10:41:05,660 |-ERROR in com.saeed.springlogbackappender.NotificationAppender[NOTIFY] - Appender [NOTIFY] failed to append. java.lang.NullPointerException: Cannot invoke "com.saeed.springlogbackappender.Notifier.notify(String)" because "this.notifier" is null
 at java.lang.NullPointerException: Cannot invoke "com.saeed.springlogbackappender.Notifier.notify(String)" because "this.notifier" is null

Even if we change the appender class and make it a Spring bean by adding @Component on top of the class, The situation is getting worse.

@Component
public class NotificationAppender extends AppenderBase<ILoggingEvent> {

    private  Notifier notifier;

    public NotificationAppender(Notifier notifier) {
        this.notifier = notifier;
    }

    @Override
    protected void append(ILoggingEvent loggingEvent) {
        notifier.notify(loggingEvent.getFormattedMessage());
    }
}

And we will get an error similar to this:

10:53:57,887 |-ERROR in ch.qos.logback.core.model.processor.AppenderModelHandler - Could not create an Appender of type [com.saeed.springlogbackappender.NotificationAppender]. ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type com.saeed.springlogbackappender.NotificationAppender
Caused by: java.lang.NoSuchMethodException: com.saeed.springlogbackappender.NotificationAppender.<init>()

This is because Logback needs a default constructor to initialize the NotificationAppender. If we add the default constructor to the class, we will get the previous NullPointerException for the Notifier bean because now we have two instances of NotificationAppender in our application, one instantiated and managed by Logback and the other by ApplicationContext!

I hope I was able to explain the problem. Now, we want to solve this problem by providing three solutions. I have created a spring boot project called spring-logback-appender in GitHub and created separate commits for each solution.

1- Spring Boot creates the bean and adds it as a Logback appender dynamically in @PostConstruct

In this approach, we define the NotificationAppender as a Spring bean, so we can inject every Spring bean into it without a problem. But As we saw in the problem statement before, how do we want to introduce this Spring bean as an appender to Logback? We will do it programmatically using the LoggerContext:

@Component
public class NotificationAppender extends AppenderBase<ILoggingEvent> {

    private final Notifier notifier;

    public NotificationAppender(Notifier notifier) {
        this.notifier = notifier;
    }

    @Override
    protected void append(ILoggingEvent loggingEvent) {
        notifier.notify(loggingEvent.getFormattedMessage());
    }

    @PostConstruct
    public void init() {
        LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
        Logger rootLogger = loggerContext.getLogger(Logger.ROOT_LOGGER_NAME);
        rootLogger.addAppender(this);
        setContext(context);
        start();
    }
}

This will work, and if we call the /hello API, we will see that the Notifier will notify using the appender.

For me, this approach has some drawbacks:

  • It is less flexible because the appender is not configurable in the logback-spring.xml file.
  • We will miss some logs at the early stage of the Spring boot start.

2- Logback creates the appender and then fills the bean dependency in the custom appender using the ApplicationContexAware

In this approach, to fix one important drawback of the first approach, we will register the Logback appender in a standard way by adding it to the logback-spring.xml file.

<configuration debug="true">
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

    <appender name="NOTIFY" class="com.saeed.springlogbackappender.NotificationAppender"/>

    <logger name="org.springframework.web" level="DEBUG"/>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="NOTIFY" />
    </root>
</configuration>

The other change that we need to make is to make the Notifier field static and NotificationAppender implement the ApplicationContextAware:

@Component
public class NotificationAppender extends AppenderBase<ILoggingEvent> implements ApplicationContextAware {

    private static Notifier notifier;

    @Override
    protected void append(ILoggingEvent loggingEvent) {
        if (notifier != null)
            notifier.notify(loggingEvent.getFormattedMessage());
    }

    @Override
    public void setApplicationContext(ApplicationContext applicationContext) throws BeansException {
        notifier = applicationContext.getAutowireCapableBeanFactory().getBean(Notifier.class);
    }

}

This approach will result in a similar result to the first approach, but now the appender is configurable using a standard method in the Logback.

We still have some drawbacks to this approach:

  • We need to check if the notifier is not null and make it static.
  • Since the injected class is not present before the Spring ApplicationContext loads completely, we will miss some logs at an early stage of the application start.

3- As mentioned above, you might be interested in not losing the events logged during the Spring Boot startup

In the third and last approach, we will concentrate on fixing the problem of missing logs in the early stages of the application start. For this approach, I was inspired by this question on StackOverflow to mix both previous approaches and create a new AppenderDelegator class.

In this approach, we will define two appenders:

  • AppenderDelegator: Register as an appender in the Logback config file (logback-spring.xml). This appender is our main appender, acts as a delegator, and has a buffer to store log events for when the actual logger is not yet ready to log.
public class AppenderDelegator<E> extends UnsynchronizedAppenderBase<E> {

    private final ArrayList<E> logBuffer = new ArrayList<>(1024);
    private Appender<E> delegate;

    @Override
    protected void append(E event) {
        synchronized (logBuffer) {
            if (delegate != null) {
                delegate.doAppend(event);
            } else {
                logBuffer.add(event);
            }
        }
    }

    public void setDelegateAndReplayBuffer(Appender<E> delegate) {
        synchronized (logBuffer) {
            this.delegate = delegate;
            for (E event : this.logBuffer) {
                delegate.doAppend(event);
            }
            this.logBuffer.clear();
        }
    }
}
  • NotificationAppender: This is our actual appender, which is configured programmatically and uses the Spring SmartLifecycle to have more control over its lifecycle. We will connect this appender to the delegator one during the component start lifecycle:
@Component
public class NotificationAppender extends AppenderBase<ILoggingEvent> implements SmartLifecycle {

    private final Notifier notifier;

    public NotificationAppender(Notifier notifier) {
        this.notifier = notifier;
    }

    @Override
    protected void append(ILoggingEvent loggingEvent) {
        notifier.notify(loggingEvent.getFormattedMessage());
    }

    @Override
    public boolean isRunning() {
        return isStarted();
    }

    @Override
    public void start() {
        super.start();
        LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
        Logger rootLogger = loggerContext.getLogger(Logger.ROOT_LOGGER_NAME);
        AppenderDelegator<ILoggingEvent> delegate = (AppenderDelegator<ILoggingEvent>) rootLogger.getAppender("DELEGATOR");
        delegate.setDelegateAndReplayBuffer(this);
    }
}

It is worth mentioning that, unlike the second approach, we don’t add the NotificationAppender to the LoggerContext’s root logger.

This approach is the most complicated one, but it offers the most flexibility and log coverage in the appender.

Dev/Test Observability using Digma

Logs, metrics, and traces are the three pillars of observability, and this problem that we tried to solve happened to me in a real project where we wanted to produce a metric in specific circumstances in the logs.

In the last section of this article, I want to introduce you to Digma, a tool that is very helpful for me during testing and development. The Digma has an IntelliJ plugin that profiles our code execution in runtime on our local machine without needing to deploy it to other environments. It helps us find the root cause of different issues, such as bottlenecksscaling problems, or DB query issues locally.

Unlike traditional observability tools that target DevOps and IT teams, we built Digma as a Continuous Feedback platform for developers that is all about writing performant code.

Correlating Log and Trace using Digma

Log correlation is supported out of the box in Spring Boot 3, If we have Micrometer Tracing on the classpath, then logs are automatically correlated, which means they contain a trace and span identifier:

2024-05-21T17:40:22.986+02:00  INFO 22314 --- [nio-8080-exec-2] [cc2253dbdf2c1b3a4a1f23838ffe44d9-c617167947067265] c.s.springlogbackappender.HelloService   : Call Hello service!

As you can see, the format is similar to this: [traceId-spanId] in the log when we call the /hello endpoint in our sample project. In this case, the traceId and spanId are: [cc2253dbdf2c1b3a4a1f23838ffe44d9-c617167947067265]

On the other hand, one of the exciting features of Digma is to show traces when we call the /hello endpoint:

How to call a Spring Bean from a custom Logback appender class - image 17

Digma Observability View

By clicking on the Trace button in the Observability view, we can see the trace details in a timeline view:

How to call a Spring Bean from a custom Logback appender class - image 19

Correlate Log and Trace using Digma

As you can see, in addition to the nice timeline view and details, we can also see the traceId (on the top) and spanId in this view, which helps us to correlate logs and traces easily.

Learn more about Digma:

Final Thought

We discuss the challenge of accessing a Spring Bean from a custom Logback appender in a Spring Boot application and provide three solutions to fix this issue. The second approach should usually work. In the last section, we also discuss how to correlate the Log and Trace using Digma to improve application observability.


Install Digma: Here

Spread the news:

Similar Posts

Leave a Reply

Your email address will not be published. Required fields are marked *