Log final MySQL query in MyBatis Java to execute it manually afterwards on a different server

Question

I am developing a command line application in JAVA where, based on some factors, MySQL queries are executed on a sandbox MySQL server and after some manual verification these queries need to be executed on the production server. I want to log these MySQL queries in a .sql file on sandbox server and execute it later using scripts.

I tried searching through stack overflow and found lots of examples for logging queries, but the queries logged are not the final queries executed. For example,

Preparing: INSERT into table_name values(null, ?,?, ?,?,?, ?, ?,?); 
DEBUG [pool-4-thread-1] - ==> Parameters: 21655(Integer), 2658413(Integer), 04:05:00(Time), null, 1565.0(Double), 3(String), (String), 0(Integer)

Also, the queries are not logged in directly executable format.

My log4j.properties file:

log4j.rootLogger=INFO, stdout
log4j.logger.com.test.mappers.TableMapper=TRACE
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] - %m%n
log4j.logger.java.sql.PreparedStatement=DEBUG, stdout

log4j.logger.com.ibatis.common.jdbc.SimpleDataSource=DEBUG
log4j.logger.com.ibatis.common.jdbc.ScriptRunner=DEBUG
log4j.logger.com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate=DEBUG

log4j.logger.com.ibatis=DEBUG
log4j.logger.java.sql.Connection=DEBUG
log4j.logger.java.sql.Statement=DEBUG
log4j.logger.java.sql.PreparedStatement=DEBUG
log4j.logger.java.sql.ResultSet=DEBUG

Can I log exact final MySQL queries in a .sql file separately?

@YCF_L Thanks for replying, I found a solution for this by using log4jdbc-log4j2 and using custom log delegator which logs exact Mysql query in a separate file. — Saheb, May 02 '17 at 07:01
you can post the solution as an answer maybe it help others in future :) — Youcef LAIDANI, May 02 '17 at 07:03

Saheb · Accepted Answer · 2018-02-24T09:02:24.103

After trying a lot, I found that this is not possible only with Mybatis and log4j, it needs a proxy driver which can log the request to JDBC driver.

I found the idea of using log4jdbc2 from here with LOG4JDBC_SQL marker to send the SQL queries to a separate file. But, this file will contain approximated time taken for execution and connection number also. So to get rid of them I wrote a custom spy log delegator.

Installation and configuration of log4jdbc2 can be found here.

I will rewrite the steps taken for getting the desired results:

Added maven dependency for log4jdbc2. log4jdbc2 depends on log4j-api and log4j-core, make sure they are included in the project.

<dependency>
    <groupId>org.bgee.log4jdbc-log4j2</groupId>
    <artifactId>log4jdbc-log4j2-jdbc4.1</artifactId>
    <version>1.16</version>
</dependency>

Changed JDBC URL from jdbc:mysql://localhost:3306/mydb to jdbc:log4jdbc:mysql://localhost:3306/mydb
Changed the driver used to net.sf.log4jdbc.sql.jdbcapi.DriverSpy

Created an appender and created a logger with LOG4JDBC_SQL marker to filter only sql queries.

<Appenders>
    <File name="queryLog" fileName="/Users/sahebpreetsingh/queries.sql"
    immediateFlush="false" append="false">
        <PatternLayout pattern="%msg%n" />
    </File>
</Appenders>

<Loggers>
    <logger name="log4jdbc.log4j2" level="info" additivity="false">
        <MarkerFilter marker="LOG4JDBC_SQL" onMatch="ACCEPT"
        onMismatch="DENY" />
        <appender-ref ref="queryLog" />
    </logger>
</Loggers>

The marker here specifies to filter sql queries only and ignore the rest of the results.

Extended the existing Log4j2SpyLogDelegator to save time and log only sql queries in executable form.

package com.myapp.utils;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.MarkerManager;

import net.sf.log4jdbc.Properties;
import net.sf.log4jdbc.log.log4j2.Log4j2SpyLogDelegator;
import net.sf.log4jdbc.sql.Spy;

public class QueryLogDelegator extends Log4j2SpyLogDelegator {

    private static final Logger LOGGER = LogManager.getLogger("log4jdbc.log4j2");

    private static final Marker SQL_MARKER = MarkerManager.getMarker("LOG4JDBC_SQL");

    private static final Marker SELECT_MARKER = MarkerManager.getMarker("LOG4JDBC_SELECT", SQL_MARKER);

    private static final Marker INSERT_MARKER = MarkerManager.getMarker("LOG4JDBC_INSERT", SQL_MARKER);

    private static final Marker UPDATE_MARKER = MarkerManager.getMarker("LOG4JDBC_UPDATE", SQL_MARKER);

    private static final Marker DELETE_MARKER = MarkerManager.getMarker("LOG4JDBC_DELETE", SQL_MARKER);

    private static final Marker CREATE_MARKER = MarkerManager.getMarker("LOG4JDBC_CREATE", SQL_MARKER);

    private String getSqlOperation(String sql) {
        if (sql == null) {
            return "";
        }
        sql = sql.trim();

        if (sql.length() < 6) {
            return "";
        }
        return sql.substring(0, 6).toLowerCase();
    }

    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 sqlTimingOccurred(Spy spy, long execTime, String methodCall, String sql) {
        String operation = getSqlOperation(sql);
        if ((Properties.isDumpSqlFilteringOn()) && (!(shouldSqlBeLogged(operation)))) {
            return;
        }

        Marker marker = getStatementMarker(operation);

        if ((Properties.isSqlTimingErrorThresholdEnabled()) && (execTime >= Properties.getSqlTimingErrorThresholdMsec())) {
            LOGGER.error(marker, sql);
        } else if (LOGGER.isWarnEnabled())
            if ((Properties.isSqlTimingWarnThresholdEnabled()) && (execTime >= Properties.getSqlTimingWarnThresholdMsec())) {
                LOGGER.warn(marker, sql);
            } else
                LOGGER.info(marker, sql);
    }

    private Marker getStatementMarker(String operation) {
        if (operation == null)
            return SQL_MARKER;
        if ("select".equals(operation))
            return SELECT_MARKER;
        if ("insert".equals(operation))
            return INSERT_MARKER;
        if ("update".equals(operation))
            return UPDATE_MARKER;
        if ("delete".equals(operation))
            return DELETE_MARKER;
        if ("create".equals(operation)) {
            return CREATE_MARKER;
        }
        return SQL_MARKER;
    }

}

Added the logger to log4jdbc.log4j2.properties

log4jdbc.dump.sql.addsemicolon=true
log4jdbc.spylogdelegator.name=com.myapp.QueryLogDelegator

Log final MySQL query in MyBatis Java to execute it manually afterwards on a different server

1 Answers1