p6spy is an open source project which is abandoned, but which is a very useful project. Note: the queries are not the EXACT queries, if it was a prepared statement with params, the params are substituted for the values
If you turn on p6spy, each statement of db traffic, and each resultset will be printed to a log file. Here is an example:
- Each time the app is started (or app server restarted), the file will clear and overwrite. The file never rotates, so dont leave it on too long or it gets big
- Each line has a timestamp. mm-dd-yyyy
- Each line tells how long it took (e.g. 0ms, 15ms). Note this is not too accurate... its probably accurate to 10ms.
- The "statement" is the type of jdbc call. And after that is the horizontal stack of where the call came from:
JDBCTransaction.java.commit() line 106, Hib3MembershipDAO.java.update() line 873 ...
- When there is a resultset, first the columns are printed (the alias in the 0 index column is "id"):
02-16-08 15:24:25:153, resultset: ALIASES: 0: id
- Then the data is printed in the same column order as the columns (the data in the 0 column is a string 402881821823e6b3011823eb3e34001f)
02-16-08 15:24:25:153, resultset: 0: 402881821823e6b3011823eb3e34001f
- Change the DB driver wherever you want to log (e.g. grouper.hibernate.properties, sources.xml)
- Make sure there is a spy.properties file in the classpath in the default package. Customize the conf/spy.example.properties in grouper
- Make sure the p6spy.jar is in the lib dir (its in grouper/lib)
- In the spy.properties, specify the underlying driver (e.g. for mysql): realdriver=com.mysql.jdbc.Driver
- Set the logfile in the spy.properties: logfile=f\:\\temp
- Other useful things in the config file: you can filter out things you dont want to see based on patterns, if you are looking for long running queries you can restrict a threshold of millis, you can print full stacktrace (vertical) for each statement (not recommend), you can set it to not delete file on start
Customizations Made to P6SPY
Again, this is a defunct project, so no need to ever upgrade it.
I customized it to work with grouper, and I can further tweak it if people have suggestions (right now the queries with bind vars are printed out with dates and timestamps in oracle format... I could detect which underlying driver is used and give output for other db's). The source and build script are in the jar, though some other jars are needed to compile it.
Some things I did are:
- Substitute the values of prepared statement params so the query can be runable (note, might not work if not oracle... might need to tweak it)
- Put a horizontal stacktrace on each call (ignore DB driver parts)
- In the resultset, print the column headers in one line, then each subsequent line is the data that was read
- Add timing for each statement
- Improve the filtering for long running queries
- Take some things out that didnt work (it converted columns by index to name, but that didnt work in mysql when a column name is "id"). Not sure why it existed anyway