Log4j2 programmatic JdbcAppender ColumnConfig lookup not working

Question

My application runs on top of Spring-Boot (Vaadin) and uses a configuration class (see below) to programmatically configure Log4j's JdbcAppender.

In addition to the JdbcAppender a ConsoleAppender is configured via the XML file (see below).

Both appenders use a lookup plugin (see below) which should trigger the user name. The ConsoleAppender works fine and the username is printed in the log after login.

Problem: the JdbcAppender unfortunately does not resolve the lookup. In the database column there is only "$${app:username}".

1. configuration class:

@Configuration
public class LogConfiguration {

    private final Environment environment;

    public LogConfiguration(Environment environment) {
        this.environment = environment;
    }

    @PostConstruct
    public void onStartUp() {
        String url = Objects.requireNonNull(environment.getProperty("database.url"));
        String username = Objects.requireNonNull(environment.getProperty("database.username"));
        String password = Objects.requireNonNull(environment.getProperty("database.password"));

        ColumnConfig[] columnConfigs = new ColumnConfig[5];
        columnConfigs[0] = ColumnConfig.newBuilder()
                .setName("logger")
                .setPattern("%logger")
                .setUnicode(false)
                .build();
        columnConfigs[1] = ColumnConfig.newBuilder()
                .setName("level")
                .setPattern("%level")
                .setUnicode(false)
                .build();
        columnConfigs[2] = ColumnConfig.newBuilder()
                .setName("message")
                .setPattern("%message")
                .setUnicode(false)
                .build();
        columnConfigs[3] = ColumnConfig.newBuilder()
                .setName("exception")
                .setPattern("%ex{full}")
                .setUnicode(false)
                .build();
        columnConfigs[4] = ColumnConfig.newBuilder()
                .setName("revision_id")
                .setPattern("%X{rev.id}")
                .setUnicode(false)
                .build();
        columnConfigs[8] = ColumnConfig.newBuilder()
                .setName("username")
                .setPattern("$${app:username}")
                .setUnicode(false)
                .build();

        ConnectionSource connectionSource = DriverManagerConnectionSource.newBuilder()
                .setDriverClassName("org.postgresql.Driver")
                .setConnectionString(url)
                .setUserName(username.toCharArray())
                .setPassword(password.toCharArray())
                .build();

        ColumnMapping[] columnMappings = new ColumnMapping[1];
        columnMappings[0] = ColumnMapping.newBuilder()
                .setName("created_at")
                .setLiteral("now()")
                .setType(OffsetDateTime.class)
                .build();

        JdbcAppender appender = JdbcAppender.newBuilder()
                .setTableName("logs")
                .setConnectionSource(connectionSource)
                .setName("Database")
                .setIgnoreExceptions(true)
                .setBufferSize(1)
                .setColumnConfigs(columnConfigs)
                .setColumnMappings(columnMappings)
                .setFilter(ThresholdFilter.createFilter(Level.INFO, Filter.Result.ACCEPT, Filter.Result.DENY))
                .build();

        appender.start();
        Logger logger = (Logger) LogManager.getRootLogger();
        logger.addAppender(appender);
    }

}

2. xml configuration

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss} %-5level - %msg$${app:username}%n"/><!-- %logger{36} -->
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.stackoverflow" level="info" additivity="true"/>
        <Root level="warn">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

3. lookup plugin

@Plugin(name = "app", category = StrLookup.CATEGORY)
public class UsernameLookup implements StrLookup {

    @Override
    public String lookup(String key) {
        return username();
    }

    @Override
    public String lookup(LogEvent event, String key) {
        return username();
    }

    private String username() {
        User user = SecurityUtils.getUser();
        if(user == null) {
            return "";
        }

        return " (" + user.getUsername() + ")";
    }

}

Answer 1

The reason for the programmatic configuration was that some data is only available at runtime. I have now circumvented this problem with two configuration files. One configuration file is loaded automatically as default and the other one is then loaded within a Spring Configuration. Additionally, a new Maven dependency is used to load values from the Spring Boot Configuration.

1. log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss} %-5level - %msg$${app:username}%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.stackoverflow" level="info" additivity="true"/>
        <Root level="warn">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

2. log4j2-full.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss} %-5level - %msg$${app:username}%n"/><!-- %logger{36} -->
        </Console>
        <JDBC name="Database" tableName="logs" bufferSize="1">
            <DriverManager connectionString="${spring:database.url}"
                           driverClassName="org.postgresql.Driver"
                           username="${spring:database.username}"
                           password="${spring:database.password}" />
            <Column name="created_at" isEventTimestamp="true" isUnicode="false" />
            <Column name="logger" pattern="%logger" isUnicode="false" />
            <Column name="level" pattern="%level" isUnicode="false" />
            <Column name="message" pattern="%message" isUnicode="false" />
            <Column name="exception" pattern="%ex{full}" isUnicode="false" />
            <Column name="username" pattern="$${app:username}" isUnicode="false" />
        </JDBC>
    </Appenders>
    <Loggers>
        <Logger name="com.stackoverflow" level="info" additivity="true"/>
        <Root level="warn">
            <AppenderRef ref="Console"/>
            <AppenderRef ref="Database"/>
        </Root>
    </Loggers>
</Configuration>

3. configuration class

@Configuration
public class LogConfiguration {

    public LogConfiguration() throws URISyntaxException {
        ClassLoader classLoader = LogConfiguration.class.getClassLoader();
        URL resource = classLoader.getResource("log4j2-full.xml");

        if (resource != null) {
            Configurator.reconfigure(resource.toURI());
            log.info("Verbindung zur Datenbank hergestellt. Starte parallele Protokollierung in die Datenbank...");
        }
    }

}