P6Spy not logging SQL

Question

I have a program that updates tables in a database using prepared statements, and I'm trying to see the output of all the SQL statements that are implemented.

My research suggested P6Spy which looked great, I downloaded it, added the P6Spy.jar as a dependency in my library, modified to the spy.properties file to connect to use the oracle driver as the realdriver, added the spy.properties to my classpath, and changed the driver to "com.p6spy.engine.spy.P6SpyDriver" in my code.

It all works, the spy.log file is generated BUT it DOES NOT CONTAIN THE SQL STATEMENTS. Instead, the output in the spy.log file is :

1374244954573|-1||debug||com.p6spy.engine.common.P6SpyOptions reloading properties
1374244954578|-1||info||Using properties file: C:\Users\gboss\logging\spy.properties
1374244954579|-1||info||No value in environment for: getStackTrace, using: false
1374244954579|-1||info||No value in environment for: getDeregisterDrivers, using: false
1374244954579|-1||info||No value in environment for: getUsePrefix, using: false
1374244954579|-1||info||No value in environment for: getExecutionThreshold, using: 0
1374244954579|-1||info||No value in environment for: getAutoflush, using: true
1374244954579|-1||info||No value in environment for: getExclude, using: 
1374244954579|-1||info||No value in environment for: getExcludecategories, using: info,debug,result,batch
1374244954579|-1||info||No value in environment for: getFilter, using: true
1374244954579|-1||info||No value in environment for: getInclude, using: 
1374244954579|-1||info||No value in environment for: getIncludecategories, using: 
1374244954579|-1||info||No value in environment for: getLogfile, using: c:/spy.log
1374244954579|-1||info||No value in environment for: getAppender, using: com.p6spy.engine.logging.appender.FileLogger
1374244954579|-1||info||No value in environment for: getRealdriver, using: oracle.jdbc.driver.OracleDriver
1374244954579|-1||info||No value in environment for: getRealdriver2, using: 
1374244954580|-1||info||No value in environment for: getRealdriver3, using: 
1374244954580|-1||info||No value in environment for: getAppend, using: true
1374244954580|-1||info||No value in environment for: getSpydriver, using: com.p6spy.engine.spy.P6SpyDriver
1374244954580|-1||info||No value in environment for: getDateformat, using: 
1374244954580|-1||info||No value in environment for: getDateformatter, using: null
1374244954580|-1||info||No value in environment for: getStringmatcher, using: com.p6spy.engine.common.SubstringMatcher
1374244954580|-1||info||No value in environment for: getStringMatcherEngine, using: com.p6spy.engine.common.SubstringMatcher@13aaa14a
1374244954580|-1||info||No value in environment for: getStackTraceClass, using: 
1374244954580|-1||info||No value in environment for: getSQLExpression, using: null
1374244954580|-1||info||No value in environment for: getReloadProperties, using: false
1374244954580|-1||info||No value in environment for: getReloadPropertiesInterval, using: 60
1374244954580|-1||info||No value in environment for: getJNDIContextFactory, using: null
1374244954580|-1||info||No value in environment for: getJNDIContextProviderURL, using: null
1374244954580|-1||info||No value in environment for: getJNDIContextCustom, using: null
1374244954580|-1||info||No value in environment for: getRealDataSource, using: null
1374244954580|-1||info||No value in environment for: getRealDataSourceClass, using: null
1374244954580|-1||info||No value in environment for: getRealDataSourceProperties, using: null

does anyone have experience using P6Spy and know what the issue is? I've read that the spy.log is just supposed to generate the sql statements after doing all the things I did and running the program, so I'm pretty confused here

EDIT -- The database was updated by the way, so the SQL statements did go through and update the database

Answer 1

This is typically caused by the P6SpyDriver being registered with DriverManager after your real JDBC driver is registered. P6Spy 1.3 did not require you to change the JDBC URL. When the application code (or app server) tries to get a suitable driver from DriverManager, it cycles through the registered drivers to find the first one the handles the URL. If P6SpyDriver is not registered before the real driver, then it will not be used.

There are two ways to fix this problem:

1. Set 'deregisterdrivers=true' in your spy.properties.

This will cause P6Spy to unregister the real driver and then reregister it. This will cause DriverManager to use P6SpyDriver. However, with Java 6+ you must make sure that the driver class you have listed for the real driver matches the one that will be autoregistered. You can get this class name from META-INF/services/java.sql.Driver. If that file does not exist in the JAR file for the JDBC driver, then it does not support auto registeration.

2. Set 'useprefix=true' in spy.properties and modify your JDBC URL to add the 'p6spy:' prefix.

This will ensure that the P6SpyDriver will be used regardless of the order in which the drivers are loaded. This is actually the most reliable way...

See http://p6spy.github.io/p6spy/1.3/configandusage.html for the various configuration options available with 1.3.

Answer 2

I had the same problem and I could not get it working, so I used log4jdbc to intercept the JDBC statements, it is very easy to use and provides more info than p6spy :

Just follow these two simple steps :

1. Add below two dependencies in your pom file or add respective jars to your classpath :

   <dependency>
       <groupId>org.slf4j</groupId>
       <artifactId>slf4j-log4j12</artifactId>
       <version>1.7.21</version>
   </dependency>
   <dependency>
       <groupId>org.lazyluke</groupId>
       <artifactId>log4jdbc-remix</artifactId>
       <version>0.2.7</version>
   </dependency>
   

2. Change your DB_URL and DB_DRIVER properties like this, I was using an h2 database, so I had set below properties :

   DB_DRIVER=org.h2.Driver DB_URL=jdbc:h2:./target/db/notificationdb;AUTO_SERVER=TRUE;TRACE_LEVEL_FILE=0;MODE=Oracle;

   So I modified them as :

   DB_DRIVER=net.sf.log4jdbc.DriverSpy DB_URL=jdbc:log4jdbc:h2:./target/db/notificationdb;AUTO_SERVER=TRUE;TRACE_LEVEL_FILE=0;MODE=Oracl;

And this was my log4j.properties File:

log4j.rootLogger=INFO, stdout                                               
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{yy/MM/dd HH:mm:ss} %p %c{2}: %m%n

And you are good to go and you will see real SQL queries and even their results.