Spring Boot中Log4j2 JDBC Appender写入PostgreSQL失败问题

我尝试用Log4j2把日志写入PostgreSQL指定表，但启动Spring Boot项目时触发以下错误，且错误消息在控制台循环输出，陷入死循环。

错误日志 #

2023-03-12 11:26:06,380 main ERROR Unable to write to database [JdbcManager{name=jdbcAppender, bufferSize=0, tableName=logs, columnConfigs=[{ name=date, layout=null, literal=null, timestamp=true }, { name=level, layout=%level, literal=null, timestamp=false }, { name=message, layout=%message, literal=null, timestamp=false }, { name=class, layout=%class, literal=null, timestamp=false }], columnMappings=[]}] for appender [jdbcAppender]. org.apache.logging.log4j.core.appender.db.DbAppenderLoggingException: Failed to insert record for log event in JDBC manager: java.sql.SQLFeatureNotSupportedException: Method org.postgresql.jdbc.PgPreparedStatement.setNString(int, String) is not yet implemented. [columnConfigs=[{ name=date, layout=null, literal=null, timestamp=true }, { name=level, layout=%level, literal=null, timestamp=false }, { name=message, layout=%message, literal=null, timestamp=false }, { name=class, layout=%class, literal=null, timestamp=false }], sqlStatement=insert into logs (date,level,message,class) values (?,?,?,?), factoryData=FactoryData [connectionSource=factory{ public static java.sql.Connection com.pouya.logfix.LogsConfgi.getDatabaseConnection() }, tableName=logs, columnConfigs=[{ name=date, layout=null, literal=null, timestamp=true }, { name=level, layout=%level, literal=null, timestamp=false }, { name=message, layout=%message, literal=null, timestamp=false }, { name=class, layout=%class, literal=null, timestamp=false }], columnMappings=[], immediateFail=false, retry=true, reconnectIntervalMillis=5000, truncateStrings=true], connection=jdbc:postgresql://localhost:5000/postgres, UserName=postgres, PostgreSQL JDBC Driver, statement=insert into logs (date,level,message,class) values ('2023-03-12 11:26:06.373+03:30',?,?,?), reconnector=null, isBatchSupported=true, columnMetaData={DATE=ColumnMetaData [schemaName=, catalogName=, tableName=logs, name=date, nameKey=DATE, label=date, displaySize=255, type=12, typeName=varchar, className=java.lang.String, precision=255, scale=0, isStringType=true], MESSAGE=ColumnMetaData [schemaName=, catalogName=, tableName=logs, name=message, nameKey=MESSAGE, label=message, displaySize=2147483647, type=12, typeName=text, className=java.lang.String, precision=2147483647, scale=0, isStringType=true], LEVEL=ColumnMetaData [schemaName=, catalogName=, tableName=logs, name=level, nameKey=LEVEL, label=level, displaySize=255, type=12, typeName=varchar, className=java.lang.String, precision=255, scale=0, isStringType=true], CLASS=ColumnMetaData [schemaName=, catalogName=, tableName=logs, name=class, nameKey=CLASS, label=class, displaySize=255, type=12, typeName=varchar, className=java.lang.String, precision=255, scale=0, isStringType=true]}]
    at org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.writeInternal(JdbcDatabaseManager.java:871)
    at org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.writeThrough(JdbcDatabaseManager.java:898)
    at org.apache.logging.log4j.core.appender.db.AbstractDatabaseManager.write(AbstractDatabaseManager.java:298)
    at org.apache.logging.log4j.core.appender.db.AbstractDatabaseAppender.append(AbstractDatabaseAppender.java:110)
    at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:134)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125)
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
    at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:675)
    at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:633)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:616)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:552)
    at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
    at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
    at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2205)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2159)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2142)
    at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2022)
    at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1875)
    at org.apache.commons.logging.LogAdapter$Log4jLog.log(LogAdapter.java:266)
    at org.apache.commons.logging.LogAdapter$Log4jLog.debug(LogAdapter.java:240)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:213)
    at org.springframework.context.support.PostProcessorRegistrationDelegate.registerBeanPostProcessors(PostProcessorRegistrationDelegate.java:270)
    at org.springframework.context.support.AbstractApplicationContext.registerBeanPostProcessors(AbstractApplicationContext.java:762)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:567)
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:147)
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:731)
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:408)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:307)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1303)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1292)
    at com.pouya.logfix.LogfixApplication.main(LogfixApplication.java:26)
Caused by: java.sql.SQLFeatureNotSupportedException: Method org.postgresql.jdbc.PgPreparedStatement.setNString(int, String) is not yet implemented.
    at org.postgresql.Driver.notImplemented(Driver.java:731)
    at org.postgresql.jdbc.PgPreparedStatement.setNString(PgPreparedStatement.java:1522)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.setNString(DelegatingPreparedStatement.java:238)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.setNString(DelegatingPreparedStatement.java:238)
    at org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.writeInternal(JdbcDatabaseManager.java:850)
    ... 33 more

