java笔记：自己动手写javaEE框架（三）--引入SQL监控技术P6spy

    最近忙得要死，昨晚写着写着居然睡着了。哎，还是接着写java框架吧。
    任何系统里，日志和一定的监控是相当重要的，在一个软件整个生命周期里维护永远是大头同时是痛苦的，而日志和监控就是为后期维护提供了良好的基础和手段，在java工程里面大多使用log4j来记录系统日志，这个技术几乎所有的java工程师都很熟悉，不太明白了，大家可以查查百度。这里我打算引入一个能监控JDBC执行语句的框架到我写的java框架里面，这个框架非常的好用，他就是p6spy。

　“如果优化SQL语句,如何进行系统调优”，这样的问题我想很多程序员都听到过，优化和调优是一个高难度的技术技能，只有具有扎实的技术功底和多年的项目经验才把他做好。我以前遇到这样的提问，思路很机械，都是从SQL语法，索引，分区，算法来考虑，其实优化和调优程序环境的搭配也是很重要的，例如，现在做java企业级项目，大多使用了orm技术，很少会直接去用jdbc操作数据库，而orm技术对jdbc的封装让最终执行的sql语句的原型离程序员越来越远，因此对jbdc执行的原生态的sql语句的掌控是相当重要的。

   在这里我可以分享一下我的经验。我现在比较推崇ibatis，它既实现了orm思想，又保留了sql语句的使用而不是像hibernate那样对数据库做完全面向对象的映射，而产生了很多新的东西，比如hql。这是一个简便的设计，我觉得系统设计最佳的方案就是新老兼容。其实不同的程序员擅长的技术也不同，做java的程序员当然对java更熟悉，开发数据库的程序员对数据库很在行，假如你现在开发一个后台数据库数据量很大，业务操作很复杂的系统，我这里会首推ibatis技术做orm层，因为这样的大系统到了数据库层面和dba打交道很多，对sql语句以及数据库优化很多，而ibatis直接写sql语句的优点就很明显了，java程序员和dba的沟通和程序的交互也就方便多了。我最近做了几个这样的系统，系统做完后我都会把重要的sql语句从系统里抽取出来给dba优化，而dba优化后我基本只要拷贝到程序里就可以，为整个工作带来了便利。此外系统上线，如果操作数据库报错，在日志里提取sql语句，进行检查，检查后维护程序也是有很大的便利，最后用sql嵌入orm，程序架构的变迁所带来的问题也会少很多，因此我以后开发系统orm技术的首选就是ibatis了。

   但是ibatis执行jdbc是使用prepareStatement，所以最终打印出来的sql语句是下面的格式：

2011-10-13 11:17:36  Connection - {conn-100000} Connection
2011-10-13 11:17:36  Connection - {conn-100000} Preparing Statement:    select t.username,t.password,t.enabled from users t   where         t.username = ?          
2011-10-13 11:17:36  PreparedStatement - {pstm-100001} Executing Statement:    select t.username,t.password,t.enabled from users t   where         t.username = ?          
2011-10-13 11:17:36  PreparedStatement - {pstm-100001} Parameters: [sharpxiajun]
2011-10-13 11:17:36  PreparedStatement - {pstm-100001} Types: [java.lang.String]

我们拷贝出sql语句还要改写，真是烦死人了，那么p6spy就能解决这个问题，它会把?替换成参数，看看我加入了p6spy后执行的效果吧。

|statement| select t.username,t.password,t.enabled from users t where t.username = 'sharpxiajun' 

P6spy使用很简单，只要完成下面步骤就行：
1.将p6spy.jar包放到应用的classpath所在的路径中；
2.修改连接池或者连接配置的jdbc的驱动为p6spy所提供的保证后的驱动，com.p6spy.engine.spy.P6SpyDriver
3.修改spy.properties并将其放到类搜索目录.

下面我们开始开发了。

1.新的工程结构图如下：

新添两个jar包：log4j-1.2.12.jar和p6spy.jar

2.将log4j.properties和spy.properties拷贝到src下面（暂时拷贝到src下面，其实应该放到conf下面，因为现在都是在本地测试，没有发布到tomcat下面，就把两个文件拷贝到默认的路径下）

log4j.properties内容如下：

log4j.debug=true
log4j.rootLogger=INFO,CONSOLE,STDOUT


#-----CONSOLE-----
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss}  %c{1} - %m%n

