net.sf.log4jdbc.log.log4j2.Log4j2SpyLogDelegator Maven / Gradle / Ivy
package net.sf.log4jdbc.log.log4j2;
import net.sf.log4jdbc.Properties;
import net.sf.log4jdbc.log.SpyLogDelegator;
import net.sf.log4jdbc.log.log4j2.message.ConnectionMessage;
import net.sf.log4jdbc.log.log4j2.message.ExceptionOccuredMessage;
import net.sf.log4jdbc.log.log4j2.message.MethodReturnedMessage;
import net.sf.log4jdbc.log.log4j2.message.SqlTimingOccurredMessage;
import net.sf.log4jdbc.log.log4j2.message.ConnectionMessage.Operation;
import net.sf.log4jdbc.sql.Spy;
import net.sf.log4jdbc.sql.jdbcapi.ResultSetSpy;
import net.sf.log4jdbc.sql.resultsetcollector.ResultSetCollector;
import net.sf.log4jdbc.sql.resultsetcollector.ResultSetCollectorPrinter;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.MarkerManager;
/**
* Delegates JDBC spy logging events to log4j2.
*
* Differences in implementation and behavior as compared to Slf4jSpyLogDelegator:
*
* - Only 2 loggers are used, instead of 6 in the
Slf4jSpyLogDelegator:
* one for logging all spy logging events
* ("log4jdbc.log4j2", see LOGGER attribute),
* another one for logging debugging within log4jdbc itself
* ("log4jdbc.debug" logger, see DEBUGLOGGER attribute,
* or Slf4jSpyLogDelegator debugLogger attribute).
* - The behavior of the loggers "jdbc.connection", "jdbc.resultset", and "jdbc.audit"
* is reproduced through the use of Markers
* within one single logger:
*
* - The
Marker CONNECTION_MARKER, named "LOG4JDBC_CONNECTION"
* - The
Marker RESULTSET_MARKER, named "LOG4JDBC_RESULTSET",
* a child of the Marker JDBC_MARKER, named "LOG4JDBC_JDBC"
* - The
Marker RESULTSETTABLE_MARKER, named "LOG4JDBC_RESULTSETTABLE",
* a child of the Marker RESULTSET_MARKER, named "LOG4JDBC_RESULTSET"
* - The
Marker AUDIT_MARKER, named "LOG4JDBC_AUDIT",
* a child of the Marker JDBC_MARKER, named "LOG4JDBC_JDBC"
* JDBC_MARKER and CONNECTION_MARKER are children of
* NON_STATEMENT_MARKER, named "LOG4JDBC_NON_STATEMENT".
* This is to easily reproduce standard log4jdbc loggers behavior,
* and behavior of log4jdbc-remix.
*
* - The behavior of the logger "jdbc.sqlonly"
* (see for instance
Slf4jSpyLogDelegator sqlOnlyLogger attribute)
* is not reproduced.
* This is for the will of keeping one single logger, while the logging of spy events
* immediately, before the action is executed and before knowing the execution time,
* would definitely require another logger.
* Also, execution time seems to be an always-useful information to get.
* - As a consequence, the method
sqlOccured(Spy, String, String) is not implemented.
* - Thanks to the use of
Markers, some options configured
* in the log4jdbc properties file can be set directly in the log4j2 configuration file:
*
* - log4jdbc.dump.sql.select property can be set using the
Marker SELECT_MARKER,
* named "LOG4JDBC_SELECT"
* - log4jdbc.dump.sql.insert property can be set using the
Marker INSERT_MARKER,
* named "LOG4JDBC_INSERT"
* - log4jdbc.dump.sql.update property can be set using the
Marker UPDATE_MARKER,
* named "LOG4JDBC_UPDATE"
* - log4jdbc.dump.sql.delete property can be set using the
Marker DELETE_MARKER,
* named "LOG4JDBC_DELETE"
* - log4jdbc.dump.sql.create property can be set using the
Marker CREATE_MARKER,
* named "LOG4JDBC_CREATE"
*
* These Markers are all children of the Marker SQL_MARKER, named "LOG4JDBC_SQL".
* These properties can also be set through the log4jdbc properties file.
* They would have priority over the Markers.
* - The interface
SpyLogDelegator,
* and the classes Slf4jSpyLogDelegator, DriverSpy,
* ConnectionSpy, SpyLogFactory,
* StatementSpy and PreparedStatementSpy
* have been modified. See their corresponding javadoc for information about the changes.
*
*
* @author Frederic Bastian
* @author Mathieu Seppey
* @see #LOGGER
* @see #DEBUGLOGGER
* @see net.sf.log4jdbc.Slf4jSpyLogDelegator
* @see net.sf.log4jdbc.SpyLogDelegator
* @see net.sf.log4jdbc.DriverSpy
* @see net.sf.log4jdbc.SpyLogFactory
*/
public class Log4j2SpyLogDelegator implements SpyLogDelegator
{
/**
* Logger responsible of logging all spy events
*/
private static final Logger LOGGER = LogManager.getLogger("log4jdbc.log4j2");
/**
* Logger just for debugging things within log4jdbc itself (admin, setup, etc.)
* @see net.sf.log4jdbc.Log4j2SpyLogDelegator#debugLogger
*/
private static final Logger DEBUGLOGGER = LogManager.getLogger("log4jdbc.debug");
/**
* Marker to log events generated by Statements
* (corresponds to the "jdbc.sqltiming" logger in the standard implementation)
*/
private static final Marker SQL_MARKER = MarkerManager.getMarker("LOG4JDBC_SQL");
/**
* Marker to log events following select statements
* (corresponds to the log4jdbc.dump.sql.select property)
*/
private static final Marker SELECT_MARKER = MarkerManager.getMarker("LOG4JDBC_SELECT", SQL_MARKER);
/**
* Marker to log events following insert statements
* (corresponds to the log4jdbc.dump.sql.insert property)
*/
private static final Marker INSERT_MARKER = MarkerManager.getMarker("LOG4JDBC_INSERT", SQL_MARKER);
/**
* Marker to log events following update statements
* (corresponds to the log4jdbc.dump.sql.update property)
*/
private static final Marker UPDATE_MARKER = MarkerManager.getMarker("LOG4JDBC_UPDATE", SQL_MARKER);
/**
* Marker to log events following delete statements
* (corresponds to the log4jdbc.dump.sql.delete property)
*/
private static final Marker DELETE_MARKER = MarkerManager.getMarker("LOG4JDBC_DELETE", SQL_MARKER);
/**
* Marker to log events following create statements
* (corresponds to the log4jdbc.dump.sql.create property)
*/
private static final Marker CREATE_MARKER = MarkerManager.getMarker("LOG4JDBC_CREATE", SQL_MARKER);
/**
* Marker parent of the CONNECTION_MARKER and
* JDBC_MARKER, to easily disable logging of connection, JDBC, and ResultSet calls.
* This is to easily reproduce log4jdbc standard loggers behaviors.
*/
private static final Marker NON_STATEMENT_MARKER = MarkerManager.getMarker("LOG4JDBC_NON_STATEMENT");
/**
* Marker to log connections events
* (corresponds to the "jdbc.connection" logger in the standard implementation)
*/
private static final Marker CONNECTION_MARKER = MarkerManager.getMarker("LOG4JDBC_CONNECTION", NON_STATEMENT_MARKER);
/**
* Marker to log all JDBC calls including ResultSets,
* and result sets as tables.
*/
private static final Marker OTHER_MARKER = MarkerManager.getMarker("LOG4JDBC_OTHER", NON_STATEMENT_MARKER);
/**
* Marker to log all JDBC calls including ResultSets
*/
private static final Marker JDBC_MARKER = MarkerManager.getMarker("LOG4JDBC_JDBC", OTHER_MARKER);
/**
* Marker to log all JDBC calls except for ResultSets
* (corresponds to the "jdbc.audit" logger in the standard implementation)
*/
private static final Marker AUDIT_MARKER = MarkerManager.getMarker("LOG4JDBC_AUDIT", JDBC_MARKER);
/**
* Marker to log ResultSets calls
* (corresponds to the "jdbc.resultset" logger in the standard implementation)
*/
private static final Marker RESULTSET_MARKER = MarkerManager.getMarker("LOG4JDBC_RESULTSET", JDBC_MARKER);
/**
* Marker to log JDBC ResultSets as table.
* Functionality inherited from log4jdbc-remix.
* (corresponds to the "jdbc.resultsettable" logger in the log4jdbc-remix implementation)
* @see net.sf.log4jdbc.sql.resultsetcollector
*/
private static final Marker RESULTSETTABLE_MARKER =
MarkerManager.getMarker("LOG4JDBC_RESULTSETTABLE", OTHER_MARKER);
/**
* Marker to log Exceptions.
* These are not specific to one logger in the standard implementation,
* and they are not logged by the loggers "jdbc.resultset" and "jdbc.connection"
* (bug, or a hope for no exception to occur for these events?)
*/
private static final Marker EXCEPTION_MARKER = MarkerManager.getMarker("LOG4JDBC_EXCEPTION");
@Override
public boolean isJdbcLoggingEnabled() {
return LOGGER.isErrorEnabled();
}
@Override
public void exceptionOccured(Spy spy, String methodCall, Exception e,
String sql, long execTime) {
LOGGER.error(EXCEPTION_MARKER, new ExceptionOccuredMessage(spy, methodCall,
sql, execTime, LOGGER.isDebugEnabled(EXCEPTION_MARKER)), e);
}
@Override
public void methodReturned(Spy spy, String methodCall, String returnMsg)
{
String classType = spy.getClassType();
Marker marker = ResultSetSpy.classTypeDescription.equals(classType)?
RESULTSET_MARKER:AUDIT_MARKER;
LOGGER.info(marker,
new MethodReturnedMessage(spy, methodCall, returnMsg, LOGGER.isDebugEnabled(marker)));
}
@Override
public void constructorReturned(Spy spy, String constructionInfo) {
//not yet used in the current implementation of log4jdbc
}
@Override
public void sqlOccurred(Spy spy, String methodCall, String sql) {
//not implemented,
//as the features provided by the logger "jdbc.sqlonly" are not reproduced.
}
@Override
public void sqlTimingOccurred(Spy spy, long execTime, String methodCall,
String sql)
{
//test useless in the current implementation,
//as if error level is not enabled for this logger,
//the ConnectionSpy will not be used (see isjdbcLoggingEnabled())
//might maybe change one day?
/*if (!LOGGER.isErrorEnabled()) {
return;
}*/
String operation = this.getSqlOperation(sql);
if (Properties.isDumpSqlFilteringOn() && !this.shouldSqlBeLogged(operation)) {
return;
}
Marker marker = this.getStatementMarker(operation);
SqlTimingOccurredMessage message =
new SqlTimingOccurredMessage(spy, execTime, methodCall, sql, LOGGER.isDebugEnabled(marker));
if (Properties.isSqlTimingErrorThresholdEnabled() &&
execTime >= Properties.getSqlTimingErrorThresholdMsec()) {
LOGGER.error(marker, message);
} else if (LOGGER.isWarnEnabled()) {
if (Properties.isSqlTimingWarnThresholdEnabled() &&
execTime >= Properties.getSqlTimingWarnThresholdMsec()) {
LOGGER.warn(marker, message);
} else {
LOGGER.info(marker, message);
}
}
}
/**
* Identify the operation performed by the sql statement
* (either "select", "insert", "update", "delete", or "create").
*
* @param sql A String representing the SQL statement to evaluate
* @return A String representing the operation
* performed by the sql statement
* (either "select", "insert", "update", "delete", or "create"),
* or an empty String if the operation could not be determined
* (sql null, etc.)
*/
private String getSqlOperation(String sql)
{
if (sql == null) {
return "";
}
sql = sql.trim();
if (sql.length()<6) {
return "";
}
return sql.substring(0,6).toLowerCase();
}
/**
* Return the appropriate Marker
* (either SQL_MARKER, SELECT_MARKER,
* INSERT_MARKER, UPDATE_MARKER, DELETE_MARKER,
* or CREATE_MARKER) depending on the operation
* performed by a SQL statement
* (either "select", "insert", "update", "delete", or "create").
* @param operation a String representing the operation
* performed by a SQL statement
* (either "select", "insert", "update", "delete", or "create").
* @return the appropriate Marker depending on the operation:
* SELECT_MARKER if operation is equal to "select".
* INSERT_MARKER if operation is equal to "insert".
* UPDATE_MARKER if operation is equal to "update".
* DELETE_MARKER if operation is equal to "delete".
* CREATE_MARKER if operation is equal to "create".
* SQL_MARKER otherwise.
* @see #SQL_MARKER
* @see #SELECT_MARKER
* @see #INSERT_MARKER
* @see #UPDATE_MARKER
* @see #DELETE_MARKER
* @see #CREATE_MARKER
*/
private Marker getStatementMarker(String operation)
{
if (operation == null) {
return SQL_MARKER;
} else if ("select".equals(operation)) {
return SELECT_MARKER;
} else if ("insert".equals(operation)) {
return INSERT_MARKER;
} else if ("update".equals(operation)) {
return UPDATE_MARKER;
} else if ("delete".equals(operation)) {
return DELETE_MARKER;
} else if ("create".equals(operation)) {
return CREATE_MARKER;
}
return SQL_MARKER;
}
/**
* Determine if the given operation of an SQL statement
* should be logged or not
* based on the various DumpSqlXXXXXX flags.
*
* @param operation A String representing the operation of a SQL statement
* (either "select", "insert", "update", "delete", or "create").
* @return true if the SQL statement
* executing the given operation should be logged, false if not.
*/
private boolean shouldSqlBeLogged(String operation)
{
return
(operation == null) ||
(Properties.isDumpSqlSelect() && "select".equals(operation)) ||
(Properties.isDumpSqlInsert() && "insert".equals(operation)) ||
(Properties.isDumpSqlUpdate() && "update".equals(operation)) ||
(Properties.isDumpSqlDelete() && "delete".equals(operation)) ||
(Properties.isDumpSqlCreate() && "create".equals(operation));
}
@Override
public void connectionOpened(Spy spy, long execTime)
{
this.connectionModified(spy, execTime, Operation.OPENING);
}
@Override
public void connectionClosed(Spy spy, long execTime)
{
this.connectionModified(spy, execTime, Operation.CLOSING);
}
@Override
public void connectionAborted(Spy spy, long execTime)
{
this.connectionModified(spy, execTime, Operation.ABORTING);
}
/**
*
* @param spy ConnectionSpy that was opened or closed.
* @param execTime A long defining the time elapsed to open or close the connection in ms
* Caller should pass -1 if not used
* @param operation an int to define if the operation was to open, or to close connection.
* Should be equals to ConnectionMessage.OPENING
* if the operation was to open the connection,
* to ConnectionMessage.CLOSING if the operation was to close the connection.
*/
private void connectionModified(Spy spy, long execTime, Operation operation)
{
LOGGER.info(CONNECTION_MARKER,
new ConnectionMessage(spy, execTime, operation, LOGGER.isDebugEnabled(CONNECTION_MARKER)));
}
@Override
public void debug(String msg)
{
DEBUGLOGGER.debug(msg);
}
@Override
public boolean isResultSetCollectionEnabled() {
return LOGGER.isInfoEnabled(RESULTSETTABLE_MARKER);
}
@Override
public boolean isResultSetCollectionEnabledWithUnreadValueFillIn() {
return LOGGER.isDebugEnabled(RESULTSETTABLE_MARKER);
}
@Override
public void resultSetCollected(ResultSetCollector resultSetCollector) {
String resultToPrint = new ResultSetCollectorPrinter().getResultSetToPrint(resultSetCollector);
LOGGER.info(RESULTSETTABLE_MARKER,resultToPrint);
}
}