Re: [logback-user] Logging to Oracle with DBAppender and connection pooling doesn't work

29 Oct 2008

      Hi,

I have the same problem. I debug it and found 2 problems.

1) getGeneratedKeys doesn't work on Oracle 10
2) Oracle driver rolback transaction if you don't set autocommit to true 
after commit.

I think DBAppender needs rewrite. I solved it by writing my own appender 
subclassed from DBAppender redefining methods that I don't like. Source 
is included.
Regards
	Marian Habsuda

package logtest;

import java.lang.reflect.InvocationTargetException;
import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.util.HashMap;
import java.util.Iterator;
import java.util.Map;
import java.util.Set;

import ch.qos.logback.classic.db.DBAppender;
import ch.qos.logback.classic.spi.CallerData;
import ch.qos.logback.classic.spi.LoggingEvent;

public class DBAppenderOracle10g extends DBAppender {
	static int	ii	= 0;

	public DBAppenderOracle10g() {
		super();
		ii++;
		System.out.println("DBAppenderOracle10g, instances = " + ii);
	}

	Connection	connection	= null;

	public void append(Object eventObject) {

		try {
			if (connection == null) {
				connection = connectionSource.getConnection();
				connection.setAutoCommit(false);
			}
			PreparedStatement insertStatement = 
connection.prepareStatement(getInsertSQL());

			subAppend(eventObject, connection, insertStatement);

			// we no longer need the insertStatement
			if (insertStatement != null) {
				insertStatement.close();
				insertStatement = null;
			}

			connection.commit();
		} catch (Throwable sqle) {
			addError("problem appending event", sqle);
		} finally {
			 closeConnection(connection);
		}
	}

	static public void closeConnection(Connection connection) {
		if (connection != null) {
			try {
				connection.setAutoCommit(true);
				connection.close();
			} catch (SQLException sqle) {
				// static utility classes should not log without an explicit repository
				// reference
			}
		}
	}

	public static void closeStatement(Statement statement) {
		if (statement != null) {
			try {
				statement.close();
			} catch (SQLException sqle) {
			}
		}
	}

	protected void subAppend(Object eventObject, Connection connection, 
PreparedStatement insertStatement)
			throws Throwable {
		LoggingEvent event = (LoggingEvent) eventObject;

		addLoggingEvent(insertStatement, event);
		// This is very expensive... should we do it every time?
		addCallerData(insertStatement, event.getCallerData());

		int updateCount = insertStatement.executeUpdate();
		if (updateCount != 1) {
			addWarn("Failed to insert loggingEvent");
		}

		Map mergedMap = mergePropertyMaps(event);

		int eventId = -1;

		Set propertiesKeys = mergedMap.keySet();
		if (propertiesKeys.size() > 0
				|| (event.getThrowableInformation() != null && 
event.getThrowableInformation().getThrowableStrRep().length > 0)) {
			eventId = getEventId(insertStatement, connection);
		}

		insertProperties(mergedMap, connection, eventId);

		if (event.getThrowableInformation() != null) {
			insertThrowable(event.getThrowableInformation().getThrowableStrRep(), 
connection, eventId);
		}
	}

	protected int getEventId(PreparedStatement insertStatement, Connection 
connection) throws SQLException,
			InvocationTargetException {
		ResultSet rs = null;
		Statement idStatement = null;

		insertStatement.close();
		insertStatement = null;

		idStatement = connection.createStatement();
		idStatement.setMaxRows(1);
		rs = idStatement.executeQuery(sqlDialect.getSelectInsertId());

		// A ResultSet cursor is initially positioned before the first row;
		// the
		// first call to the method next makes the first row the current row
		rs.next();
		int eventId = rs.getInt(1);

		rs.close();

		if (idStatement != null) {
			idStatement.close();
			idStatement = null;
		}

		return eventId;
	}

	protected void insertProperties(Map mergedMap, Connection connection, 
int eventId) throws SQLException {
		Set propertiesKeys = mergedMap.keySet();
		if (propertiesKeys.size() > 0) {
			PreparedStatement insertPropertiesStatement = 
connection.prepareStatement(insertPropertiesSQL);

			for (Iterator i = propertiesKeys.iterator(); i.hasNext();) {
				String key = (String) i.next();
				String value = (String) mergedMap.get(key);

				insertPropertiesStatement.setInt(1, eventId);
				insertPropertiesStatement.setString(2, key);
				insertPropertiesStatement.setString(3, value);

				if (cnxSupportsBatchUpdates) {
					insertPropertiesStatement.addBatch();
				} else {
					insertPropertiesStatement.execute();
				}
			}

			if (cnxSupportsBatchUpdates) {
				insertPropertiesStatement.executeBatch();
			}

			insertPropertiesStatement.close();
			insertPropertiesStatement = null;
		}
	}

