No errors, but not SQL logging either

Help
2007-12-02
2013-04-25
  • Hello all,

    I am dangerously close to getting SQL tracing out of p6spy but need a little help.
    I've got it for a stand-alone java app.
    Now I'm working on WebSphere 6.2.
    The problem:  my app has full access to the db and I see spy initialization in my log files,
    but those same log files contain no SQL when I exercise the application.

    The application was using the jndi name 'jdbc/TPDataSource'
    I changed that name to 'jdbc/RealTPDataSource'.
    I then created a data source for spy with the original name: 'jdbc/TPDataSource'

    The DriverManager shows the p6 driver first, then the Oracle one.
    Is this correct? 
    1196626934953|-1||debug||Driver manager reporting driver registered: com.p6spy.engine.spy.P6SpyDriver@45050c48
    1196626934953|-1||debug||Driver manager reporting driver registered: oracle.jdbc.driver.OracleDriver@5c034c48

    I'm working on adding debug to my code that shows the class name of
    the datasource/connection received from jndi.  Having classpath problems,
    but I'll post results when I get them.  It is sure behaving like it is using
    direct oracle instead of spy-->oracle.

    Environment:  Oracle 10g, Windows 2k, WAS 6.2.

    Any help would be greatly appreciated.
    Thanks,

    --Erik Ostermueller

    I've recompiled my jar to add additional debug, which you'll see below...

    ############### I have two spy.log files being used. 
    ############### Here is one in WebSphere 6.2's 'default' directory
    ############### The 'other' one is further below
    1196626934922|-1||debug||com.p6spy.engine.common.P6SpyOptions reloading properties
    1196626934938|-1||info||Using properties file: C:\Program Files\IBM\WebSphere\AppServer/properties\spy.properties
    1196626934938|-1||info||No value in environment for: getExecutionThreshold, using: 0
    1196626934938|-1||info||No value in environment for: getUsePrefix, using: false
    1196626934938|-1||info||No value in environment for: getAutoflush, using: true
    1196626934938|-1||info||No value in environment for: getExclude, using:
    1196626934938|-1||info||No value in environment for: getExcludecategories, using:
    1196626934938|-1||info||No value in environment for: getFilter, using: false
    1196626934938|-1||info||No value in environment for: getInclude, using:
    1196626934938|-1||info||No value in environment for: getIncludecategories, using: error, info, batch, debug, statement, commit, rollback, result
    1196626934938|-1||info||No value in environment for: getDeregisterDrivers, using: true
    1196626934938|-1||info||No value in environment for: getLogfile, using: c:/TouchPoint/logs/spy.log
    1196626934938|-1||info||No value in environment for: getAppender, using: com.p6spy.engine.logging.appender.FileLogger
    1196626934938|-1||info||No value in environment for: getRealdriver, using: oracle.jdbc.driver.OracleDriver
    1196626934938|-1||info||No value in environment for: getRealdriver2, using:
    1196626934938|-1||info||No value in environment for: getRealdriver3, using:
    1196626934938|-1||info||No value in environment for: getAppend, using: true
    1196626934938|-1||info||No value in environment for: getSpydriver, using: com.p6spy.engine.spy.P6SpyDriver
    1196626934938|-1||info||No value in environment for: getDateformat, using:
    1196626934938|-1||info||No value in environment for: getDateformatter, using: null
    1196626934938|-1||info||No value in environment for: getStringmatcher, using: com.p6spy.engine.common.SubstringMatcher
    1196626934938|-1||info||No value in environment for: getStringMatcherEngine, using: com.p6spy.engine.common.SubstringMatcher@4c334c48
    1196626934938|-1||info||No value in environment for: getStackTrace, using: false
    1196626934938|-1||info||No value in environment for: getStackTraceClass, using:
    1196626934938|-1||info||No value in environment for: getSQLExpression, using: null
    1196626934938|-1||info||No value in environment for: getReloadProperties, using: false
    1196626934938|-1||info||No value in environment for: getReloadPropertiesInterval, using: 60
    1196626934938|-1||info||No value in environment for: getJNDIContextFactory, using: null
    1196626934938|-1||info||No value in environment for: getJNDIContextProviderURL, using: null
    1196626934938|-1||info||No value in environment for: getJNDIContextCustom, using: null
    1196626934938|-1||info||No value in environment for: getRealDataSource, using: jdbc/RealTPDataSource
    1196626934938|-1||info||No value in environment for: getRealDataSourceClass, using: oracle.jdbc.pool.OracleConnectionPoolDataSource
    1196626934938|-1||info||No value in environment for: getRealDataSourceProperties, using: oracleLogFileSizeLimit;0,oracleLogFileCount;1,oracleLogFileName;,oracleLogTraceLevel;INFO,oracle9iLogTraceLevel;2,oracleLogFormat;SimpleFormat,oracleLogPackageName;oracle.jdbc.driver,TNSEntryName;,networkProtocol;,databaseName;,serverName;,portNumber;1521,dataSourceName;,loginTimeout;,description,

    ############ my spy.properties points to a log file that contains this stuff:
    1196626934938|-1||info||reloadProperties() successful
    1196626934953|-1||debug||debug: static void deregister(String className)
    1196626934953|-1||debug||debug: driver [oracle.jdbc.driver.OracleDriver]
    1196626934953|-1||debug||debug: marked for de-registration [oracle.jdbc.driver.OracleDriver]
    1196626934953|-1||debug||debug: driver [com.p6spy.engine.spy.P6SpyDriver]
    1196626934953|-1||debug||debug: found P6 [com.p6spy.engine.spy.P6SpyDriver]
    1196626934953|-1||debug||debug: de-registering [oracle.jdbc.driver.OracleDriver]
    1196626934953|-1||info||deregistering driver oracle.jdbc.driver.OracleDriver
    1196626934953|-1||debug||debug: END OF static void deregister(String className)
    1196626934953|-1||debug||debug: showDriverOrder [com.p6spy.engine.spy.P6SpyDriver]
    1196626934953|-1||debug||debug: showDriverOrder [oracle.jdbc.driver.OracleDriver]
    1196626934953|-1||debug||Registered driver: oracle.jdbc.driver.OracleDriver, realdriver: oracle.jdbc.driver.OracleDriver@5c034c48
    1196626934953|-1||debug||Registered factory: com.p6spy.engine.logging.P6LogFactory with options: null
    1196626934953|-1||debug||Driver manager reporting driver registered: com.p6spy.engine.spy.P6SpyDriver@45050c48
    1196626934953|-1||debug||Driver manager reporting driver registered: oracle.jdbc.driver.OracleDriver@5c034c48

    ##############################
    ##############################  spy.properties, with comments taken out for brevity
    ##############################
    realdriver=oracle.jdbc.driver.OracleDriver
    realdriver2=
    realdriver3=
    deregisterdrivers=true
    executionthreshold=
    outagedetection=false
    outagedetectioninterval=
    filter=false
    include     =
    exclude     =
    sqlexpression =
    autoflush   = true
    dateformat=
    includecategories=error, info, batch, debug, statement, commit, rollback, result
    excludecategories=
    stringmatcher=
    stacktrace=false
    stacktraceclass=
    reloadproperties=false
    reloadpropertiesinterval=60
    useprefix=false
    appender=com.p6spy.engine.logging.appender.FileLogger
    logfile      = c:/TouchPoint/logs/spy.log
    append=true
    log4j.appender.STDOUT=org.apache.log4j.ConsoleAppender
    log4j.appender.STDOUT.layout=org.apache.log4j.PatternLayout
    log4j.appender.STDOUT.layout.ConversionPattern=p6spy - %m%n
    realdatasource=jdbc/RealTPDataSource
    realdatasourceclass=oracle.jdbc.pool.OracleConnectionPoolDataSource
    realdatasourceproperties=oracleLogFileSizeLimit;0,oracleLogFileCount;1,oracleLogFileName;,oracleLogTraceLevel;INFO,oracle9iLogTraceLevel;2,oracleLogFormat;SimpleFormat,oracleLogPackageName;oracle.jdbc.driver,TNSEntryName;,networkProtocol;,databaseName;,serverName;,portNumber;1521,dataSourceName;,loginTimeout;,description,

     
    • Posting to my own thread here...
      I got this to work!  I'm very excited.
      Here is what I did:

      KlausR left a post at this site:
      http://www-128.ibm.com/developerworks/forums/thread.jspa?threadID=104234
      with this timestamp: Mar 06, 2006 08:07:20 AM

      I added this code to the p6spy source on my box, compiled it and jar'd it.
      I used the package com.p6spy.engine.spy and kept KlausR's original name: OracleXADataSource

      1) With an existing (working) Oracle data source in WAS 6.2, I changed the "Implementation class name" from oracle.jdbc.pool.OracleConnectionPoolDataSource to my new com.p6spy.engine.spy.OracleXADataSource.  I did this on the WAS console's "Oracle JDBC Driver" page, "General Properties" section.  I also added the _directory_ of my newly compiled p6spy.jar to the "Class path" section of this same was console page.

      I put my spy.properties file in the IBM\WebSphere\AppServer\properties directory.
      That was it!!! That easy.  Thank you KlausR!!

      Separately, the subject of this post was dead wrong.  I was indeed getting errors, but they were tough to detect.  SystemOut.log -- no errors.  SystemErr.log, no errors.
      I had to go the the profiles\**\logs\ffdc directory to find the actual errors (which I don't have close at hand, sorry -- I think it was the ClassCastException I've seen everyone else run into).

      --Erik

      PS, here is the source from KlausR that I used:

      package com.p6spy.engine.spy;

      import java.sql.SQLException;

      import javax.sql.PooledConnection;
      import javax.sql.XAConnection;

      import oracle.jdbc.xa.client.OracleXADataSource;

      import com.p6spy.engine.spy.P6PooledConnection;
      import com.p6spy.engine.spy.P6SpyDriver;
      import com.p6spy.engine.spy.P6XAConnection;
      import com.p6spy.engine.common.P6LogQuery;

      public class P6SpyOracleDataSource extends OracleXADataSource {

          static {
              try {
                  Class.forName(P6SpyDriver.class.getName());
              } catch (ClassNotFoundException e) {
                  System.err.println("Could not initialize p6 spy!");
              }
          }

          public P6SpyOracleDataSource() throws SQLException {
              super();
              P6LogQuery.logDebug("debug: public P6SpyOracleDataSource()");
          }

          /* (non-Javadoc)
           * @see javax.sql.XADataSource#getXAConnection()
           */
          public XAConnection getXAConnection() throws SQLException {
              P6LogQuery.logDebug("debug: public XAConnection getXAConnection()");
                      return new P6XAConnection(super.getXAConnection());
          }

          /* (non-Javadoc)
           * @see javax.sql.XADataSource#getXAConnection(java.lang.String, java.lang.String)
           */
          public XAConnection getXAConnection(String arg0, String arg1) throws SQLException {
              P6LogQuery.logDebug("debug: public XAConnection getXAConnection(String arg0, String arg1)");
              return new P6XAConnection(super.getXAConnection(arg0, arg1));
          }

          /* (non-Javadoc)
           * @see javax.sql.ConnectionPoolDataSource#getPooledConnection()
           */
          public synchronized PooledConnection getPooledConnection() throws SQLException {
              P6LogQuery.logDebug("debug: public synchronized PooledConnection getPooledConnection()");
              return new P6PooledConnection(super.getPooledConnection());
          }

          /* (non-Javadoc)
           * @see javax.sql.ConnectionPoolDataSource#getPooledConnection(java.lang.String, java.lang.String)
           */
          public synchronized PooledConnection getPooledConnection(String arg0, String arg1) throws SQLException {
              P6LogQuery.logDebug("debug: public synchronized PooledConnection getPooledConnection(String arg0, String arg1)");
              return new P6PooledConnection(super.getPooledConnection(arg0, arg1));
          }

      }

       
    • >>I changed the "Implementation class name" from >>oracle.jdbc.pool.OracleConnectionPoolDataSource to my new >>com.p6spy.engine.spy.OracleXADataSource.
      WHOOPS.  Big mistake.  I'll try again.

      I changed the "Implementation class name" from oracle.jdbc.pool.OracleConnectionPoolDataSource to my new com.p6spy.engine.spy.P6SpyOracleDataSource.

      sorry 'bout that.

      --Erik