Open Source RDBMS - Seamless, Scalable, Stable and Free

한국어 | Login |Register

Analyzing JDBC Logs with log4jdbc

First, let's clarify what exactly this log4jdbc is useful for. Assume you work on a project written in Java which communicates with CUBRID JDBC (or any other JDBC driver), and at some point you encounter some issues with your JDBC connections or SQL statements, which might be running surprisingly slow at the same time. Here log4jdbc would be very handy. Instead of adding tons of lines with System.out.println("Some Debug Message"), which later become difficult to manage, log4jdbc provides very easy to control methods with several level of importance.

For instance, at some point of a time you wish to see only error type of messages, at some - simple info type. When you debug you want to see debug type messages. With log4jdbc you can customize exactly what kind of messages you would like to see, and this can be easily configured at run-time as well. There is no need to recompile your project again.

In this tutorial we will show how to analyze CUBRID JDBC logs with log4jdbc in Eclipse environment.

Downloads

  • CUBRID 1.1 or higher
    Download the latest version of CUBRID Database, and follow the installation instructions.
  • Eclipse
    This is the environment we will use to develop our Java application. You can download it from www.eclipse.org/downloads.
  • log4jdbc
    log4jdbc is a Java JDBC driver that can log SQL and/or JDBC calls (and optionally SQL timing information) for different JDBC drivers using the SLF4J logging system, which provides APIs for interworking of logging service with log4jdbc. This is the main JAR library we need to analyse the CUBRID JDBC Driver.

    Download the latest version of log4jdbc compatible with JDK 1.5 or higher from http://code.google.com/p/log4jdbc/downloads/list. CUBRID JDBC supports JDK 1.5 and higher.

  • SLF4J
    log4jdbc uses the SLF4J (Simple Logging Facade for Java), a very simple and flexible small library which enables logging at runtime without modifying the application binary. Moreover users are free to pick any java logging systems such as Log4j, java.util logging in JDK 1.4, logback, Jakarta Commons Logging. In this tutorial we will be using Log4j as our logging system.

    SLF4J is distributed in zip archive which has many jar files in it. You will need only two of them:

    1. slf4j-api-1.5.0.jar or any other latest available version. This library will provide APIs for interworking of logging service with log4jdbc.
    2. slf4j-log4j12-1.5.2.jar or any latest version. This library will provide the implementation libraries for interworking of Log4j-based logging service with log4jdbc.
    Download the latest version of slf4j from http://www.slf4j.org/download.html.
  • log4j
    log4j is a Java logging system which we will use throughout our project.
    Download log4j from http://logging.apache.org/log4j/1.2/download.html.
    You will also need to download the sample log4j.xml configuration file so that you do not have to type all properties manually.
    Download the sample log4j.xml file from http://code.google.com/p/log4jdbc/source/browse/trunk/doc/log4j.xml.

Set up Eclipse Environment

Create Eclipse Project

If you have not created an Eclipse project, we need to have one set up. The Eclipse program does not require installation. Once you have downloaded the zip file, extract it and start the program.

When the program is launched, create a new Java project: File > New > Java Project as shown in the image below.

New Java Project

Give the project a name (ex.: CubridDB) and click the Finish button.

New CubridDB Java Project

In the Package Explorer panel on the left, right click on the src directory, and create new Java class.

New Java Class

Give the class the same name you gave to your project. Under Which method stubs would you like to create? select public static void main (String[] args).

New CubridDB Java Class

This should create an empty Java class for you with one static method.

Ready Eclipse Project

Add JAR Libraries

At this point you should have four JAR files: log4jdbc4-1.1.jar, slf4j-api-1.6.1.jar, slf4j-log4j12-1.6.1.jar, and apache-log4j-1.2.16.zip. We will need one more JAR file which is the CUBRID JDBC driver itself. It is usually located in c:CUBRIDjdbccubrid_jdbc.jar on Windows platform or in /opt/cubrid/jdbc on Linux.

We need to place all five JAR libraries to the project's Java Build Path. Right click on the project name in the Package Explorer panel on the left and choose the Properties.

Select the Java Build Path from the pop-up window and navigate to the Libraries tab.

Press the Add External JARs... button to add the five jars we need and click OK.

Add JAR Libraries

