Asynchronous DBAppender with logback

2019-02-11 02:50发布

问题:

I'm working on an application that uses logback for logging. I used the logback DBAppender to insert logs into DB.

All worked great for me and i was able to insert and see the logs into the Database.

I did some testing with 200 logging line of code and measured the time consumption for those 200 logs and got 10 milliseconds without using the DBAppender. When i added the DBAppender i got around 2700 milliseconds.

I tried to use the ch.qos.logback.classic.AsyncAppender with no luck making it work asynchronously. I always get 0 results inserted into my database.

My configuration looks like the below:

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true"> 

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

    <appender name="DBAppPostgreSQL" class="ch.qos.logback.classic.db.DBAppender">
        <connectionSource class="ch.qos.logback.core.db.DriverManagerConnectionSource">
            <dataSource class="com.mchange.v2.c3p0.ComboPooledDataSource">
                  <driverClass>org.postgresql.Driver</driverClass>
                  <url>jdbc:postgresql://127.0.0.1:5678/DB</url>
                  <user>YYYYY</user>
                  <password>XXX</password>
            </dataSource>
        </connectionSource>
        <sqlDialect class="ch.qos.logback.core.db.dialect.PostgreSQLDialect" />
        <insertHeaders>true</insertHeaders>
</appender>

    <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
            <appender-ref ref="DBAppPostgreSQL" />
            <includeCallerData>true</includeCallerData>
    </appender>

  <root level="debug">
      <appender-ref ref="ASYNC" />
      <appender-ref ref="STDOUT" />
  </root>
</configuration>

Is there anything missing with my configuration? Or is there any other way to make it insert logs into DB faster?

Note that i'm using postgreSQL

Thanks,

EDITED:

I'm using logback 1.0.11 over slf4j 1.7.5. Also i'm using postgresql 8.0.325.

The logback's internal status is:

10:52:09,693 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
10:52:09,693 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
10:52:09,693 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/D:/BOOM/BoomFinancial/BoomMonitoringTesting/bin/logback.xml]
10:52:09,759 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:52:09,761 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
10:52:09,771 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:52:09,800 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.db.DBAppender]
10:52:09,803 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [DBAppPostgreSQL]
10:52:09,809 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@14:75 - no applicable action for [dataSource], current pattern is [[configuration][appender][connectionSource][dataSource]]
10:52:09,866 |-INFO in ch.qos.logback.core.db.dialect.DBUtil@30e34726 - Could not call supportsGetGeneratedKeys method. This may be recoverable
10:52:09,866 |-INFO in ch.qos.logback.core.db.DriverManagerConnectionSource@195428dd - Driver name=PostgreSQL Native Driver
10:52:09,866 |-INFO in ch.qos.logback.core.db.DriverManagerConnectionSource@195428dd - Driver version=PostgreSQL 8.0 JDBC2 with NO SSL (build 325)
10:52:09,866 |-INFO in ch.qos.logback.core.db.DriverManagerConnectionSource@195428dd - supportsGetGeneratedKeys=false
10:52:09,867 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@21:77 - no applicable action for [sqlDialect], current pattern is [[configuration][appender][sqlDialect]]
10:52:09,868 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@22:21 - no applicable action for [insertHeaders], current pattern is [[configuration][appender][insertHeaders]]
10:52:09,870 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
10:52:09,872 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ASYNC]
10:52:09,872 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [DBAppPostgreSQL] to ch.qos.logback.classic.AsyncAppender[ASYNC]
10:52:09,872 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Attaching appender named [DBAppPostgreSQL] to AsyncAppender.
10:52:09,874 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Setting discardingThreshold to 51
10:52:09,874 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
10:52:09,875 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ASYNC] to Logger[ROOT]
10:52:09,875 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
10:52:09,875 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
10:52:09,876 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@23e0512a - Registering current configuration as safe fallback point

回答1:

There is one error message reported by logback:

0:52:09,809 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@14:75 - no applicable action for [dataSource], current pattern is [[configuration][appender][connectionSource][dataSource]]

This indicates that the element nested within could not be understood. Here is the relevant part of the configuration file:

<appender name="DBAppPostgreSQL" class="ch.qos.logback.classic.db.DBAppender">
  <!-- DriverManagerConnectionSource does not have a dataSource property -->
  <connectionSource class="ch.qos.logback.core.db.DriverManagerConnectionSource">
    <dataSource class="com.mchange.v2.c3p0.ComboPooledDataSource">
      <driverClass>org.postgresql.Driver</driverClass>
      <url>jdbc:postgresql://127.0.0.1:5678/DB</url>
      <user>YYYYY</user>
      <password>XXX</password>
    </dataSource>
  </connectionSource>
  <sqlDialect class="ch.qos.logback.core.db.dialect.PostgreSQLDialect" />
  <insertHeaders>true</insertHeaders>
</appender>

ch.qos.logback.core.db.DriverManagerConnectionSource does not have a dataSource property whereas ch.qos.logback.core.db.DataSourceConnectionSource does. You probably want to configure DBAppPostgreSQL with:

<appender name="DBAppPostgreSQL" class="ch.qos.logback.classic.db.DBAppender">
  <!-- use DataSourceConnectionSource instead of DriverManagerConnectionSource -->
  <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
    <dataSource class="com.mchange.v2.c3p0.ComboPooledDataSource">
      <driverClass>org.postgresql.Driver</driverClass>
      <url>jdbc:postgresql://127.0.0.1:5678/DB</url>
      <user>YYYYY</user>
      <password>XXX</password>
    </dataSource>
  </connectionSource>
  <sqlDialect class="ch.qos.logback.core.db.dialect.PostgreSQLDialect" />
  <insertHeaders>true</insertHeaders>
</appender>


回答2:

Thanks for the Ceki's answer. I can't comment it, so I'm adding a new answer: Ceki's answer contains one more thing which is incorrect: The element "url" should be replaced by "jdbcUrl". So the configuration should look like this:

<appender name="DBAppPostgreSQL" class="ch.qos.logback.classic.db.DBAppender">
  <!-- use DataSourceConnectionSource instead of DriverManagerConnectionSource -->
  <connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
    <dataSource class="com.mchange.v2.c3p0.ComboPooledDataSource">
      <driverClass>org.postgresql.Driver</driverClass>
      <jdbcUrl>jdbc:postgresql://127.0.0.1:5678/DB</jdbcUrl>
      <user>YYYYY</user>
      <password>XXX</password>
    </dataSource>
  </connectionSource>
  <sqlDialect class="ch.qos.logback.core.db.dialect.PostgreSQLDialect" />
  <insertHeaders>true</insertHeaders>
</appender>