net.sf.log4jdbc.PostLogProfilerProcessor Maven / Gradle / Ivy
Go to download
Show more of this group Show more artifacts with this name
Show all versions of log4jdbc Show documentation
Show all versions of log4jdbc Show documentation
JDBC proxy driver for logging SQL and other interesting information.
The newest version!
/**
* Copyright 2007-2012 Arthur Blake
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package net.sf.log4jdbc;
import java.io.FileReader;
import java.io.LineNumberReader;
import java.io.PrintStream;
import java.util.List;
import java.util.LinkedList;
import java.util.Arrays;
/**
* Post processes an existing sqltiming log, and creates a profiling report from it.
* Name of log file is passed in on the command line as the only argument.
*
* Assumptions:
*
* 1. Each sql statement in the log is separated by a blank line.
* 2. Each sql statement is terminated with the timing string "{executed in N msec}" where N is the number of
* milliseconds that the sql executed in.
*
*/
public class PostLogProfilerProcessor {
//todo: needs to be able to gracefully handle sql exceptions in log output
/**
* Post Process log4jdbc sqltiming log data.
*
* @param args command line arguments. Expects one argument, the name of the file to post process.
* @throws Exception if something goes wrong during processing.
*/
public static void main(String[] args) throws Exception
{
if (args.length < 1)
{
System.out.println("usage: java PostLogProfilerProcessor ");
System.exit(1);
}
new PostLogProfilerProcessor(args[0], System.out);
}
/**
* Total number of sql statements processed.
*/
private long totalSql = 0L;
/**
* Number of lines processed.
*/
private long lineNo = 0L;
/**
* Total number of milliseconds that all processed sql took to run.
*/
private long totalMsec = 0L;
/**
* Milliseconds of the worst single offending sql statement.
*/
private long maxMsec = 0L;
/**
* Total combined milliseconds of all flagged sql statements.
*/
private long flaggedSqlTotalMsec = 0L;
/**
* Threshold at which sql is deemed to be running slow enough to be flagged.
*/
private long threshold = 100L;
/**
* How many top offender sql statements to display in final report
*/
private long topOffenderCount = 1000L;
/**
* Collection of all sql that took longer than "threshold" msec to run.
*/
private List flaggedSql = new LinkedList();
/**
* Process given filename, and produce sql profiling report to given PrintStream.
*
* @param filename sqltiming log to process.
* @param out PrintStream to write profiling report to.
* @throws Exception if reading error occurs.
*/
public PostLogProfilerProcessor (String filename, PrintStream out) throws Exception
{
FileReader f= new FileReader(filename);
LineNumberReader l = new LineNumberReader(f);
String line;
boolean blankLine;
StringBuffer sql = new StringBuffer();
do
{
line = l.readLine();
if (line != null)
{
blankLine = line.length()==0;
lineNo++;
/*
if (lineNo%100000L==0L)
{
out.println("" + lineNo + " lines...");
}
*/
if (blankLine)
{
processSql(sql);
sql = new StringBuffer();
}
else
{
sql.append(line);
}
}
} while (line != null);
out.println("processed " + lineNo + " lines.");
f.close();
// display report to stdout
out.println("Number of sql statements: " + totalSql);
out.println("Total number of msec : " + totalMsec);
if (totalMsec>0)
{
out.println("Average msec/statement : " + totalSql/totalMsec);
}
int flaggedSqlStmts = flaggedSql.size();
if (flaggedSqlStmts>0)
{
out.println("Sql statements that took more than "+ threshold + " msec were flagged.");
out.println("Flagged sql statements : " + flaggedSqlStmts);
out.println("Flagged sql Total number of msec : " + flaggedSqlTotalMsec);
out.println("Flagged sql Average msec/statement : " + flaggedSqlTotalMsec/flaggedSqlStmts);
out.println("sorting...");
Object[] flaggedSqlArray = flaggedSql.toArray();
Arrays.sort(flaggedSqlArray);
int execTimeSize = ("" + maxMsec).length();
if (topOffenderCount > flaggedSqlArray.length)
{
topOffenderCount = flaggedSqlArray.length;
}
out.println("top " + topOffenderCount + " offender"+ (topOffenderCount==1?"":"s") + ":");
ProfiledSql p;
for (int i=0; i < topOffenderCount; i++)
{
p = (ProfiledSql) flaggedSqlArray[i];
out.println(Utilities.rightJustify(execTimeSize,""+p.getExecTime()) + " " + p.getSql());
}
}
}
private void processSql(StringBuffer sql)
{
if (sql.length()>0)
{
totalSql++;
String sqlStr = sql.toString();
if (sqlStr.endsWith("msec}"))
{
int executedIn = sqlStr.indexOf("{executed in ");
if (executedIn == -1)
{
System.err.println("WARNING: sql w/o timing info found at line " + lineNo);
return;
}
//todo: proper error handling for parse
String msecStr = sqlStr.substring(executedIn+13, sqlStr.length()-6);
long msec = Long.parseLong(msecStr);
totalMsec +=msec;
if (msec > maxMsec)
{
maxMsec = msec;
}
if (msec >threshold)
{
flagSql(msec,sqlStr);
flaggedSqlTotalMsec += msec;
}
}
else
{
System.err.println("WARNING: sql w/o timing info found at line " + lineNo);
}
}
}
private void flagSql(long msec, String sql)
{
flaggedSql.add(new ProfiledSql(msec,sql));
}
private class ProfiledSql implements Comparable {
private Long execTime;
private String sql;
public ProfiledSql (long msec, String sql)
{
this.execTime= new Long(msec);
this.sql = sql;
}
/**
* Compares this object with the specified object for order. Returns a
* negative integer, zero, or a positive integer as this object is less
* than, equal to, or greater than the specified object.
*
* In this case the comparison is used to sort flagged sql in descending order.
* @param o ProfiledSql Object to compare to this ProfiledSql. Must not be null.
*/
public int compareTo(Object o) {
return ((ProfiledSql)o).execTime.compareTo(execTime);
}
public Long getExecTime() {
return execTime;
}
public String getSql() {
return sql;
}
public String toString()
{
return this.execTime + " msec: " + this.sql;
}
}
}