To validate all the steps we made up to now, run the project by pressing the keyboard combination Ctrl+F11. At this point the Console windows should be empty.

Add log4j.xml Configuration File to Classpath

The last step in our preparation is to set the log4j.xml configuration file to the project classpath. Copy this configuration file to the project root directory. In our case this is CubridDB directory. Before we continue, make sure you have built your project.

As in the previous step, right click on the project name in the Package Explorer panel on the left and choose the Properties.

Select the Run/Debug Settings from the pop-up window and double click on the project name. If you do not see your project name, it means you have not built it. Compile your project in that case.

Run/Debug Settings

In the pop-up window navigate to the Classpath tab.

Select your project name and click on Advanced... button.

Advanced Options

In the pop-up window choose the Add Folder option.

Folder Selection

In the Folder Selection window choose your project name and click OK.

Then again click OK to save the changes in your Classpath. And one more time press OK button.

Add System Properties

log4jdbc can analyze the JDBC drivers for all popular database systems. In our case we want to analyze the CUBRID JDBC Driver, so we need to set the following system properties to the project.

-Dlog4jdbc.drivers=cubrid.JDBC.driver.CUBRIDDriver

This property will be used in run-time by the log4jdbc.

As in the previous step, right click on the project name in the Package Explorer panel on the left and choose the Properties.

Select the Run/Debug Settings from the pop-up window and double click on the project name.

In the pop-up window navigate to the Arguments tab.

Copy the above setting to the VM arguments: field and press OK twice.

Add System Properties

log4jdbc Configuration

First, let's look at the sample log4j.xml configuration file. If you do not have it, see the Downloads section.


<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
 
<!-- An example log4j configuration xml file for log4jdbc -->
<!-- Logging levels are:                                  -->
<!-- DEBUG < INFO < WARN < ERROR < FATAL                  -->
 
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
 
  <appender name="stdout-appender" class="org.apache.log4j.ConsoleAppender">
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %5p %c{1}: %m%n"/>
    </layout>
  </appender>
 
  <appender name="sql-appender" class="org.apache.log4j.FileAppender">
    <param name="File" value="./logs/sql.log"/>
    <param name="Append" value="false"/>
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="-----> %d{yyyy-MM-dd HH:mm:ss.SSS} <%t> %m%n%n"/>
    </layout>
  </appender>
 
  <appender name="sql-timing-appender" class="org.apache.log4j.FileAppender">
    <param name="File" value="./logs/sqltiming.log"/>
    <param name="Append" value="false"/>
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="-----> %d{yyyy-MM-dd HH:mm:ss.SSS} %m%n%n"/>
    </layout>
  </appender>
 
  <appender name="jdbc-appender" class="org.apache.log4j.FileAppender">
    <param name="File" value="./logs/jdbc.log"/>
    <param name="Append" value="false"/>
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %m%n"/>
    </layout>
  </appender>
 
  <appender name="jdbc-connection" class="org.apache.log4j.FileAppender">
    <param name="File" value="./logs/connection.log"/>
    <param name="Append" value="false"/>
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %m%n"/>
    </layout>
  </appender>
 
  <!--
       The Following 5 logs can be turned on and off while the server is running
       LIVE in order to trace the SQL and/or all JDBC coming out of the application.
 
       To turn a log on, set the level value to INFO or DEBUG (to see class name and
       line number information in the log)  The DEBUG setting is much more inefficient
       but the output is much more useful.
 
       To turn off JDBC logging completely, you must set all 5 logs to a level higher 
       than ERROR (FATAL is suggested.)
  -->
 
  <!-- log SQL (pre-execution) plus exceptions caused by SQL -->
  <logger name="jdbc.sqlonly" additivity="false">
    <level value="debug"/>
    <appender-ref ref="sql-appender"/>
  </logger>
 
  <!-- log SQL with timing information, post execution -->
  <logger name="jdbc.sqltiming" additivity="false">
    <level value="fatal"/>
    <appender-ref ref="sql-timing-appender"/>
  </logger>
 
  <!-- only use the two logs below to trace ALL JDBC information,
       NOTE:  This can be very voluminous!  -->
 
  <!-- log all jdbc calls except ResultSet calls -->
  <logger name="jdbc.audit" additivity="false">
    <level value="fatal"/>
    <appender-ref ref="jdbc-appender"/>
  </logger>
 
  <!-- log the jdbc ResultSet calls -->
  <logger name="jdbc.resultset" additivity="false">
    <level value="fatal"/>
    <appender-ref ref="jdbc-appender"/>
  </logger>
  
  <!-- log connection open/close events and dump of all open connection numbers -->
  <logger name="jdbc.connection" additivity="false">
    <level value="fatal"/>
    <appender-ref ref="connection-appender"/>
  </logger>
 
  <!-- this log is for internal debugging of log4jdbc, itself -->
  <!-- debug logging for log4jdbc itself -->
  <logger name="log4jdbc.debug" additivity="false">
    <level value="debug"/>
    <appender-ref ref="stdout-appender"/>
  </logger>
 
  <!-- by default, log everything to the console with a level of WARN or higher -->
  <root>
    <level value="warn"/>
    <appender-ref ref="stdout-appender"/>
  </root>
