[
https://issues.apache.org/jira/browse/LOG4J2-2667?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16901675#comment-16901675
]
Edith Chui edited comment on LOG4J2-2667 at 8/7/19 4:02 AM:
------------------------------------------------------------
Extracted the SQLite code,
org.apache.logging.log4j.core.appender.db.AbstractDatabaseManager.flush()
{code:java}
@Override
public final synchronized void flush() {
if (this.isRunning() && isBuffered()) {
this.connectAndStart();
try {
for (final LogEvent event : this.buffer) {
this.writeInternal(event, layout != null ? layout.toSerializable(event) :
null);
}
} finally {
this.commitAndClose();
// not sure if this should be done when writing the events failed
this.buffer.clear();
}
}
}{code}
The paramValid was forcibly cleared in writeInternal() function. Since the
whole logging action is still not finished and is waiting to be committed to
database in commitAndClose(), that means paramValid is still in use by JDBC
driver. It is not a right moment to clear the parameter as the whole operation
is not came to the end.
I am not sure what is the impact of reverting the code of LOG4J2-2489. Is there
other solution to release the resource right after all things are done?
Note (LOG4J2-2489):
org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.writeInternal(LogEvent,
Serializable)
finally {
// Release ASAP
try
{ statement.clearParameters(); }
catch (final SQLException e)
{ // Ignore }
Closer.closeSilently(reader);
}
was (Author: epmchui):
Extracted the SQLite code,
org.apache.logging.log4j.core.appender.db.AbstractDatabaseManager.flush()
{code:java}
@Override
public final synchronized void flush() {
if (this.isRunning() && isBuffered()) {
this.connectAndStart();
try {
for (final LogEvent event : this.buffer) {
this.writeInternal(event, layout != null ? layout.toSerializable(event) :
null);
}
} finally {
this.commitAndClose();
// not sure if this should be done when writing the events failed
this.buffer.clear();
}
}
}{code}
The paramValid was forcibly clear in writeInternal() function. Since the whole
logging action is still not finished and is waiting to be committed to database
in commitAndClose(), that means paramValid is still in use by JDBC driver. It
is not a right moment to clear the parameter as the whole operation is not came
to the end.
I am not sure what is the impact if reverting the code of LOG4J2-2489. Is there
other solution to release the resource right after all things are done?
Note (LOG4J2-2489):
org.apache.logging.log4j.core.appender.db.jdbc.JdbcDatabaseManager.writeInternal(LogEvent,
Serializable)
finally {
// Release ASAP
try {
statement.clearParameters();
} catch (final SQLException e) {
// Ignore
}
Closer.closeSilently(reader);
}
> "Values not bound to statement" when using JDBC appender, appender does not
> respect bufferSize="0".
> ---------------------------------------------------------------------------------------------------
>
> 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
> Assignee: Gary Gregory
> Priority: Major
> Fix For: 3.0.0, 2.12.1
>
> 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)
