# How to configure Spring Logback to pipe logs to different appenders using Profile Specific Configuration Extension

This article talks about my experience when configuring [Spring Boot Logback Configuration](https://docs.spring.io/spring-boot/docs/current/reference/html/howto.html#howto.logging.logback) where I make use of [Spring Boot - Profile Specific Configuration Extension](https://docs.spring.io/spring-boot/docs/current/reference/html/features.html#features.logging.logback-extensions.profile-specific) feature to configure different rules per profile and [logstash-logback-encoder](https://github.com/logfellow/logstash-logback-encoder) library to pipe logs as JSON format.

The end state is simple

- In development, output the logs using `CONSOLE` appender
- In production, output the logs using `JSON` appender

With that in mind, let's see how we can achieve it.

# Configure logback-spring file

It is [recommended](https://docs.spring.io/spring-boot/docs/current/reference/html/howto.html#howto.logging.logback) to create `logback-spring.xml` in `src/main/resources` instead of `logback.xml` because doing so allows us to use `Spring Logback Extension` such as `Profile Specific Configuration` feature.

What exactly does this extension help us with? Imagine that we want to configure different "rules" for different environments. We can do so using this configuration

```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<include resource="org/springframework/boot/logging/logback/base.xml" />
	
    <!-- Define different configuration for different profiles -->
    <springProfile name="default">
        <logger name="com.bwgjoseph.springlogback" additivity="false" level="debug">
            <appender-ref ref="CONSOLE" />
        </logger>
		
		<root level="INFO">
            <appender-ref ref="CONSOLE" />
        </root>
		
    </springProfile>

    <!-- For multiple profiles, use commas to separate profile name -->
    <springProfile name="staging, production">
        <logger name="com.bwgjoseph.springlogback" additivity="false" level="warn">
            <appender-ref ref="CONSOLE" />
        </logger>
		
		<root level="INFO">
            <appender-ref ref="CONSOLE" />
        </root>
    </springProfile>

</configuration>
```

For the default environment, we set the log level for `com.bwgjoseph.springlogback` to `debug` and to `warn` in the production environment.

# Example 

Assuming we have the following code

```java
@SpringBootApplication
public class SpringLogbackApplication {
	public static void main(String[] args) {
		SpringApplication.run(SpringLogbackApplication.class, args);
	}

	@Bean
	ApplicationRunner init() {
		return arg -> {
			Logger rootLogger = LoggerFactory.getLogger(SpringLogbackApplication.class);
			rootLogger.trace("trace");
			rootLogger.debug("debug");
			rootLogger.info("info");
			rootLogger.warn("warn");
			rootLogger.error("error");
		};
	}
}
```

Spring will initialize your application with `default` profile unless overridden in `application.properties`, and since we did not, when the application is started, the logs would look like

```
2022-04-10 02:17:26.343  INFO 6372 --- [  restartedMain] c.b.s.SpringLogbackApplication           : Started SpringLogbackApplication in 1.597 seconds (JVM running for 2.009)
2022-04-10 02:17:26.349 DEBUG 6372 --- [  restartedMain] c.b.s.SpringLogbackApplication           : debug
2022-04-10 02:17:26.350  INFO 6372 --- [  restartedMain] c.b.s.SpringLogbackApplication           : info
2022-04-10 02:17:26.353  WARN 6372 --- [  restartedMain] c.b.s.SpringLogbackApplication           : warn
2022-04-10 02:17:26.354 ERROR 6372 --- [  restartedMain] c.b.s.SpringLogbackApplication           : error
```

Now, let's configure it to run using `production` profile. To do so, update `application.properties` to indicate the profile to use

```
spring.profiles.active=production
```

And the logs would now look like

```
2022-04-10 02:31:51.306  INFO 13476 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2022-04-10 02:31:51.326  WARN 13476 --- [  restartedMain] c.b.s.SpringLogbackApplication           : warn
2022-04-10 02:31:51.326 ERROR 13476 --- [  restartedMain] c.b.s.SpringLogbackApplication           : error
```

As you can see, Spring Logback `Profile Specific Configuration` feature makes it easy for us to configure different sets of rules for each profile and it will automatically be applied based on the environment you have deployed it to.

# Output logs in JSON format

One of our objective is to ensure that we can pipe the logs to `JSON` appender instead of the `CONSOLE` appender in production. But how can we do that?

Let me introduce you to [logstash-logback-encoder](https://github.com/logfellow/logstash-logback-encoder) library. Add the following to your Gradle/Maven config

```
// gradle
implementation 'net.logstash.logback:logstash-logback-encoder:7.0.1'

// maven
<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>7.0.1</version>
</dependency>
```

And then head back to `logback-spring.xml` and add the following

```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- Added this section -->
    <!-- Create a appender to output JSON log format -->
    <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
    </appender>
    <!-- omitted --> 
</configuration>
```

Perfect, let's also update our configuration to switch the `production` profile log to use `JSON` appender

```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<!-- omitted -->

    <springProfile name="production">
        <logger name="com.bwgjoseph.springlogback" additivity="false" level="warn">
            <!-- switched to JSON from CONSOLE -->
            <appender-ref ref="JSON" />
        </logger>
		
		<root level="INFO">
            <!-- switched to JSON from CONSOLE -->
            <appender-ref ref="JSON" />
        </root>
    </springProfile>

</configuration>
```

And the result is...

```
2022-04-10 02:42:56.796  INFO 15268 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
{"@timestamp":"2022-04-10T02:42:56.796+08:00","@version":"1","message":"Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable","logger_name":"org.springframework.boot.devtools.env.DevToolsPropertyDefaultsPostProcessor","thread_name":"restartedMain","level":"INFO","level_value":20000}
2022-04-10 02:42:57.578  INFO 15268 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
{"@timestamp":"2022-04-10T02:42:57.578+08:00","@version":"1","message":"LiveReload server is running on port 35729","logger_name":"org.springframework.boot.devtools.autoconfigure.OptionalLiveReloadServer","thread_name":"restartedMain","level":"INFO","level_value":20000}
{"@timestamp":"2022-04-10T02:42:57.608+08:00","@version":"1","message":"warn","logger_name":"com.bwgjoseph.springlogback.SpringLogbackApplication","thread_name":"restartedMain","level":"WARN","level_value":30000}
{"@timestamp":"2022-04-10T02:42:57.609+08:00","@version":"1","message":"error","logger_name":"com.bwgjoseph.springlogback.SpringLogbackApplication","thread_name":"restartedMain","level":"ERROR","level_value":40000}
```

Cool, how easy was it? All it took was to just add `logstash-logback-encoder` library and configure a `JSON` appender and use it. 

But, have you noticed something weird about the logs? You probably have, and that there are now two different type of log format `CONSOLE and JSON` but why is that happening? It turns out that we have this line under `configuration` tag in our configuration which brings in a number of default configurations including a root logger configuration

```xml
<include resource="org/springframework/boot/logging/logback/base.xml" />
```

If you are using `VSCode` (or any other IDE), you can see from the dependencies project, and what exactly was defined in `base.xml` or you can view it directly from [spring-boot-github](https://github.com/spring-projects/spring-boot/blob/main/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback/base.xml)

![image.png](https://cdn.hashnode.com/res/hashnode/image/upload/v1649530178842/vkRFrPo27.png)

I extracted the content for your convenience (based on `spring-boot-2.6.6`)

```xml
<included>
	<include resource="org/springframework/boot/logging/logback/defaults.xml" />
	<property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}}/spring.log}"/>
	<include resource="org/springframework/boot/logging/logback/console-appender.xml" />
	<include resource="org/springframework/boot/logging/logback/file-appender.xml" />
	<root level="INFO">
		<appender-ref ref="CONSOLE" />
		<appender-ref ref="FILE" />
	</root>
</included>
```

Notice the root logger have been configured with `CONSOLE` and `FILE` appender and because root logger is [cumulative](https://logback.qos.ch/manual/configuration.html#cumulative), the merged logback config would look something like (based on my understanding) in your `logback-spring.xml`

```xml
<springProfile name="production">
	<logger name="com.bwgjoseph.springlogback" additivity="false" level="warn">
		<appender-ref ref="JSON" />
	</logger>
	<root level="info">
        <!-- merged from base.xml -->
		<appender-ref ref="CONSOLE" />
		<appender-ref ref="FILE" />
		<appender-ref ref="JSON" />
	</root>
</springProfile>
```

And that is probably the cause of why there are multiple type of logs being shown. 

# Solve conflicting root appender

The fix is easy; move `base.xml` resource to `default` profile

```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<!-- omitted -->

    <springProfile name="default">
        <!-- Moved base.xml from above into here -->
        <include resource="org/springframework/boot/logging/logback/base.xml" />

        <logger name="com.bwgjoseph.springlogback" additivity="false" level="debug">
            <appender-ref ref="CONSOLE" />
        </logger>

        <root level="INFO">
            <appender-ref ref="CONSOLE" />
        </root>
    </springProfile>
	
	<!-- omitted -->

</configuration>
``` 

This way, whatever that was defined in `default` profile will not affect `production` profile. The downside is that `production` profile can no longer use `CONSOLE` appender but that's okay, since we only want to log out as `JSON`.

# Can we do better?

Yes, we definitely can do better

According to [spring-boot-docs](https://docs.spring.io/spring-boot/docs/current/reference/html/howto.html#howto.logging.logback), `base.xml` was added for `compatibility/legacy` reason although I'm not entirely sure what is the use-case for that. We can safely assume that we don't need that, hence, we can just pick and choose what we need and then include it in our `logback-spring.xml` configuration.

In our case, we just need `default.xml` and `console-appender.xml` which would not have brought in `root logger` configuration

```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<!-- omitted -->

    <springProfile name="default">
        <!-- Replace this 2 lines with the base.xml -->
        <include resource="org/springframework/boot/logging/logback/defaults.xml" />
        <include resource="org/springframework/boot/logging/logback/console-appender.xml" />

	<!-- omitted -->

</configuration>
```

> So far, I am unable to figure out if there is a way to override the `root logger` and remove just the `appender`. If you know how, please comment below!

After we have updated the configuration, let's run the application again to see if we have everything configured to what we desired for

```
{"@timestamp":"2022-04-10T16:57:59.853+08:00","@version":"1","message":"Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable","logger_name":"org.springframework.boot.devtools.env.DevToolsPropertyDefaultsPostProcessor","thread_name":"restartedMain","level":"INFO","level_value":20000}
{"@timestamp":"2022-04-10T16:58:00.679+08:00","@version":"1","message":"LiveReload server is running on port 35729","logger_name":"org.springframework.boot.devtools.autoconfigure.OptionalLiveReloadServer","thread_name":"restartedMain","level":"INFO","level_value":20000}
{"@timestamp":"2022-04-10T16:58:00.703+08:00","@version":"1","message":"warn","logger_name":"com.bwgjoseph.springlogback.SpringLogbackApplication","thread_name":"restartedMain","level":"WARN","level_value":30000}
{"@timestamp":"2022-04-10T16:58:00.703+08:00","@version":"1","message":"error","logger_name":"com.bwgjoseph.springlogback.SpringLogbackApplication","thread_name":"restartedMain","level":"ERROR","level_value":40000}
```

Congratulation! This time, it is without the extra `CONSOLE` appender log message

> Note: this would have worked even if `defaults.xml` and `console-appender.xml` was placed outside of `springProfile` tag

# Conclusion

We have looked at how to use `Spring Profile in Logback` to define different set of rules and configuration for each of the profile, how to output the logs in `JSON` format using `logstash-logback-encoder` and finally, how to resolve conflicting configs when we include configuration provided by `spring-boot`

Reading through the documentation of `spring-boot` and `logback` certainly helped further my understanding especially on the part where root logger are [cumulative](https://logback.qos.ch/manual/configuration.html#cumulative) and it kind of cleared up my confusion as to why the different type of logs are shown even though we did not explicitly configured for it

# Source Code

Full source code is available in [GitHub](https://github.com/bwgjoseph/tutorials/tree/main/spring-logback)

# Resources

- [Configure Logback for Logging](https://docs.spring.io/spring-boot/docs/current/reference/html/howto.html#howto.logging.logback)
- [Logback Extensions](https://docs.spring.io/spring-boot/docs/current/reference/html/features.html#features.logging.logback-extensions)
- [Appenders are accumulative](https://logback.qos.ch/manual/configuration.html#cumulative)