</log4j:configuration>
  1. In log4j there are 5 logging levels: DEBUG < INFO < WARN < ERROR < FATAL. The value of DEBUG is the lowest, so when you set to log DEBUG level messages, log4j will log everything, including INFO, WARN, ERROR, and FATAL messages.
  2. You can see the <appender name="stdout-appender" class="org.apache.log4j.ConsoleAppender">. This element indicates the destination of logs.
    1. ConsoleAppender tell log4j to output all the messages to the console (in our case to the Eclipse console).
    2. FileAppender will save all the logs to the file indicated in the parameters like <param name="File" value="./logs/sql.log"/>. Thus, developer can save the log even to the remote server.
  3. You can give any arbitrary name to the appender such as stdout-appender. These names will be used later when we create different type of loggers.
  4. Inside the <appender> you will see the <layout class="org.apache.log4j.PatternLayout">. This tells log4j how to display the messages. You might want it to log the code line number where the message was logged, or you might want to log the exact time when the message was logged. This gives the developer high flexibility.
  5. In log4jdbc there are 5 different loggers: jdbc.sqlonly, jdbc.sqltiming, jdbc.audit, jdbc.resultset, jdbc.connection. In the configurations they are indicated as <logger name="jdbc.sqlonly" additivity="false">.
Logger name Description
JDBC.sqlonly Logs SQL statements only.

If it is PreparedStatement, there is a SQL statement that is configured as a related argument value.
JDBC.sqltimming Includes time information (in ms) used to execute a SQL statement and its corresponding SQL.
JDBC.audit Logs all JDBC call information except for ResultSet.

(Because a large number of logs is created, it is not recommended to use this logger except for tracing a specific JDBC error.)
JDBC.resultset Logs all JDBC call information, including ResultSet; a large number of logs is created.
JDBC.connection Logs open/close transactions for connections. (log4jdbc version 1.2alpha1 or later.)

