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設定檔，讓查詢方法接收到參數，如下：

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE sqlMap PUBLIC "-//ibatis.apache.org//DTD SQL Map 2.0//EN" "http://ibatis.apache.org/dtd/sql-map-2.dtd">
<sqlMap namespace="USERS">
<select id="queryUserList" parameterClass="java.util.Map" resultClass="java.util.HashMap">
        select t.username,t.password,t.enabled from users t
<dynamic prepend="where">
<isNotEmpty prepend="and" property="username">
                t.username = #username#
</isNotEmpty>    
</dynamic>
</select>
</sqlMap>

執行結果如下：

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<String>['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了，這個才是我的重點。