#-----SQL LOG-----
log4j.logger.java.sql.Connection=DEBUG
log4j.logger.java.sql.Statement=DEBUG
log4j.logger.java.sql.PreparedStatement=DEBUG


log4j.logger.com.ibatis=debug
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

日志打印到控制台里，SQL LOG下的配置表示打印出jbdc以及ibatis的日志。

spy.properties内容如下：

module.log=com.p6spy.engine.logging.P6LogFactory
realdriver=oracle.jdbc.driver.OracleDriver
deregisterdrivers=true
executionthreshold=
outagedetection=false
outagedetectioninterval=
filter=false
include     = 
exclude     =
sqlexpression = 
autoflush   = true
dateformat=
includecategories=
excludecategories=info,debug,result,batch
stringmatcher=
stacktrace=false
stacktraceclass=
reloadproperties=false
reloadpropertiesinterval=60
useprefix=false
appender=com.p6spy.engine.logging.appender.StdoutLogger
append=true
log4j.appender.STDOUT=org.apache.log4j.ConsoleAppender
log4j.appender.STDOUT.layout=org.apache.log4j.SimpleLayout
log4j.appender.STDOUT.layout.ConversionPattern=p6spy
log4j.logger.p6spy=DEBUG,STDOUT

这里只要修改下realdriver=oracle.jdbc.driver.OracleDriver就行。

3.接下来我们只要更改下数据库的驱动就行了，修改下constants.properties，内容如下：

#db.driverClass = oracle.jdbc.driver.OracleDriver
db.driverClass = com.p6spy.engine.spy.P6SpyDriver
db.user        = sharpxiajun
db.password    = sharpxiajun
db.jdbcUrl     = jdbc:oracle:thin:@127.0.0.1:1521:orcl

#db.driverClass = com.mysql.jdbc.Driver
#db.user        = root
#db.password    = root
#db.jdbcUrl     = jdbc\:mysql\://localhost\:3306/sq_xidi?useUnicode\=true&characterEncoding\=utf-8

4.最后修改下USERS.xml配置文件，让查询方法接收到参数，如下：

    
        select t.username,t.password,t.enabled from users t
        
            
                t.username = #username#
                
        
    

执行结果如下：