当前配置文件（log4j2-spring.xml） #

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Appenders>
        <Console name="STDOUT" target="SYSTEM_OUT">
            <PatternLayout pattern="%m%n"/>
        </Console>

        <JDBC name="jdbcAppender" tableName="logs">
            <ConnectionFactory class="com.pouya.logfix.LogsConfig" method="getDatabaseConnection"/>
            <Column name="date" isEventTimestamp="true"/>
            <Column name="level" pattern="%level"/>
            <Column name="message" pattern="%message"/>
            <Column name="class" pattern="%class"/>
        </JDBC>
    </Appenders>
    <Loggers>
        <Root level="debug">
            <!--<AppenderRef ref="databaseAppender"/>-->
            <AppenderRef ref="STDOUT"/>
            <AppenderRef ref="jdbcAppender"/>
        </Root>
    </Loggers>
</Configuration>

数据库连接配置类（LogsConfig.java） #

public class LogsConfig {

    private static interface Singleton {
            final LogsConfig INSTANCE = new LogsConfig();
    }

    private final DataSource dataSource;

    private LogsConfig() {
            
            try {
                    Class.forName("org.postgresql.Driver");
            } catch (ClassNotFoundException e) {
                    e.printStackTrace();
                    System.exit(0);
            }

            Properties properties = new Properties();
            properties.setProperty("user", "postgres");
            properties.setProperty("password", "password");

            GenericObjectPool<PoolableConnection> pool = new GenericObjectPool<PoolableConnection>();
            DriverManagerConnectionFactory connectionFactory = new DriverManagerConnectionFactory(
                    "jdbc:postgresql://localhost:5000/postgres", properties
            );
            new PoolableConnectionFactory(connectionFactory, pool, null, "SELECT 1", 3, false, false, Connection.TRANSACTION_READ_COMMITTED);
            this.dataSource = new PoolingDataSource(pool);
    }

    public static Connection getDatabaseConnection() throws SQLException {
            var dt = Singleton.INSTANCE.dataSource.getConnection();
            return dt;
    }
}

环境版本 #

• Spring Boot 2.7.9
• PostgreSQL驱动42.5.4

原因分析 #

核心问题有两个：

1. 写入失败：Log4j2的JDBC Appender自动检测到数据库列是字符串类型时，默认调用setNString方法，但PostgreSQL JDBC驱动配合Apache Commons DBCP连接池时不支持该方法，导致日志写入失败。
2. 死循环：日志写入失败后，Log4j2会生成错误日志，而错误日志又会触发JDBC Appender的写入逻辑，形成无限循环。

解决方法 #

方法1：显式指定字符串列类型（快速修复） #

在Log4j2配置中，给每个字符串类型的Column添加type="VARCHAR"属性，强制Log4j2使用setString方法而非setNString：

<JDBC name="jdbcAppender" tableName="logs">
    <ConnectionFactory class="com.pouya.logfix.LogsConfig" method="getDatabaseConnection"/>
    <Column name="date" isEventTimestamp="true"/>
    <Column name="level" pattern="%level" type="VARCHAR"/>
    <Column name="message" pattern="%message" type="VARCHAR"/>
    <Column name="class" pattern="%class" type="VARCHAR"/>
</JDBC>

方法2：替换连接池为HikariCP（推荐） #

Apache Commons DBCP对JDBC规范的兼容性较差，改用Spring Boot默认的HikariCP连接池可以彻底避免这类问题：

1. 移除项目中Commons DBCP的相关依赖
2. 修改LogsConfig类为HikariCP实现：

public class LogsConfig {

    private static interface Singleton {
        final LogsConfig INSTANCE = new LogsConfig();
    }

    private final DataSource dataSource;

    private LogsConfig() {
        HikariConfig config = new HikariConfig();
        config.setJdbcUrl("jdbc:postgresql://localhost:5000/postgres");
        config.setUsername("postgres");
        config.setPassword("password");
        config.setDriverClassName("org.postgresql.Driver");
        // 可添加其他HikariCP配置，如连接池大小等
        this.dataSource = new HikariDataSource(config);
    }

    public static Connection getDatabaseConnection() throws SQLException {
        return Singleton.INSTANCE.dataSource.getConnection();
    }
}

注意：Spring Boot项目默认已包含HikariCP依赖，无需额外引入。

方法3：临时终止死循环 #

如果需要先停止循环再处理根本问题，可以：

• 在JDBC Appender中添加immediateFail="true"，关闭自动重试
• 降低Root日志级别到info，减少启动时的日志输出量

<JDBC name="jdbcAppender" tableName="logs" immediateFail="true">
    <!-- 其他配置 -->
</JDBC>
<Root level="info">
    <AppenderRef ref="STDOUT"/>
    <AppenderRef ref="jdbcAppender"/>
</Root>

此方法仅能临时解决循环问题，需配合前两种方法彻底修复写入错误。

内容的提问来源于stack exchange，提问作者Pouya Kermanshahi