	Map mergePropertyMaps(LoggingEvent event) {
		Map mergedMap = new HashMap();
		// we add the context properties first, then the event properties, since
		// we consider that event-specific properties should have priority over
		// context-wide
		// properties.
		Map loggerContextMap = 
event.getLoggerRemoteView().getLoggerContextView().getPropertyMap();
		Map mdcMap = event.getMDCPropertyMap();
		if (loggerContextMap != null) {
			mergedMap.putAll(loggerContextMap);
		}
		if (mdcMap != null) {
			mergedMap.putAll(mdcMap);
		}

		return mergedMap;
	}

	void addLoggingEvent(PreparedStatement stmt, LoggingEvent event) throws 
SQLException {
		stmt.setLong(1, event.getTimeStamp());
		stmt.setString(2, event.getFormattedMessage());
		stmt.setString(3, event.getLoggerRemoteView().getName());
		stmt.setString(4, event.getLevel().toString());
		stmt.setString(5, event.getThreadName());
		stmt.setShort(6, computeReferenceMask(event));
	}

	void addCallerData(PreparedStatement stmt, CallerData[] 
callerDataArray) throws SQLException {
		CallerData callerData = callerDataArray[0];
		if (callerData != null) {
			stmt.setString(7, callerData.getFileName());
			stmt.setString(8, callerData.getClassName());
			stmt.setString(9, callerData.getMethodName());
			stmt.setString(10, Integer.toString(callerData.getLineNumber()));
		}
	}

	public static short	PROPERTIES_EXIST	= 0x01;
	public static short	EXCEPTION_EXISTS	= 0x02;

	public static short computeReferenceMask(LoggingEvent event) {
		short mask = 0;

		int mdcPropSize = 0;
		if (event.getMDCPropertyMap() != null) {
			mdcPropSize = event.getMDCPropertyMap().keySet().size();
		}
		int contextPropSize = 0;
		if 
(event.getLoggerRemoteView().getLoggerContextView().getPropertyMap() != 
null) {
			contextPropSize = 
event.getLoggerRemoteView().getLoggerContextView().getPropertyMap().size();
		}

		if (mdcPropSize > 0 || contextPropSize > 0) {
			mask = PROPERTIES_EXIST;
		}
		if (event.getThrowableInformation() != null) {
			String[] strRep = event.getThrowableInformation().getThrowableStrRep();
			if (strRep != null) {
				mask |= EXCEPTION_EXISTS;
			}
		}
		return mask;
	}
}

Morten Egelund Rasmussen wrote:
...
Hi all,
Does anybody have a working example on how to log to Oracle with a
connection pool on a Tomcat server?
I have the following:
In Tomcat's server.xml:
<Resource name="jdbc/logger" auth="Container"
                  type="javax.sql.DataSource"
driverClassName="oracle.jdbc.OracleDriver"
                  url="foo"
                  username="foo" password="foobar"
                  maxActive="50" maxIdle="5"  initialSize="10"
                  maxWait="-1" removeAbandoned="true"
                  validationQuery="select 1 from dual"/>
In Tomcat's context.xml:
<ResourceLink name="jdbc/logger"
                  global="jdbc/logger"
                  type="javax.sql.DataSource"/>
I have defined the following Logback appenders:
<appender name="db" class="myAppenderClass">
        <connectionSource class="ch.qos.logback.core.db.JNDIConnectionSource">
          <param name="jndiLocation" value="java:comp/env/jdbc/logger" />
        </connectionSource>
    </appender>
<appender name="db2" class="myAppenderClass">
        <connectionSource
class="ch.qos.logback.core.db.DriverManagerConnectionSource">
            <driverClass>oracle.jdbc.driver.OracleDriver</driverClass>
            <url>foo</url>
            <user>foo</user>
            <password>foobar</password>
        </connectionSource>
    </appender>
.....where "myAppenderClass" is an appender class as described here:
http://jira.qos.ch/browse/LBCORE-15
Using the "db" appender gives nothing, but using the "db2" appender
gives lots of output. What am I missing?
Any ideas?
~Morten :-/

Re: [logback-user] Logging to Oracle with DBAppender and connection pooling doesn't work

ros246