logback dbappender performance

Question

I am looking to use Logback Classic DB Appender (ch.qos.logback.classic.db.DBAppender) in the application. Database is Sybase ASE. I use c3p0 connection pool.

Besides the DB appender, I also have a rolling file appender. Problem is, with the DB Appender I see a drastic decrease in performance. For instance, with only rolling file appender, it takes 13 ms (milli seconds) to log the messages to file. However, with rolling file appender and db appender together, it takes 4510 ms (4.5 seconds) to output the same set of messages to file and database.

Logback DBAppender document mentions that with c3p0 connection pool, it takes around 1ms to insert a single logging statement. Numbers I am seeing are thousand times more than that. Wonder what could be wrong. Following is my logback.xml file:

<configuration debug="true" scan="true">

    <property resource="log.properties" />

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.file.dir}/${project.artifactId}.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- daily rollover -->
            <fileNamePattern>${project.artifactId}.%d{yyyy-MM-dd}.log</fileNamePattern>
            <!-- keep 30 days' worth of history -->
            <maxHistory>${log.file.rolling.history.days}</maxHistory>
        </rollingPolicy>

        <encoder>
            <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="DB" class="ch.qos.logback.classic.db.DBAppender">
        <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
            <dataSource class="com.mchange.v2.c3p0.ComboPooledDataSource">
                <driverClass>${log.db.driver}</driverClass>
                <jdbcUrl>jdbc:sybase:Tds:${log.db.server}:${log.db.port}/${log.db.name}</jdbcUrl>
                <serverName>${log.db.server}</serverName>
                <databaseName>${log.db.name}</databaseName>
                <user>${log.db.user}</user>
                <password>${log.db.password}</password>
            </dataSource>
        </connectionSource>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="FILE" />
    </root>

</configuration>

Any pointers appreciated.

Thanks.

Can you create a reference test case adding the same amount of data using plain JDBC, each record in a separate transaction? I don't think Logback adds any significant overhead, so it would be interesting to see how fast it can be done directly. — Tomasz Nurkiewicz

Mavlarn Mavlarn · Accepted Answer · 2012-03-27T02:15:03

I found the following from logback manual:

If your JDBC driver supports the getGeneratedKeys method introduced in JDBC 3.0 specification, assuming you have created the appropriate database tables as mentioned above, then no more steps are required, except for the usual logback configuration.

Otherwise, there must be an SQLDialect appropriate for your database system. Currently, we have dialects for PostgreSQL, MySQL, Oracle and MS SQL Server.

for oracle, it said the supported version is :(10.2.0.1)

link: http://logback.qos.ch/manual/appenders.html#DBAppender

If you have no a Dialect class in your JDBC driver, you can get from hibernate, and put it in your source, I don't know whether it can work.

logback dbappender performance

1 Answers