用Log4j記錄log到資料庫,大致上分兩種:
第一 à 使用自動抓取的資訊來源存到對應的欄位
第二 à 使用自行定義的資訊來源存到對應的欄位
我們先看第一點。
(1) 自動抓取資訊的方式
甚麼叫做”自動抓取的資訊”呢?
在log4j產生一筆log時有些資訊是可以讓它自動抓取的,像是其logger的名稱,該筆log的Level,產生log的類別名稱,method名稱,執行緒名稱,log訊息,Log發生的時間點,等等… 這些資訊我們不必自行蒐集或是產生,可以請log4j在產生一筆log的時候,讓它自動去蒐集,我們要做的只是告訴它這筆log的訊息就行了。
我們以一個範例來說明…
[資料庫端]
先在資料庫建立一個用來記錄log的table(這裡我們用MySQL資料庫,架在本機,資料庫叫test_db)
DROP TABLE IF EXISTS `test_db`.`ap_log`;
CREATE TABLE `test_db`.`ap_log` (
`log_id` INT NOT NULL AUTO_INCREMENT,
`logger` VARCHAR(45) NULL DEFAULT NULL,
`log_level` VARCHAR(10) NULL DEFAULT NULL,
`log_msg` VARCHAR(100) NULL DEFAULT NULL,
`log_thread` VARCHAR(45) NULL DEFAULT NULL,
`exception` TEXT NULL DEFAULT NULL,
`class` VARCHAR(45) NULL DEFAULT NULL,
`method` VARCHAR(45) NULL DEFAULT NULL,
`log_date` TIMESTAMP NULL DEFAULT NULL,
`custom_date` VARCHAR(45) NULL DEFAULT NULL,
`user` VARCHAR(45) NULL DEFAULT NULL,
`module_id` INT NULL DEFAULT NULL,
PRIMARY KEY (`log_id`));
|
[Eclipse端]
接著,我們在Eclipse建立一個Java專案,導入以下所需的套件包(我們用的Java版本是1.8.0_161):
[Log4j設定]
然後在Classpath中建立一個log4j的設定檔(Log4j2.xml),然後在設定檔中,加入JDBC的Appender標籤:
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%-5p %d{yyyy-MM-dd HH:mm:ss} [%t] %C{1} (%F:%L) - %m%n" />
</Console>
<JDBC name="MySQLDatabase" tableName="ap_log">
<ConnectionFactory class="log4j2.database.fix_column.ConnectionFactory" method="getConnection" />
<Column name="logger" pattern="%logger" />
<Column name="log_level" pattern="%level" />
<Column name="log_msg" pattern="%m" />
<Column name="log_thread" pattern="%t" />
<Column name="exception" pattern="%throwable" />
<Column name="class" pattern="%C " />
<Column name="method" pattern="%method" />
<Column name="log_date" isEventTimestamp="true" />
<Column name="custom_date" pattern="%d{MM^dd HH^mm^ss.SSS}"/>
</JDBC>
</Appenders>
<Loggers>
<Logger name="log4j2.database.fix_column" level="debug" additivity="false">
<AppenderRef ref="Console" />
<AppenderRef ref="MySQLDatabase" />
</Logger>
<Root level="trace">
<AppenderRef ref="Console" />
<AppenderRef ref="MySQLDatabase" />
</Root>
</Loggers>
</Configuration>
|
其中的各Column標籤,就是對應到資料庫中的欄位,Column標籤的name屬性值必須要和資料庫中的欄位名稱一致,才找得到對應。至於後面的pattern屬性值,則是前面所說的”自動抓取的資訊”,也就是程式中產生log的時候就有的資訊,其中:
%logger就是產生log的logger名稱
%level就是log的等級(trace, debug, info, warn, error, fatal)
%m就是log的訊息資訊
%t就是產生log的執行緒名稱
%C就是產生log的類別名稱
% method就是產生log的method名稱
%d{MM^dd HH^mm^ss.SSS}就是產生log的時間點,以我們自訂的形式寫到資料庫(所以資料庫用varchar欄位,若是一般正常的時間樣式,資料庫可以用TIMESTAMP或是DATETIME格式)
% throwable就是當程式中出現例外的時候,在try-catch中捕捉到了,然後可以將整個Throwable物件當成參數傳到記錄log的方法中。像是:
catch(Exception e){
logger.error("Runtime error..", e);
}
|
其中有一項比較特別的是isEventTimestamp=”true”,它是記錄log發生時的時間點到資料庫欄位。
[AP程式端]
在程式的部份,必須要有一個ConnectionFactory類別,其用來定義上面JDBC Appender的資料庫連線等資訊。
類別完整名稱必須要和上面JDBC Appende標籤中的ConnectionFactory子標籤中class屬性定義的值相同,而類別中必須要有一個method,當log4j要將日誌存到資料庫時,可以從此method得到一個和資料庫的Connection連線。此method名稱也必須和JDBC Appende標籤中的ConnectionFactory子標籤中method屬性定義的值相同。
package log4j2.database.fix_column;
import java.sql.Connection;
import java.sql.SQLException;
import org.apache.commons.dbcp2.BasicDataSource;
public class ConnectionFactory{
private static BasicDataSource dataSource;
private ConnectionFactory() {
}
public static Connection getConnection() throws SQLException{
if(dataSource == null){
dataSource = new BasicDataSource();
dataSource.setUrl("jdbc:mysql://localhost:3306/test_db?useSSL=false");
dataSource.setDriverClassName("com.mysql.cj.jdbc.Driver");
dataSource.setUsername("XXXXX");
dataSource.setPassword("XXXXX");
}
return dataSource.getConnection();
}
}
|
再來建立一個類別(ApMain.class),是程式入口點。
package log4j2.database.fix_column;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class ApMain{
private static final Logger logger = LogManager.getLogger(ApMain.class);
public static void main(String[] args){
logger.info("Start AP.");
try{
int answer= 5/0; //這裡會拋出一個Exception,是除以0所導致
logger.info("answer is : {}", answer); //實際上不會執行到這邊
}catch(Exception e){
logger.error("catch an exception!", e);
}
}
}
|
好了,以上都設定完成之後,執行ApMain這個類別(Run As Java Application),在Console中出現log資訊:
查看一下資料庫ap_log這table,多了log資訊:
再來我們看第二點。
第二點,其實有兩種實作方式,我們兩種都會介紹到。
上面的範例,我們只能寫入一組自訂的訊息到資料庫,有時候不是很方便,因為我們有時會需要記錄更多的自訂訊息,像是”
當次操作的使用者名稱”
以及”
操作了甚麼模組功能”
。當然,這些資訊我們可以統統集合起來,寫到一個log message
欄位,但是這樣會不好閱讀,而且對問題的分析與統計上,也不好實作,我們需要分開欄位去記錄不同的資訊,這在系統的開發與維護過程中很常碰見。
Log4j中有一種機制(MDC,Mapped
Diagnostic Context),讓我們可以達到上述需求,它是基於執行續獨立下運作的,執行續各自儲存資訊,不會互相干涉。
一樣,我們以一個範例來說明…
(2-1) 自行定義資訊的方式 - ThreadContext
[資料庫端]
資料庫的結構定義與上面的範例一樣,所以不再重複列出。
[Eclipse端]
建立專案以及導入的jar套件包都與上面的範例一樣,所以也不再重複列出。
[Log4j設定]
這部份開始做一些調整。
一樣是在Classpath中建立一個log4j的設定檔(Log4j2.xml),但是JDBC的Appender標籤內容與上面範例不同。
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%-5p %d{yyyy-MM-dd HH:mm:ss} [%t] %C{1} (%F:%L) - %m%n" />
</Console>
<JDBC name="MySQLDatabase" tableName="ap_log">
<ConnectionFactory class="log4j2.database.custom_column.ConnectionFactory" method="getConnection" />
<Column name="logger" pattern="%logger" />
<Column name="log_level" pattern="%level" />
<Column name="log_msg" pattern="%m" />
<Column name="log_thread" pattern="%t" />
<Column name="exception" pattern="%throwable " />
<Column name="class" pattern="%C" />
<Column name="method" pattern="%method" />
<Column name="log_date" isEventTimestamp="true" />
<Column name="custom_date" pattern="%d{MM^dd HH^mm^ss.SSS}"/>
<Column name="user " pattern="%X{user}" />
<Column name="module_id " pattern="%X{module_id}" />
</JDBC>
</Appenders>
<Loggers>
<Logger name="log4j2.database.fix_column" level="debug" additivity="false">
<AppenderRef ref="Console" />
<AppenderRef ref="MySQLDatabase" />
</Logger>
<Root level="trace">
<AppenderRef ref="Console" />
<AppenderRef ref="MySQLDatabase" />
</Root>
</Loggers>
</Configuration>
|
設定檔中其它地方是一樣的,只是增加了兩個Column標籤(user和module_id)。
注意這兩個新增的Column標籤的pattern的屬性值,它們與其它的不一樣,是以%X{key}的形式來定義。其{}中的key,是一組Map結構中的key值,log4j在產生log的時候,會根據此key值找出屬於它的value,將此value寫到資料庫對應的欄位底下。
[AP程式端]
在程式的部份,一樣要有一個ConnectionFactory類別,這和上面的範例相同,所以不再重複列出。
再來建立一個類別(ApMain.class),是程式入口點,這類別和上面範例大同小異,只是修改/增加了黃底的部份。
package log4j2.database.custom_column;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;
public class ApMain{
private static final Logger logger = LogManager.getLogger(ApMain.class);
public static void main(String[] args){
ThreadContext.put("user", "David");
ThreadContext.put("module_id", "5");
logger.info("Start AP.");
try{
int answer= 5/0; //這裡會拋出一個Exception,是除以0所導致
logger.info("answer is : {}", answer); //實際上不會執行到這邊
}catch(Exception e){
ThreadContext.put("user", "James");//會覆蓋掉相同key的value
logger.error("catch an exception!", e);
}
ThreadContext.clearAll();//把內容清空
}
}
|
基本上是增加了ThreadContext這個類別的使用。
ThreadContext這個類別有點像是Map集合的結構,可以透過它的靜態put()函式在其中放入多組key-value,這樣在透過logger產生一個log記錄的時候,就會根據ThreadContext裡面的key值,找到設定檔中JDBC Appender中所對應的Column標籤,就知道要把value寫入的是資料庫中的哪一個欄位了。
運行ApMain之後,在Console中看到:
資料庫的情況:
要注意的是:
- ThreadContext的內容會一直保存,如果沒有透過呼叫其ThreadContext.clearAll()來把內容清除,每一次當logger建立一筆log記錄的時候,都會把ThreadContext的內容重新寫一遍到資料庫中。
- 如果放入已經存在的key值到ThreadContext中,會以新的value覆蓋掉舊的value。
- 如果資料庫中對應的欄位是數值型態(例如int,numeric等),而不是字串型態,在ThreadContext放入對應的Key-Value值的時候,將value值得數值當成字串放入(例如4寫成”4”),這樣log4j在寫入對應的資料庫欄位的時候,會自動轉成數值型態寫入(測試後MySQL的官方Java驅動包mysql-connector-java-xxx.jar和Sybase的官方Java驅動包jcon4.jar都會自動轉成數值,但是Sybase的非官方區Java驅動包jtds1.3.1.jar不會自動轉成數值寫到資料庫,導致資料庫拋出錯誤寫不進去)。
- 如果log4j設定檔中的JDBC Appender有設定該Column欄位標籤,但是程式中沒有放對應的Key-Value值到ThreadContext類別中,這樣預設會寫入空字串到對應的欄位(不是寫null值),這裡要注意的是,如果資料庫中的對應欄位是數值型態,像是int,或是numeric,log4j要寫入空字串時就會發生錯誤寫不進去。
(2-2) 自行定義資訊的方式 - StringMapMessage
使用自訂的資訊來源存到資料庫中對應的欄位的實作方式還有一種,除了使用ThreadContext外,就是使用StringMapMessage類別來達成。
使用StringMapMessage類別需在log4j設定檔中的JDBC Appender中搭配ColumnMapping標籤來實作。程式中以logger寫入log記錄的寫法亦需調整。
我們一樣以一個範例來說明…
[資料庫端]
資料庫的結構定義與上面的範例一樣,所以不再重複列出。
[Eclipse端]
建立專案以及導入的jar套件包都與上面的範例一樣,所以也不再重複列出。
[Log4j設定]
一樣是在這部份開始做一些調整。
一樣是在Classpath中建立一個log4j的設定檔(Log4j2.xml),但是JDBC的Appender標籤內容與上面範例不同。主要是加入了ColumnMapping標籤。一樣,我們在修改/增加的部份,以黃底標記。
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%-5p %d{yyyy-MM-dd HH:mm:ss} [%t] %C{1} (%F:%L) - %m%n" />
</Console>
<JDBC name="MySQLDatabase" tableName="ap_log">
<ConnectionFactory class="log4j2.database.custom_column.ConnectionFactory" method="getConnection" />
<ColumnMapping name="logger" pattern="%K{logger}" />
<ColumnMapping name="log_msg" pattern="%K{message}" />
<ColumnMapping name="log_thread" pattern="%K{thread}" />
<ColumnMapping name="exception" pattern="%K{exception}" />
<ColumnMapping name="class" pattern="%K{class} " />
<ColumnMapping name="custom_date" pattern="%d{MM^dd HH^mm^ss.SSS}"/>
<ColumnMapping name="user" pattern="%K{user}" />
<ColumnMapping name="module_id" pattern="%K{module_id}" />
<Column name="log_level" pattern="%level" />
<Column name="method" pattern="%method" />
<Column name="log_date" isEventTimestamp="true" />
<!-- <Column name="exception" pattern="%throwable" /> 程式中使用logger.error(Message msg, Throwable t)會有問題-->
<!-- 見下面[要注意的部份]第6點說明-->
</JDBC>
</Appenders>
<Loggers>
<Logger name="log4j2.database.fix_column" level="debug" additivity="false">
<AppenderRef ref="Console" />
<AppenderRef ref="MySQLDatabase" />
</Logger>
<Root level="trace">
<AppenderRef ref="Console" />
<AppenderRef ref="MySQLDatabase" />
</Root>
</Loggers>
</Configuration>
|
ColumnMapping標籤跟Column標籤一樣,它的name屬性值對應到資料庫table中的一個欄位,所以屬性值必須跟table中欄位一樣才對應得到,所以一個ColumnMapping標籤對應到資料庫table的一個欄位。
至於ColumnMapping標籤中的pattern屬性值,是以%K{key}的形式來定義。其{}中的key,是一組Map結構中的key值,log4j在產生log的時候,會根據此key值找出屬於它的value,將此value寫到資料庫對應的欄位底下,這部份跟上一個範例差不多,只是上一個範例是用ThreadContext,這次不是,改用StringMapMessage。
ColumnMapping標籤跟Column標籤,兩者是可以並存的。所以哪些欄位要用Column標籤實作,哪些欄位要用ColumnMapping標籤實作,視情況與個人喜好。
[AP程式端]
在程式的部份,一樣要有一個ConnectionFactory類別,這和上面的範例相同,所以不再重複列出。
再來建立一個類別(ApMain.class),是程式入口點,這類別和上面範例不太一樣,主要是因為很多欄位值,我們可以視自己需要,自行”組裝”出來,跟上面的範例異動頗大,就不以黃底標記異動的部份了。
package log4j2.database.custom_column;
import java.util.HashMap;
import java.util.Map;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.StringMapMessage;
public class ApMain{
private static final Logger logger = LogManager.getLogger(ApMain.class);
public static void main(String[] args){
StringMapMessage mapMessage = getMapMessage("Start AP.", null);
logger.info(mapMessage);
try{
int answer= 5/0; //這裡會拋出一個Exception,是除以0所導致
logger.info("answer is : {}", answer); //實際上不會執行到這邊
}catch(Exception e){
mapMessage = getMapMessage("catch an exception!", e);
// logger.error(mapMessage, e);//會有問題,見下面[要注意的部份]第6點說明
logger.error(mapMessage);
}
}
private static StringMapMessage getMapMessage(String logMessage, Exception e){
Map<String, String> map = new HashMap<>();
map.put("logger", logger.getName());
map.put("message", logMessage);
map.put("thread", Thread.currentThread().getName());
map.put("class", ApMain.class.getName());
map.put("user", "Ryan");
map.put("module_id", "11");
if(e != null){
String exceptionValue = parseStackTrace(e);
map.put("exception", exceptionValue);
}
return new StringMapMessage(map);
}
/**
* 自行將例外的StackTrace組合成一個字串
*/
private static String parseStackTrace(Exception e){
if(e == null || e.getStackTrace() == null){
return "";
}
StringBuilder sb = new StringBuilder();
StackTraceElement[] stackTrace = e.getStackTrace();
sb.append("--> " + e.getClass().toString() + " : " + e.getMessage());
for(int i = 0; i < stackTrace.length; i++){
sb.append("\n" + "\t" + stackTrace[i].toString());
}
return sb.toString();
}
}
|
程式中主要是透過StringMapMessage類別,它類似Map集合物件的特性,可以將一組Key-Value值放入其中,而log4j就是透過該StringMapMessage類別物件中的key值,對應到設定檔中的ColumnMapping標籤,就知道該Key所對應的Value值,要寫到資料庫中的哪一個欄位了。
與ThreadContext不同的是,操作StringMapMessage的這種方式,logger一次是操作一個StringMapMessage類別的物件,將該StringMapMessage物件中的Key-Value值寫入該筆log的記錄中,除非產生log時是傳入相同一個StringMapMessage物件並且其內容都是一樣的,否則一次logger產生的log的值,不會留到下一次,因為下一次會是傳入另一個StringMapMessage物件。
運行ApMain之後,在Console中看到:
要注意的部份:
- ColumnMapping標籤沒有isEventTimestamp的屬性。
- 如果放入已經存在的key值到StringMapMessage中,會以新的value覆蓋掉舊的value。
- 如果資料庫中對應的欄位是數值型態(例如int,numeric等),而不是字串型態,在StringMapMessage放入對應的Key-Value值的時候,將value值得數值當成字串放入(例如4寫成”4”),這樣log4j在寫入對應的資料庫欄位的時候,會自動轉成數值型態寫入(測試後MySQL的官方Java驅動包mysql-connector-java-xxx.jar和Sybase的官方Java驅動包jcon4.jar都會自動轉成數值,但是Sybase的非官方區Java驅動包jtds1.3.1.jar不會自動轉成數值寫到資料庫,導致資料庫拋出錯誤寫不進去),這部份和上一個範例使用ThreadContext的情況是一樣的。
- 如果log4j設定檔中的JDBC Appender有設定該ColumnMapping欄位標籤,但是程式中沒有放對應的Key-Value值,這樣預設會寫入空字串到對應的欄位(不是寫null值),這裡要注意的是,如果資料庫中的對應欄位是數值型態,像是int,或是numeric,log4j要寫入空字串時就會發生錯誤寫不進去。
- 設定檔中ColumnMapping標籤的pattern屬性值除了使用%K{key}方式定義,用${key}方式的效果是一樣的,例如%K{message}也可以寫成${message}
<ColumnMapping name="message" pattern="%K{message}"/>也可以寫成
<ColumnMapping name="message" pattern="${message}"/>
- 雖然設定檔中ColumnMapping標籤與Column標籤是可以並存的,但是當我們想在設定檔中以Column的方式定義將捕捉到的例外(Exception)寫到資料庫對應欄位的時候,像下面這樣:
<Column name="exception" pattern="%throwable" />而在程式中呼叫logger的產生log的函式時,比如用
Logger.error(Message msg, Throwable t)的方式,傳入StringMapMessage物件和捕捉到的Exception物件,資料庫會拋出錯誤無法寫入該筆log記錄:
Caused by: com.mysql.cj.jdbc.exceptions.MysqlDataTruncation: Data truncation: Data too long for column 'logger' at row 1
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:97)
at com.mysql.cj.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:1983)
at com.mysql.cj.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1826)
at com.mysql.cj.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2034)
at com.mysql.cj.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1712)
... 23 more
這是在資料庫版本MySQL 5.6.17下,AP程式用MySQL的官方Java驅動包版本mysql-connector-java-6.0.6.jar,log4j套件包版本是log4j-api-2.10.0.jar和log4j-core-2.10.0.jar,以及搭配commons-dbcp2-2.1.1.jar,commons-logging-1.2.jar,commons-pool2-2.8.0.jar所測得的結果。
再拿Sybase
ASE 15.7測試,jconn4.jar,log4j-api-2.1.10.0.jar,log4j-core-2.1.10.0.jar,commons-dbcp2-2.1.1.jar,commons-logging-1.2.jar,commons-pool2-2.8.0.jar測試相同的情況,一樣拋出錯誤無法儲存。
至於其它類型的資料庫會不會發生這問題就沒再去試了,上面範例中我們換成採用Logger.error(Message msg),這樣變成Exception訊息的資料庫欄位的內容值,我們要自行將Exception的StackTrace訊息解析出來組合成字串,然後透過ColumnMapping的方式寫入資料庫。
將使用自訂的資訊來源存到對應的欄位的兩種設定方式的格式,整理一下資訊:
- 以Column標籤定義,並其pattern屬性值是以%X{key}的形式定義,就是抓取ThreadContext中的值
- 以ColumnMapping標籤定義,並其pattern屬性值是以%K{key}或者是以${key}的形式定義,就是抓取StringMapMessage中的值