Chào mọi người, ở bài trước ([Java] Phần 12 – Log 1: Tầm quan trọng của ghi log trong phát triển phần mềm) mình đã chia sẻ về tầm quan trọng của ghi log và một số nguyên tắc khi ghi log. Bài này mình sẽ hướng dẫn cách tích hợp một module log cơ bản vào ứng dụng. Các bạn nên tập thói quen tích hợp ghi log vào mọi phần mềm từ nhỏ nhất của cá nhân, sẽ thấy sự tiện lợi của nó và phần mềm trở nên chuyên nghiệp hơn, khi làm các phần mềm lớn cũng sẽ thấy quen thuộc và dễ dàng hơn nhiều.
Mình sẽ hướng dẫn cách tích hợp Log4j vào một chương trình Java nhỏ. Trong bài này mình sẽ hướng dẫn cấu hình bằng file XML, các bạn hoàn toàn có thể tìm hiểu và thử cấu hình bằng JSON, YAML, Properties cũng với cấu trúc tương tự. Trong phạm vi bài viết này, để đơn giản nhất có thể nên mình sẽ không sử dụng maven, thay vào đó sẽ dùng cách add lib vào project thông thường 😀
Trước tiên các bạn cần tải gói jar log4j, ở đây mình sẽ sử dụng phiên bản log4j 2.7.
Link download: http://archive.apache.org/dist/logging/log4j/2.7/apache-log4j-2.7-bin.zip
Trong file nén này có rất nhiều gói jar, nhưng để ghi được log thì chỉ cần 2 gói core và api là đủ.
Sau khi có 2 gói jar trên, các bạn add vào project và bắt đầu code. Nếu ai chưa biết các add lib .jar vào project thì tự google nhé, đây là kiến thức cơ bản 🙂
Trước tiên mình tạo 1 file Main.java cho ví dụ này và khai báo một đối tượng logger như đoạn code dưới.
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Main {
static Logger logger = LogManager.getLogger(Main.class);
public static void main(String[] args) {
logger.info("info");
logger.warn("warn");
logger.error("error");
}
}
Sau đó tạo 1 file log4j2.xml và đặt vào thư mục resources của project (phải chính xác tên file và thư mục nhé). Đây sẽ là file cấu hình cho việc ghi log.
Cấu trúc các file như ảnh
Trước mắt mình sẽ cấu hình một appender log đơn giản nhất để ghi ra màn hình console
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout
pattern="%d{yyyy-MM-dd HH:mm:ss a} %highlight{%-5level} [%15.15t] %style{%40C{1.}.%-20M}{cyan} : %msg%n"/>
</Console>
</Appenders>
<Loggers>
<Root level="debug">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
Appenders để khai báo các bộ kết nối giúp định nghĩa ra các cấu hình lưu log ở đâu, định dạng log ra sao.
Ở trên mình đã khai báo 1 appender kiểu Console, đặt tên là Console với đích xuất ra là SYSTEM_OUT nghĩa là màn hình dòng lệnh. Trong đó mình có định nghĩa thêm định dạng 1 dòng log khi xuất ra sẽ bao gồm các thông tin gì.
Các bạn có thể xem chi tiết hơn về các định dạng này tại docs của log4j
https://logging.apache.org/log4j/2.x/manual/layouts.html#PatternLayout
Loggers để khai báo các điều kiện sử dụng appender. Như trên mình đang để điều kiện là log mọi level log từ Debug trở đi sẽ ghi ra Console
Chạy thử chương trình và xem kết quả
2019-07-12 22:56:33 PM INFO [ main] n.t.l.Main.main : info 2019-07-12 22:56:33 PM WARN [ main] n.t.l.Main.main : warn 2019-07-12 22:56:33 PM ERROR [ main] n.t.l.Main.main : error
Mặc dù code trong file Main.java mình chỉ gọi hàm ghi log với các text như “info”, “warn”, “error”. Nhưng log hiển thị ra thì đầy đủ cả thời gian thực thi, log level (INFO, WARN, ERROR), package class, method, khá tiện cho việc xem log. Đó là do cấu hình trong phần PatternLayout
Tương tự mình sẽ cấu hình thêm 1 appender ghi log ra file bằng cách bổ sung thêm appender dưới
<RollingFile name="File" fileName="logs/server.log"
filePattern="logs/$${date:yyyy-MM}/%d{dd}/server.%i.log">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss a} %-5level [%t] %logger{36}.%M : %msg%n"/>
<Policies />
</RollingFile>
Kết quả, với các log ghi ra file thì thường mình để hiển thị đầy đủ package class và không căn chỉnh khoảng trắng để tránh tăng dung lượng thừa
2019-07-12 23:08:58 PM INFO [main] net.tunghuynh.logging.Main.main : info 2019-07-12 23:08:58 PM WARN [main] net.tunghuynh.logging.Main.main : warn 2019-07-12 23:08:58 PM ERROR [main] net.tunghuynh.logging.Main.main : error
Ở appender dành cho log file trên, mình đã cấu hình thêm filePattern để tự động cắt file log theo ngày
Như vậy chỉ cần một vài bước ngắn gọn, bạn đã có thể ghi log theo chuẩn cho chương trình của mình. Nếu muốn rõ ràng hơn, các bạn có thể cấu hình thêm các appender để chia ra thành các file log info, log error, log debug riêng cho dễ kiểm soát và thay thế cho log chung ở trên.
<RollingFile name="FileInfo" fileName="logs/info.log"
filePattern="logs/$${date:yyyy-MM}/%d{dd}/info.%i.log">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss a} %-5level [%t] %logger{36}.%M : %msg%n"/>
<LevelRangeFilter minLevel="INFO" maxLevel="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<Policies />
<RollingFile name="FileWarn" fileName="logs/warn.log"
filePattern="logs/$${date:yyyy-MM}/%d{dd}/warn.%i.log">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss a} %-5level [%t] %logger{36}.%M : %msg%n"/>
<LevelRangeFilter minLevel="WARN" maxLevel="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
<Policies />
<RollingFile name="FileError" fileName="logs/error.log"
filePattern="logs/$${date:yyyy-MM}/%d{dd}/error.%i.log">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss a} %-5level [%t] %logger{36}.%M : %msg%n"/>
<LevelRangeFilter minLevel="ERROR" maxLevel="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
<Policies />
</RollingFile>
Đến đây, bắt đầu thấy các appender có các cấu hình tương tự nhau ví dụ như đường dẫn lưu log, pattern layout, nếu giờ cần sửa sẽ phải sửa từng appender, nên ta có thể khai báo các property định nghĩa giá trị và tái sử dụng trong các appender
<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Properties>
<Property name="patternLayout">%d{yyyy-MM-dd HH:mm:ss a} %-5level [%t] %logger{36}.%M : %msg%n</Property>
<Property name="logPath">logs</Property>
</Properties>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout
pattern="%d{yyyy-MM-dd HH:mm:ss a} %highlight{%-5level} [%15.15t] %style{%40C{1.}.%-20M}{cyan} : %msg%n"/>
</Console>
<RollingFile name="FileInfo" fileName="${logPath}/info.log"
filePattern="${logPath}/$${date:yyyy-MM}/%d{dd}/info.%i.log">
<PatternLayout pattern="${patternLayout}"/>
<LevelRangeFilter minLevel="INFO" maxLevel="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<Policies />
</RollingFile>
<RollingFile name="FileWarn" fileName="${logPath}/warn.log"
filePattern="${logPath}/$${date:yyyy-MM}/%d{dd}/warn.%i.log">
<PatternLayout pattern="${patternLayout}"/>
<LevelRangeFilter minLevel="WARN" maxLevel="WARN" onMatch="ACCEPT" onMismatch="DENY"/>
<Policies />
</RollingFile>
<RollingFile name="FileError" fileName="${logPath}/error.log"
filePattern="${logPath}/$${date:yyyy-MM}/%d{dd}/error.%i.log">
<PatternLayout pattern="${patternLayout}"/>
<LevelRangeFilter minLevel="ERROR" maxLevel="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
<Policies />
</RollingFile>
</Appenders>
.......
</Configuration>
Vậy giờ khi chương trình phát triển lớn lên, số lượng chức năng nghiệp vụ tăng lên, nếu tất cả log vẫn ghi chung vào một file thì sẽ rất khó kiểm soát, đó là lúc ta cần chia log theo các nghiệp vụ cụ thể.
Nhưng không phải mọi nghiệp vụ đều cần tách ra file log riêng, như ở bài trước mình đã đề cập đến ta sẽ tách các log nghiệp vụ quan trọng hoặc xử lý nhiều ra để dễ kiểm soát. Ở đây mình tạo thêm 3 class mới mô phỏng 3 nghiệp vụ phát sinh, và sẽ ghi log 1 class nghiệp vụ làm ví dụ.
public class BusinessA {
Logger logger = LogManager.getLogger(getClass());
public BusinessA(){
logger.info("Info From BusinessA");
logger.warn("Warn From BusinessA");
logger.error("Error From BusinessA");
}
}
public class BusinessB {
Logger logger = LogManager.getLogger(getClass());
public BusinessB(){
logger.info("Info From BusinessB");
logger.warn("Warn From BusinessB");
logger.error("Error From BusinessB");
}
}
public class BusinessC {
Logger logger = LogManager.getLogger(getClass());
public BusinessC(){
logger.info("Info From BusinessC");
logger.warn("Warn From BusinessC");
logger.error("Error From BusinessC");
}
}
Sau đó bổ sung appender ghi log riêng cho class BusinessA và khai báo class sử dụng appender mới tạo
.....
<RollingFile name="LogBusinessA" fileName="${logPath}/business-a.log"
filePattern="${logPath}/$${date:yyyy-MM}/%d{dd}/business-a.%i.log">
<PatternLayout pattern="${patternLayout}"/>
<Policies />
</RollingFile>
.....
<Loggers>
<Logger name="net.tunghuynh.logging.BusinessA" level="debug" additivity="false">
<AppenderRef ref="LogBusinessA"/>
<AppenderRef ref="Console"/>
</Logger>
........
</Loggers>
Ở BusinessA này mình sẽ vừa ghi ra 1 file log riêng và ghi ra màn hình console với level log từ debug trở đi
Kêt quả sẽ vẫn ghi đầy đủ log của cả 3 nghiệp vụ mới thêm trên màn hình console, nhưng log của BusinessA chỉ được ghi vào file business-a.log chứ không xuất hiện trong các file log chung như info.log, warn.log, error.log
Nếu nghiệp vụ của bạn xử lý trong nhiều class thì nên gom nghiệp vụ theo package và hoàn toàn có thể cấu hình log chỉ đến tên package để ghi log toàn bộ class trong package đó
Mọi chuyện cũng không đơn giản như vậy, khi chương trình đã trở thành 1 phần mềm hay ứng dụng lớn, số lượng xử lý tăng lên dẫn đến các file log của từng nghiệp vụ cũng phải ghi nhiều hơn làm cho dung lượng ngày càng lớn, nếu xóa đi thì sẽ mất log, nếu không xóa thì cũng khó khăn trong việc đọc file hay trace log, lúc này ta lại cần phải cắt log.
Để cắt file log thì có 2 cách cắt thông dụng đó là theo dung lượng hoặc theo thời gian, mình thường kết hợp cả 2 cách này. Ví dụ cắt log khi dung lượng vượt quá 10Mb và cắt log theo ngày, mỗi ngày sẽ cắt log 1 lần vào cuối ngày rồi lưu vào thư mục riêng, với các nghiệp vụ có số lượng xử lý quá lớn thì có thể cắt log theo giờ. Ví dụ một appender cấu hình cắt log theo ngày và dung lượng như sau
<RollingFile name="LogBusinessA" fileName="${logPath}/business-a.log"
filePattern="${logPath}/$${date:yyyy-MM}/%d{dd}/business-a.%i.log">
<PatternLayout pattern="${patternLayout}"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="10 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
</RollingFile>
Ngoài ra cũng không thể tránh khỏi trường hợp hệ thống bị spam, hoặc bị 1 lỗi gì đó retry liên tục dẫn đến mặc dù đã cắt log thành nhiều file nhưng số lượng file vẫn sinh ra quá nhiều dẫn đến việc đầy ổ cứng treo máy chủ. Vậy nên ở trên mình đã bổ sung thêm cả cấu hình DefaultRolloverStrategy để chỉ cho phép lưu 10 file trong 1 chuỗi log, nếu vượt quá số lượng file thì sẽ tự động xóa dần các file cũ.
Các giá trị cấu hình này cũng cần sử dụng lại trong các appender khác nên các bạn cũng có thể đưa ra property như ở phần trên.
Như vậy chương trình của các bạn đã được tích hợp module log tiêu chuẩn cơ bản nhất đủ dùng và nhìn chuyên nghiệp hơn rất nhiều.
Đây là bài hướng dẫn tích hợp nên mình upload luôn source cho các bạn tiện tìm hiểu. Ai dùng IntelliJ IDE thì có thể open project là có luôn cấu hình lib trong project 🙂 Các bạn có thể download source ở cuối bài nhé.
Nhưng đó mới chỉ đáp ứng được việc ghi log ra file, đôi khi việc đọc log trong file cũng gặp không ít bất tiện. Ví dụ khi cần kiểm soát các thao tác của user đăng nhập phần mềm, sử dụng các chức năng gì, thao tác dữ liệu gì trên phần mềm, nói chung cần các dữ liệu mang tính liên kết có xâu chuỗi đi theo các session đăng nhập hay luồng nghiệp vụ cụ thể thì sẽ cần lưu log vào một database hoặc một kiến trúc tương tự để thuận tiện cho việc truy vấn dữ liệu.
Bài này đã khá dài rồi nên mình sẽ hướng dẫn ghi log bất đồng bộ vào database ở phần tiếp theo 🙂