log4j: Parsing for [root] with value=[INFO,CONSOLE,STDOUT].
log4j: Level token is [INFO].
log4j: Category root set to INFO
log4j: Parsing appender named "CONSOLE".
log4j: Parsing layout options for "CONSOLE".
log4j: Setting property [conversionPattern] to [%d{yyyy-MM-dd HH:mm:ss}  %c{1} - %m%n].
log4j: End of parsing for "CONSOLE".
log4j: Parsed "CONSOLE" options.
log4j: Parsing appender named "STDOUT".
log4j:ERROR Could not find value for key log4j.appender.STDOUT
log4j:ERROR Could not instantiate appender named "STDOUT".
log4j: Parsing for [com.ibatis.common.jdbc.SimpleDataSource] with value=[debug].
log4j: Level token is [debug].
log4j: Category com.ibatis.common.jdbc.SimpleDataSource set to DEBUG
log4j: Handling log4j.additivity.com.ibatis.common.jdbc.SimpleDataSource=[null]
log4j: Parsing for [java.sql.Connection] with value=[DEBUG].
log4j: Level token is [DEBUG].
log4j: Category java.sql.Connection set to DEBUG
log4j: Handling log4j.additivity.java.sql.Connection=[null]
log4j: Parsing for [com.ibatis] with value=[debug].
log4j: Level token is [debug].
log4j: Category com.ibatis set to DEBUG
log4j: Handling log4j.additivity.com.ibatis=[null]
log4j: Parsing for [java.sql.Statement] with value=[DEBUG].
log4j: Level token is [DEBUG].
log4j: Category java.sql.Statement set to DEBUG
log4j: Handling log4j.additivity.java.sql.Statement=[null]
log4j: Parsing for [com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate] with value=[debug].
log4j: Level token is [debug].
log4j: Category com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate set to DEBUG
log4j: Handling log4j.additivity.com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate=[null]
log4j: Parsing for [com.ibatis.common.jdbc.ScriptRunner] with value=[debug].
log4j: Level token is [debug].
log4j: Category com.ibatis.common.jdbc.ScriptRunner set to DEBUG
log4j: Handling log4j.additivity.com.ibatis.common.jdbc.ScriptRunner=[null]
log4j: Parsing for [java.sql.PreparedStatement] with value=[DEBUG].
log4j: Level token is [DEBUG].
log4j: Category java.sql.PreparedStatement set to DEBUG
log4j: Handling log4j.additivity.java.sql.PreparedStatement=[null]
log4j: Finished configuring.
初始化测试类....
2011-10-13 11:17:35  XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [conf/applicationContext.xml]
2011-10-13 11:17:35  GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@2808b3: startup date [Thu Oct 13 11:17:35 CST 2011]; root of context hierarchy
2011-10-13 11:17:35  PropertyPlaceholderConfigurer - Loading properties file from class path resource [conf/constants.properties]
2011-10-13 11:17:35  DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@1de17f4: defining beans [usersDao,userService,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,propertyConfigurer,myDataSource,sqlMapClient,sqlMapClientTemplate,transactionManager,methodServiceAdvisor,org.springframework.aop.config.internalAutoProxyCreator,baseServiceMethods,org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0]; root of factory hierarchy
2011-10-13 11:17:35  MLog - MLog clients using log4j logging.
2011-10-13 11:17:35  C3P0Registry - Initializing c3p0-0.9.1.2 [built 21-May-2007 15:04:56; debug? true; trace: 10]
2011-10-13 11:17:36  AbstractPoolBackedDataSource - Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> 2wyjv28i1xq0ktewu9ral|131303f, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> com.p6spy.engine.spy.P6SpyDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 2wyjv28i1xq0ktewu9ral|131303f, idleConnectionTestPeriod -> 0, initialPoolSize -> 3, jdbcUrl -> jdbc:oracle:thin:@127.0.0.1:1521:orcl, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 15, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 3, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]
2011-10-13 11:17:36  TransactionalTestExecutionListener - Began transaction (1): transaction manager [org.springframework.jdbc.datasource.DataSourceTransactionManager@6db33c]; rollback [false]
测试开始....
进入到了方法拦截器。。。。
调用的service：
cn.com.sharpxiajun.service.impl.UsersServiceImpl@23bdd1
调用的方法:
public abstract java.util.List cn.com.sharpxiajun.service.UsersService.queryUsersList(java.util.Map) throws java.lang.Exception
参数是：
{username=sharpxiajun}
2011-10-13 11:17:36  Connection - {conn-100000} Connection
2011-10-13 11:17:36  Connection - {conn-100000} Preparing Statement:    select t.username,t.password,t.enabled from users t   where         t.username = ?          
2011-10-13 11:17:36  PreparedStatement - {pstm-100001} Executing Statement:    select t.username,t.password,t.enabled from users t   where         t.username = ?          
2011-10-13 11:17:36  PreparedStatement - {pstm-100001} Parameters: [sharpxiajun]
2011-10-13 11:17:36  PreparedStatement - {pstm-100001} Types: [java.lang.String]
|statement| select t.username,t.password,t.enabled from users t where t.username = 'sharpxiajun' 
返回结果是:
[]
拦截器执行结束!!
[]
测试结束!!
|commit|
2011-10-13 11:17:36  TransactionalTestExecutionListener - Committed transaction after test execution for test context [[TestContext@1fac852 testClass = UsersServiceImplTest, locations = array['classpath:conf/applicationContext.xml'], testInstance = cn.com.sharpxiajun.junittest.service.UsersServiceImplTest@1758cd1, testMethod = testQueryUserList@UsersServiceImplTest, testException = [null]]]
2011-10-13 11:17:36  GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@2808b3: startup date [Thu Oct 13 11:17:35 CST 2011]; root of context hierarchy
2011-10-13 11:17:36  DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@1de17f4: defining beans [usersDao,userService,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,propertyConfigurer,myDataSource,sqlMapClient,sqlMapClientTemplate,transactionManager,methodServiceAdvisor,org.springframework.aop.config.internalAutoProxyCreator,baseServiceMethods,org.springframework.aop.support.DefaultBeanFactoryPointcutAdvisor#0]; root of factory hierarchy

看到了这句话了吧|statement| select t.username,t.password,t.enabled from users t where t.username = 'sharpxiajun' ，ok，写完了。

总结下了：java框架的dao和service这块写完了，这个系列下一篇是针对前三篇的技术要点做一下比较详细的解释，做程序不仅要知其然还要知其所以然，这样才能提高。不过下面的博文我会回到javascript，加固一下javascript我在学习中感觉比较难理解的基础知识，之后要继续研究jquery了，这个才是我的重点。