使用log4jdbc輸出SQL語法

簡介

若是在專案開發與偵錯的過程中，難免都會遇到希望列印完整的SQL Command(及prepare statement的value)，這類的solution筆者用過的有P6SPY(https://github.com/p6spy/p6spy)與log4jdbc(https://code.google.com/p/log4jdbc/)，本文介紹其中的log4jdbc。

使用方式(以1.2版為例)

Step 1. 先確認使用的JDK搭配的JDBC版本

• 若為JDK 1.4 or 1.5，請使用搭配的JDBC 3的log4jdbc3-1.2.jar
• 若為JDK 1.6以上版本，請使用搭配的JDBC 4的log4jdbc4-1.2.jar

請注意，不是用jdbc driver本身是type 3 or 4來判斷的！

Step 2. 選擇輸出日誌的框架

log4jdbc是使用SLF4J的Simple Logging Facade來輸出log的，但如同SLF4J，也可以支援log4j, java.util.logging, Apache Commons Logging, Logback。以筆者用的log4j為例，使用時要在classpath內增加以下jar擋：

• slf4j-api-1.6.0.jar
• slf4j-log4j12-1.6.0.jar

Step 3. 將jdbc driver的class name改為net.sf.log4jdbc.DriverSpy

如：

jdbc.driverClass=net.sourceforge.jtds.jdbc.Driver

改寫為：

jdbc.driverClass=net.sf.log4jdbc.DriverSpy

Step 4. 改寫jdbc url，將jdbc:XXXX改為jdbc:log4jdbc:XXX

如：

jdbc.jdbcUrl=jdbc:jtds:sqlserver://localhost:1433/app4use;instance=SQLEXPRESS

改寫為：

jdbc.jdbcUrl=jdbc:log4jdbc:jtds:sqlserver://localhost:1433/app4use;instance=SQLEXPRESS

Step 5. 修改log設定檔案，顯示log4jdbc的訊息

log4jdbc共有以下5個logger可供設定，每一個logger皆可以設定ERROR, INFO, DEBUG層級(FATAL表示關閉)：

• jdbc.sqlonly : 顯示執行的SQL Command
• jdbc.sqltiming : 顯示執行的SQL Command及其耗費時間(若開啟此logger，則jdbc.sqlonly可以不用開)
• jdbc.audit : 顯示除了resultset之外的所有JDBC Calls，會產生大量的log內容
• jdbc.resultset : 顯示resultset的內容，會產生更大量的log內容
• jdbc.connection : 顯示DB Connection的open, close, commit等事件發生的log，在追查connection pool調度問題時相當有用

log4j.properties範例如下：

log4j.rootLogger=INFO, stdout

log4j.logger.jdbc.sqlonly=FATAL, stdout
log4j.logger.jdbc.sqltiming=INFO, stdout
log4j.logger.jdbc.audit=FATAL, stdout
log4j.logger.jdbc.resultset=FATAL, stdout
log4j.logger.jdbc.connection=INFO, stdout

log4j.additivity.jdbc.sqlonly=false
log4j.additivity.jdbc.sqltiming=false
log4j.additivity.jdbc.audit=false
log4j.additivity.jdbc.resultset=false
log4j.additivity.jdbc.connection=false

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{ABSOLUTE} %5p [%t] (%c:%L) - %m%n

執行結果範例

 15:48:12,939  INFO [schedulerFactoryBean_Worker-3] (jdbc.connection:537) - 41. Connection opened
15:48:12,939  INFO [schedulerFactoryBean_Worker-3] (com.tstartel.estore.service.impl.MailMessageRecServiceImpl:126) - doImportJobErrorRec() - start
15:48:12,963  INFO [schedulerFactoryBean_Worker-3] (jdbc.sqltiming:370) - insert into mail_message_rec (mail_from, mail_to, mail_cc_to, subject, mail_type, send_type,
status, expected_sending_time, actual_sending_time, send_numbers, is_attachment, message_content_path,
message_content, create_time) values ('webmaster@company.com.tw', 'user@company.com.tw', '出貨接收回覆作業失敗', NULL, NULL, 10, NULL, NULL, 0, NULL, NULL,
'介接系統：<br />作業名稱：出貨接收回覆作業<br />發生時間：2015/10/20 15:48:11<br />Message：com.jcraft.jsch.JSchException:
java.net.ConnectException: Connection timed out: connect<br />', '10/20/2015 15:48:11.657')
 {executed in 1 msec}
15:48:12,968  INFO [schedulerFactoryBean_Worker-3] (jdbc.connection:556) - 41. Connection closed

Tomcat6 rotate日誌檔catalina.out的方式

Apache Tomcat有一個相當煩人的問題，就是它會把system.out/system.err都輸出至catalina.out檔案中(預設目錄在$CATALINA_HOME/logs)，且這一個catalina.out檔案並不會rotate，檔案會愈長愈大。

要切割此catalina.out的方法，可以使用cronolog幫忙做rotate(因為catalina.out在catalina.sh shell script中是透過 pipe到檔案去做的)；還有一種方式是將catalina.out改用log4j輸出，以下就介紹這個方式的設定步驟：

1. 執行/opt/tomcat6/bin/version.sh，確認tomcat的version。
2. 於http://archive.apache.org/dist/tomcat/tomcat-6/v6.0.37/bin/extras/(要根據步驟1的版號找出正確的網址)下載tomcat-juli.jar與tomcat-juli-adapters.jar，Upload至server上。
3. 於log4j (需1.2之後版本，在此使用1.2.17)下載log4j-1.2.17.jar，Upload 至server上。
4. 停止 tomcat
5. 備份$CATALINA_HOME/bin/tomcat-juli.jar，複製下載的tomcat-juli.jar至此目錄
6. 複製tomcat-juli-adapters.jar至$CATALINA_HOME/lib/目錄
7. 複製log4j-1.2.17.jar至$CATALINA_HOME/lib/目錄
8. 於$CATALINA_HOME/lib/目錄下，建立log4j.properties，範例內容如下：
   log4j.rootLogger=INFO,rollingFile
   
   log4j.appender.rollingFile=org.apache.log4j.DailyRollingFileAppender
   log4j.appender.rollingFile.File=${catalina.base}/logs/catalina
   log4j.appender.rollingFile.Append=true
   log4j.appender.rollingFile.Encoding=UTF-8
   log4j.appender.rollingFile.DatePattern='.'yyyy-MM-dd'.out'
   log4j.appender.rollingFile.layout=org.apache.log4j.PatternLayout
   log4j.appender.rollingFile.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p %c:%L - %m%n
9. 備份$CATALINA_HOME/conf/context.xml
將
<Context>
改為
<Context swallowOutput="true">

10. 啟動 tomcat