[
https://issues.apache.org/jira/browse/LOG4J2-2667?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16900356#comment-16900356
]
Gary Gregory commented on LOG4J2-2667:
--------------------------------------
[~epmchui],
Thank you for attaching a project to reproduce the issue.
The first problem is that your configuration uses a class that does not exist:
{{java.sql.Types.TIMESTAMP}}. You must have meant {{java.sql.Timestamp}}.
Beyond that, this could be a bug in the SQLite JDBC Driver:
- When an event comes in the JDBC appender, we call JDBC's
{{PreparedStatement#set}} for each configured column.
- Then we call JDBC's {{PreparedStatement#addBatch()}} build a list of
{{INSERT}} statements to send to the database.
- We do this for each event that comes in until a threshold is met and the
whole batch is sent to the database in one go. Buy, it looks like we do not
really make good use of batching since all of our batches seem to be of size
one, nevertheless we use the batch API.
The appender only uses batching if the driver says it supports it, which this
SQLite driver says it does. But, when the appender calls
{{PreparedStatement#clearParameters()}} on this driver, there is a mismatch in
expectations in how the SQLite bit field {{paramValid}} is used in the driver
which causes the exception you describe.
I tried using the latest version of the JDBC Driver (3.28.0) but that does not
help.
The only thing I can think to do on the Log4j side is to add a setting to
forcibly disable batching even when the driver says it supports it. This would
cause the appender to immediately execute SQL INSERT statements instead of
batching them.
> "Values not bound to statement" when using JDBC appender
> ---------------------------------------------------------
>
> Key: LOG4J2-2667
> URL: https://issues.apache.org/jira/browse/LOG4J2-2667
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders, Core
> Affects Versions: 2.11.2, 2.12.0
> Environment: Oracle Java 11.0.3, Windows Server 2016, Spring Boot
> 2.1.6
> Reporter: Edith Chui
> Priority: Major
> Attachments: log4j2.issue.zip
>
>
>
> Since version 2.11.2, the log4j2 library was unable to log message on
> database via JDBC connection. When using 2.11.1, no such problem was found.
> root cause:
> In org.sqlite.core.CorePreparedStatement, below function was called, but
> paramValid local variable is not initialized. Value of
> "paramValid.cardinality()" is always 0 which does not match with the total
> number of parameter.
>
> {code:java}
> protected void checkParameters() throws SQLException
> {
> if (paramValid.cardinality() != paramCount)
> throw new SQLException("Values not bound to statement");
> }
> {code}
>
> Sample appender in log4j2.xml
> {code:java}
> <JDBC name="jdbcAppender" tableName="LOG_TABLE" bufferSize="0">
> <ConnectionFactory class="MY.SQLiteConnectionFactory"
> method="getDatabaseConnection" />
> <ColumnMapping name="FIELD1" type="java.lang.Integer" pattern="%X{FIELD1}"
> />
> <ColumnMapping name="FIELD2" type="java.lang.String" pattern="%X{FIELD2}" />
> <ColumnMapping name="FIELD3" type="java.lang.String" pattern="%X{FIELD3}" />
> <ColumnMapping name="FIELD4" type="java.sql.Types.TIMESTAMP"
> pattern="%d{yyyy-MM-dd HH:mm:ss.SSS}" />
> </JDBC>{code}
>
> {panel:title=Exception Log}
> 2019-08-02 15:57:45,483 main ERROR An exception occurred processing Appender
> jdbcAppender
> org.apache.logging.log4j.core.appender.db.DbAppenderLoggingException: Failed
> to commit transaction logging event or flushing buffer.
> at
> org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.commitAndClose(JdbcDatabaseManager.java:552)
> at
> org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.writeThrough(JdbcDatabaseManager.java:867)
> at
> org.apache.logging.log4j.core.appender.db.AbstractDatabaseManager.write(AbstractDatabaseManager.java:264)
> at
> org.apache.logging.log4j.core.appender.db.AbstractDatabaseAppender.append(AbstractDatabaseAppender.java:110)
> at
> org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:464)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:448)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:431)
> at
> org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:406)
> at
> org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
> at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
> at
> org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2170)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2125)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2108)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2007)
> at
> org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1866)
> at org.apache.logging.slf4j.Log4jLogger.info(Log4jLogger.java:179)
> ...
> Caused by: java.sql.SQLException: Values not bound to statement
> at
> org.sqlite.core.CorePreparedStatement.checkParameters(CorePreparedStatement.java:71)
> at
> org.sqlite.core.CorePreparedStatement.executeBatch(CorePreparedStatement.java:83)
> at
> org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.commitAndClose(JdbcDatabaseManager.java:545)
> ...
> {panel}
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