If all 5 loggers are set to a level less than error (such as the FATAL level), then log4jdbc will not log anything and in fact the actual (real) connection to the underlying database will be returned by the log4jdbc driver (thus allowing log4jdbc to be installed and available to turn on at runtime at a moment's notice without imposing any actual performance loss when not being used). If any of the 5 logs are set to ERROR level or above (e.g ERROR,INFO or DEBUG) then log4jdbc will be activated, wrapping and logging activity in the JDBC connections returned by the underlying driver.

Each of these logs can be set at either DEBUG, INFO or ERROR level.

  • DEBUG includes the class name and line number (if available) at which the SQL was executed. Use DEBUG level with extra care, as this imposes an additional performance penalty when in use.
  • INFO includes the SQL (or other information as applicable.)
  • ERROR will show the stack traces in the log output when SQLExceptions occur.

To check SQL statements, configure JDBC.sqlonly to INFO level.

<logger name="jdbc.sqlonly" additivity="false">
  <level value="info"/>
  <appender-ref ref="sql-appender"/>
</logger>

If you want to know how long SQL statements have been executed, use JDBC.sqltiming.

<logger name="jdbc.sqltiming" additivity="false">
  <level value="fatal"/>
  <appender-ref ref="sql-timing-appender"/>
</logger>

Because Jdbc.audit, JDBC.resultset, or JDBC.connection creates a large number of logs, it is not recommended to use it except for a special case. In the log4jdbc example given above, it is shown how to use them.

In the default log4j.xml configurations given above, notice that jdbc.connection logger uses the connection-appender appender as its log destination. However, notice that at the beginning of the log4j.xml configuration file where the different appenders are declared, there is no connection-appender declared. This will cause log4j to display an error message log4j:ERROR No appender named [connection-appender] could be found. What you can do is change the appender for jdbc.connection logger from connection-appender to jdbc-connection. In fact, probably, this is what was intended in the original sample configuration file.

log4jdbc Example

The following example is completely self-explanatory. Every line is heavily commented, so you should not have any difficulties what each statement does. Briefly speaking, what we are trying to do in this example is to establish a connect to the CUBRID JDBC Driver using the log4jdbc library, which will log all the actions we perform. Then we retrieve table metadata from the database to see if there is a table called "event". Since there is an "event" table in the "demodb" database in CUBRID, after the first requests log4jdbc logs that there is such a table. In the second request for "someabsenttable" table, it logs that such table does not exist. Below you can see the sample output.

import java.sql.DatabaseMetaData;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.util.Properties;

import org.apache.log4j.Logger;

import cubrid.jdbc.driver.CUBRIDException;

import net.sf.log4jdbc.ConnectionSpy;
import net.sf.log4jdbc.DriverSpy;

public class CubridDB {
  // This logger is the main instance which will handle the logging.
  // It is derived from the Apache log4j package.
  private static Logger logger = Logger.getLogger(CubridDB.class.getName());
  // Originally CUBRID JDBC connection string is
  // "jdbc:cubrid:localhost:30000:demodb:dba::"
  // However, to be able to log all the actions we perform with the JDBC driver
  // we need to wrap original driver connection by log4jdbc library class,
  // so we modified the connection string.
  private static final String CUBRID_JDBC_WRAPPED_URL = 
    "jdbc:log4jdbc:cubrid:localhost:33000:demodb:::";
  
  public static void main(String[] args) {
    // Below we will load the CUBRID JDBC driver, which "may" not exist,
    // so we need to wrap the code into the try/catch block.
    // Also when connecting to the Driver another exception can be thrown.
    try {
      // This line tell Java to load the CUBRID JDBC driver.
      Class.forName("cubrid.jdbc.driver.CUBRIDDriver");
      // Initialize log4jdbc DriverSpy class.
      DriverSpy driverSpy = new DriverSpy();
      // Here is one example how to log the "info" level messages
      logger.info("Cheking URL");
      // Here we want to see if log4jdbc library class (DriverSpy) accepts
      // the connection string of our driver.
      if (driverSpy.acceptsURL("CUBRID_JDBC_WRAPPED_URL){
        logger.info("URL is accepted so we are good to move on");
        // The following properties could be set in the separate .properties file
        // In our case we just illustrate how to do it programmatically.
        // We create a property and assign CUBRID database user name and password.
        // The default user name for "demodb" database is dba,
        // and the password is blank.
        Properties props = new Properties(); 
        props.setProperty("cubrid.user", "dba");
        props.setProperty("cubrid.password", "");
        // ConnectionSpy is the connection wrapper class. When we pass the JDBC
        // connection string to the DriverSpy it establishes the connection with
        // CUBRID JDBC driver and wraps it with its own class. The connection
        // may take a bit of a time, so be patient.
        try{
          ConnectionSpy connection = 
            (ConnectionSpy) driverSpy.connect(CUBRID_JDBC_WRAPPED_URL, props);
          // After we tried to connect, we do not need to check if the
          // connection != null, because DriverSpy throws an Exception if
          // otherwise.
          
          // Log that the connection has been successfully established
          // and log CUBRID JDBC driver version.
          logger.info("Connection established. CUBRID JDBC version is: " + 
              driverSpy.getMajorVersion() + "." + driverSpy.getMinorVersion());
          // Let's do some more data retrieval. Let's see if in our database
          // there is a table called "event". Such table exists in the "demodb"
          // database, so would result in true.
          
          // Get the database meta data from the wrapped connection 
          DatabaseMetaData metaData = connection.getMetaData();
          // Get the array of tables which have "event" in the name.
          ResultSet rs = metaData.getTables(null, null, "event", new String[]{"TABLE"});
          // If there is any table with "event" in the name, it will be possible
          // to iterate through the array.
          if (rs.next()) {
            // Want to log this time too that the table exists.
            logger.info(""Event" TABLE exists");
          }
          else{
            logger.info(""Event" TABLE does not exists");
          }
          // One more example, but in this case the result should tell us that
          // the table we requested is absent.
          rs = metaData.getTables(null, null, "someabsenttable", new String[]{"TABLE"});
          // If should fail to iterate to the next record.
          if (rs.next()) {
            // Want to log this time too that the table exists.
            logger.info(""someabsenttable" TABLE exists");
          }
          else{
            logger.info(""someabsenttable" TABLE does not exists");
          }
          // Free the ResultSet memory
          rs.close();
        }
        catch(CUBRIDException e){
          // This time we would like to log an ERROR level message. There can be
          // different type of exceptions. 1. "Cannot connect to a broker".
          // In this case, start the CUBRID Broker by typing "cubrid broker start"
          // in the command line. 2. "Failed to connect to database server,
          // 'demodb', on the following host(s): localhost". This indicates that
          // you forgot to start the "demodb" database. Or such database
          // does not exist. To start the dmeodb CUBRID database, type
          // "cubrid server start demodb" in the command line.
          logger.error(e);
        }
      }
    } catch (ClassNotFoundException e) {
      // We let the logger handle the message even all the exceptions.
      logger.error(e);
    } catch (SQLException e) {
      // This exception too.
      logger.error(e);
    }
  }
}

Sample Output

This is the output you should see if you run the above example.

2010-11-19 10:36:10.406 DEBUG debug: ... log4jdbc initializing ...
2010-11-19 10:36:10.406 DEBUG debug: x log4jdbc.debug.stack.prefix is not defined
2010-11-19 10:36:10.406 DEBUG debug: x log4jdbc.sqltiming.warn.threshold is not defined
2010-11-19 10:36:10.406 DEBUG debug: x log4jdbc.sqltiming.error.threshold is not defined
2010-11-19 10:36:10.406 DEBUG debug:   log4jdbc.drivers = cubrid.JDBC.driver.CUBRIDDriver
2010-11-19 10:36:10.406 DEBUG debug:     will look for additional driver cubrid.JDBC.driver.CUBRIDDriver
2010-11-19 10:36:10.421 DEBUG debug: WARNING!  log4jdbc couldn't find any underlying jdbc drivers.
2010-11-19 10:36:10.421 DEBUG debug: ... log4jdbc initialized! ...
2010-11-19 10:36:10.421  INFO CubridDB: Cheking URL
2010-11-19 10:36:10.421  INFO CubridDB: URL is accepted so we are good to move on
2010-11-19 10:36:10.640  INFO CubridDB: Connection established. CUBRID JDBC version is: 8.3
2010-11-19 10:36:10.640 DEBUG audit: 1. Connection.getMetaData() returned cubrid.jdbc.driver.CUBRIDDatabaseMetaData@93dcd  CubridDB.main(CubridDB.java:68)
2010-11-19 10:36:10.687  INFO CubridDB: "Event" TABLE exists
2010-11-19 10:36:10.703  INFO CubridDB: "someabsenttable" TABLE does not exists

See also

Getting Help

If you have any difficulties with log4jdbc, post your question to CUBRID Forum at http://www.cubrid.org/?mid=forum&category=195533.

See also

Tutorial :: Store Java Logs to Database Using log4j

log4j is one of the most powerful and commonly used logging system used when programming in Java. There are many different ways how you can utilize i...

Tutorial :: Clj-DBCP Clojure Library for Connecting to CUBRID Database

Clj-DBCP is a Java-6/Clojure library to create a database connection pool, which is known to be a more efficient way to connect to multiple databases ...

CUBRID JDBC Tutorial (for CUBRID 8.3.1 and below)

You may write CUBRID powered applications in a variety of languages. The languages that probably most people use to write CUBRID applications are PHP ...




You are either using a very old browser or a browser that is not supported.
In order to browse cubrid.org you need to have one of the following browsers:



Internet Explorer: Mozilla Firefox: Google Chrome: