Logging and Logging Best Practices

Đặng Tùng Lâm

3418

18-10-2021

Hôm nay là thứ bảy, thời tiết khá mát mẻ, tôi vừa pha được một ly espresso và ngồi vào bàn làm việc để chuẩn bị tiếp tục chạy những deadline mà tôi đã miss từ hôm qua. Đột nhiên tôi lại nhớ tới một câu chuyện mà anh Long - Trưởng nhóm dev công ty B có kể với tôi, câu chuyện về log mà tôi nhớ mãi.

Tối ngày chủ nhật tuần trước, anh Long đang chơi với con trai thì nhận được một cuộc điện thoại. Tùng (một Junior developer trong nhóm anh quản lý) nói với giọng gấp gáp:

"Toang rồi anh ơi, tính năng thằng Vương làm đẩy lên từ hôm trước mà nay ko chạy được nữa? Mà hôm nay nó bị bế đi cách ly rồi, giờ phải làm sao anh, khách hàng đang than nhiều quá?".

Anh Long đúng không hổ danh là một senior khét tiếng, anh bình tĩnh nói với Tùng:

"Em bình tĩnh, chuyện gì cũng giải quyết được mà, chỉ cần có log là đoán được bệnh thôi".

Tùng tiếp tục trả lời:

"Nhưng anh ơi, thằng Vương nó ko viết log gì hết, em check file log thì không thấy gì ngoài cái exception cả"

Tùng vừa dứt lời, anh Long mất bình tĩnh, mở máy lên và cùng Tùng đọc lại code, tìm lỗi và xử lý đến 2h sáng mới xong. Ngay trong buổi họp giao ban ngày thứ 2, vì sự cố này mà công ty đã bị giảm uy tín trong mắt khách hàng còn anh Long bị khiển trách.

Cả anh Long và Tùng đều rất mệt mỏi. Nếu như Vương chịu khó viết log lại luồng chạy của app, mọi chuyện đã không ra nông nỗi đó, anh Long đã có thể phán đoán lỗi mà không cần đọc lại code, công ty cũng không thiệt hại nặng nề.

Anh Long lập tức mở một cuộc họp gấp với team, đặt vấn đề và cùng cả nhóm đưa ra những best practices, những khẩu quyết, được chắt lọc bởi các developers đầy kinh nghiệm trong nhóm về tầm quan trọng của logging trong quá trình xây dựng và bảo trì các ứng dụng, cũng như là những kinh nghiệm sử dụng logging trong các dự án. Anh Long không muốn một sự việc tương tự như vậy xảy ra lần nữa.

Từ câu chuyện của anh Long, chúng ta đặt ra câu hỏi log là gì mà quan trọng vậy. Tại sao vì không có log mà một senior khét tiếng như anh Long phải chật vật đến 2h sáng mới xong? Và các best practices được anh Long và team của mình rút ra là gì?

Để trả lời cho những câu hỏi đó, tôi sẽ chia sẻ với mọi người những khái niệm, tầm quan trọng của logging và các cách vận dụng logging trong dự án mà tôi, anh Long cũng như là cả team dev ở công ty B đã rút ra.

1 Giới thiệu về logging

1.1 Logging là gì?

Logging được hiểu đại loại là quá trình thu thập và lưu lại dữ liệu của phần mềm trong một khoảng thời gian.

Logging xuất hiện ở xung quanh ta, mọi ứng dụng, thiết bị điện tử lớn tới nhỏ đều có log ghi lại các hoạt động, sự kiện của thiết bị/phần mềm.

Ví dụ như khi sử dụng hệ điều hành Windows, đôi khi phần mềm ta sử dụng gặp lỗi gì đó. Phần mềm bị tắt đột ngột, một thông báo được hiện lên cảnh báo về việc ứng dụng lỗi và hỏi chúng ta có gửi các thông tin chuẩn đoán lỗi cho đội ngũ lập trình không. Việc gửi các thông tin chuẩn đoán lỗi đó chính là gửi các file log cho Microsoft để lập trình viên của Windows biết được nguyên nhân lỗi do đâu và có các bản vá thích hợp.

1.2 Tầm quan trọng của logging

Các dữ liệu từ quá trình logging có thể được coi là dấu vết khi cần phải điều tra nguyên nhân nếu xảy ra lỗi phần mềm.

Ngoài việc được sử dụng để chuẩn đoán lỗi, các dữ liệu log còn được sử dụng trong quá trình phân tích hành vi, thói quen của người sử dụng, từ đó đưa ra các chiến lược kinh doanh.

Trong một chiếc máy bay hiện đại, luôn có một thiết bị được gọi là hộp đen. Thiết bị này ghi lại các cuộc hội thoại của phi công, chỉ số của máy bay, độ cao, nhiệt độ, vân vân liên tục trong suốt quá trình cất cánh đến hạ cánh. Mọi thông tin được ghi lại đều là các thông tin thể hiện trạng thái của máy bay trong quá trình hoạt động. Khi máy bay gặp sự cố, thứ đầu tiên mà các cơ quan điều tra phải tìm cho bằng được chính là hộp đen của máy bay. Hộp đen của máy bay là thứ duy nhất có thể cho ta biết điều gì đã xảy ra khi máy bay gặp nạn.

Tưởng tượng phần mềm của chúng ta là chiếc máy bay đó, thì các file logs chính là hộp đen. Và quá trình logging chính là việc thu thập và ghi lại toàn bộ thông tin của app vào các file logs. Tương tự là khi một ứng dụng gặp lỗi, thứ đầu tiên mà các lập trình viên cần tìm sẽ là file log. Đọc nội dung file log giúp người đọc giả lập lại được ngữ cảnh khi sự cố xảy ra.

Như trong câu chuyện của anh Long ở đầu bài, vì không có được các thông tin cần thiết từ log để dựng lại được ngữ cảnh sự cố, anh Long và Tùng đã phải ngồi đọc lại code, cố gắng "chạy code trong đầu" để mường tượng chuyện gì đã xảy ra. Chính vì việc này đã gây ra khó khăn trong quá trình tìm lỗi.

Vậy nên việc logging là cực kì quan trọng trong quá trình phát triển phần mềm. Nhưng logging lại bị một số các lập trình viên xem nhẹ. Một phần cũng là do các lập trình viên này nghĩ là debugging đã là đủ, nhưng ở trên môi trường production, ta không thể chạy debugging như khi ta dev ở dưới localhost, lúc này, thứ duy nhất có thể giúp ta tìm lỗi là các dòng log.

2 Các best practices khi logging

Sau khi biết được tầm quan trọng của việc logging trong quá trình phát triển phần mềm. Tôi sẽ chia sẻ lại các "lưu ý" hay best practices khi logging.

Toàn bộ các lưu ý dưới đây đều là "nên làm".

Không áp dụng các lưu ý không khiến code của bạn chạy sai. Nhưng nếu áp dụng tốt, quá trình điều tra lỗi, xử lý sự cố của bạn sẽ dễ chịu hơn rất nhiều.

2.1 Mọi người đều nên log

Nếu có người hỏi tôi: "Ai thì nên thực hiện ghi log?", tôi sẽ trả lời: "Tất cả, bạn, tôi, và mọi người".

Log là quan trọng với mọi người, từ Developer, Devops Engineer tới System Admin. Logging hợp lý sẽ là cách cực hiệu quả để tăng hiệu suất làm việc. Developer sẽ tránh phải đọc lại code để tìm hiểu nguyên nhân lỗi. Devops Engineer sẽ đọc code và biết nguyên nhân của lỗi do đâu, lỗi ở scope nào, bug của ông dev hay là lỗi khi triển khai deploy. Sysadmin cũng tương tự, chuẩn đoán lỗi từ log của các package và hệ điều hành là vô cùng quan trọng.

2.2 Lưu log càng lâu càng tốt

Trả lời cho câu hỏi: "Log nên được lưu trong bao lâu và lưu ở đâu?".

Điều này tùy thuộc vào tính chất, nghiệp vụ của phần mềm. Giả sử như những log về event click của user trên UI, hay là access log của api. Sau một thời gian, log trên có thể được doanh nghiệp sử dụng data mining để phân tích rồi. Hoặc để tiết kiệm ổ cứng, chúng nên được xóa đi. Có thể là 3 tháng, 6 tháng. Tùy thuộc mức độ quan trọng

Có nhiều loại log có thể lưu cả đời. Những hệ thống thanh toán, tính tiền, lịch sử đăng nhập. Đây là những thông tin tối quan trọng với khách hàng. Nó nên được lưu trữ lâu dài.

Dữ liệu log là dữ liệu rất quan trọng, có nhiều cách để lưu trữ log.

• Lưu vào trực tiếp ổ cứng của server đang chạy dịch vụ.
  • Với cách lưu này, một best practice là nên lưu log ở ổ cứng khác với ổ cứng chạy service. Việc lưu như vậy để tránh việc ghi log làm ảnh hưởng tới hiệu năng đọc ghi của service.
  • Ví dụ những database có tần suất ghi dữ liệu lớn như mysql, ngoài việc ghi record vào các file data, database còn lưu log, lượng log mà database ghi là rất lớn. Lưu log chung ổ cứng với data có thể làm giảm khả năng ghi của db.

• Lưu tập chung vào các cơ sở dữ liệu chuyên lưu log.
  • Giải pháp này thường được các công ty có số lượng dịch vụ lớn, các dịch vụ được triển khai trên rất nhiều máy chủ khác nhau, việc quản lý log cho hệ thống phân tán như vậy cần được quy hoạch về kho log tập chung, đảm bảo dễ theo dõi, tìm kiếm log khi xảy ra sự cố.
  • Các cơ sở dữ liệu dạng timeseries như Prometheus, Elasticsearch, Mongodb,... sẽ giải quyết được nhu cầu này.

2.3 Nên dùng các thư viện logging được nhiều người sử dụng

Thực sự là bạn không nên và không cần phải tự viết một thư viện mở file, ghi log trong khi cộng đồng đã có quá nhiều sự lựa chọn. Python bạn có built-in logging, loguru, Java thì bạn có log4j...

Các ngôn ngữ lập trình phổ biến hiện nay đều có các thư viện logging được viết sẵn, được sử dụng bởi nhiều phần mềm và lập trình viên. Code đã được test ở nhiều môi trường và hoàn cảnh. Cũng như code đã được tối ưu.

Nếu bạn không thể đảm bảo thư viện bạn viết mới ra có ưu điểm vượt trội so với hàng có sẵn thì nên dừng lại. Không nên phát minh ra bánh xe nữa(Don’t Reinvent the Wheel)

2.4 Nên viết log với một log level thích hợp

Một câu hỏi khó mà luôn hiện lên mỗi khi chúng ta muốn ghi log sẽ là: "Mình sẽ dùng log level nào đây".

Việc chọn log level phụ thuộc nhiều vào kinh nghiệm của lập trình viên.

Nhưng tôi cũng chia sẻ cách mình chọn log level để mọi người có thể tham khảo. Tôi dựa vào cách tiếp cận được nói đến trong document của python

2.5 Nên viết log message có ý nghĩa

Theo tôi một log message có ý nghĩa thì cần trả lời được các câu hỏi sau:

• Who: Dòng log đó dành cho ai hay ai gây ra?
  • Có thể là class name, hay user id, hay email, IP.
  • Các thông tin cho biết log này tác động tới cái gì. tác động tới ai, hay tác động bởi ai.

• When: Log này xuất hiện khi nào?
  • Log phải có timestamp dạng ISO8601 và dạng integer để có thể cho người đọc biết log được tạo ra khi nào, timestamp cũng dùng để profiling cho app, nếu log trước tới log sau quá lâu chứng tỏ app cần phải tối ưu.

• What: Log này chứa nội dung chính là gì?
  • Message chứa thông tin cần thiết của logic đó
  • Exception trace back của lỗi
  • Các event nhận được từ user
  • ...

• Where: Log này xuất hiện ở file nào, process, thread nào?
  • Thông tin về nơi xuất hiện log cũng rất quan trọng, giúp ta khoanh vùng đơn giản hơn. Nếu toàn bộ log đều hiển thị mà ko có vị trí cụ thể, ta sẽ ko biết nó ở file nào để vào xem. gây mất thời gian. Nên cung cấp tên file hay tên module vào log.
  • Ngoài ra nếu ứng dụng sử dụng multiple threading hay multiple processing thì có thể log thêm process id hay thread id.
  • Có thể thêm các thông tin bổ xung như server name, worker id, request id

Ví dụ:

• Log 1

[2021-10-17 18:23:09,022]-[1634469789.022384] - ERROR - Transaction failed 

• Log 2

[2021-10-17 18:23:09,022]-[1634469789.022384] - ERROR - billing.payment_services.topup - [Transaction=202010] failed: The balance is not enough 

Log 1 và Log 2 đều cùng một mục đích là thông báo giao dịch thất bại. Nhưng Log 1 vô nghĩa, vì mình không thể xác định được giao dịch nào thất bại, tại sao lại thất bại.

Log 2 thì khác, trả lời đầy đủ được 4 câu hỏi. Dựa vào đó ta có thể xác định context của lỗi. Ta có thể hình dung ra được ngay lỗi này là nguyên nhân gì, xảy ra ở module nào. bị ảnh hưởng tới giao dịch nào.

2.6 Nên viết log thân thiện với máy tính

Chúng ta thường hay log ở dạng plain text. Với cách này, con người có thể đủ thông minh để đọc được. Nhưng lại không thân thiện với máy tính lắm.

Thông thường nếu app nhỏ, việc đọc log check log thực hiện thủ công thì không ảnh hưởng. Chúng ta là con người, có thể dễ dàng hiểu log dù nó không có một định dạng nhất định.

Nhưng khi app lớn, được deploy ở hàng trăm hàng nghìn server, việc đọc log thủ công sẽ khó hay bất khả thi. Lúc này sẽ có các agent lắng nghe log từ các server này và đưa về server log tập chung. Lúc này nếu log của chúng ta không có định dạng thân thiện với máy tính thì sẽ rất khó tích hợp

Ví dụ:

Có 2 dòng log như sau

Log 1:

[2021-10-17 18:23:10,024]-[1634469790.024863] - ERROR - name: someone is invalid  

Log 2:

{"asctime": "2021-10-17 18:23:10,024", "created": 1634469790.024863, "levelname": "INFO", "message": "Invalid name", "extra": {"name": "someone"}}  

Với kiểu Log 1 chúng ta sẽ phải định nghĩa pattern cho log, rồi dùng regex để bắt, bóc tách rất phức tạp. Lỡ có ai log không đúng pattern là mất log hoặc lỗi.

Còn với kiểu Log 2, sử dụng JSON giúp ích rất nhiều đối với máy. Các ngôn ngữ lập trình đều có sẵn parser JSON. Việc của máy chỉ cần đọc từng dòng và dùng parser đó parse đoạn string dạng JSON mà không cần quan tâm tới các patterns phức tạp.

2.7 Nên viết log thân thiện với người đọc

Các file log đúng là cần thân thiện với máy. Nhưng đồng thời cũng phải thân thiện với người đọc 😵‍💫

Vì ngoài máy ra thì chúng ta, những maintainer cũng là những người đọc log thường xuyên. Tưởng tượng cảnh 3h sáng đi truy vết lỗi lại phải đọc những dòng log toàn những ký tự vô nghĩa, datetime thì format loạn xạ. Lỗi nhưng lại không thấy trace back đâu thì stress lại càng thêm stress.

Cuộc sống vốn đã đầy stress, chúng ta không nên tạo thêm stress cho nhau. Chúng ta đọc log cũng thường chỉ chú ý vài vấn đề như log timestamp, log level, và message. Để dễ đọc thì chúng ta chỉ cần làm các thông tin này trở nên dễ đọc. Một số gợi ý như:

• Sử dụng chuẩn format datetime ISO8601

• Sử dụng đúng và hợp lý log level.

• Nếu là log lỗi thì nên show stack trace thay vì ẩn đi để tiết kiệm storage 😌

2.8 Viết log không chỉ để tìm lỗi

Như đề cập ở phần 1.2 khi nói về tầm quan trọng của log, log không chỉ được dùng để tái hiện lại lỗi. Log ngoài việc phục vụ cho nhu cầu tìm lỗi, còn được sử dụng vào các mục đích khác như:

• Đối soát dữ liệu: Ý tưởng của việc vận dụng logging vào đối soát dữ liệu là có thể lưu các action của người dùng như đăng nhập, nạp tiền, rút tiền, thanh toán... Dựa vào log này sẽ có thể có các dịch vụ trích xuất log từ đây để thực hiện các logic đối soát các hoạt động của người dùng. Phát hiện người dùng bị hack từ hoạt động bất thường.

• Backup dữ liệu: Mô hình lưu lại các thay đổi dữ liệu vào file log đã được các hệ quản trị cơ sở dữ liệu ứng dụng từ lâu. Ví dụ như MySQL có binlog, PostgreSQL cũng có WAL

• Đo hiệu năng của phần mềm: Bằng việc log thêm thông tin timestamp, ta có thể dựa vào khoảng thời gian giữa log trước tới log sau để biết được thời gian thực hiện của đoạn code đó.

• Thống kê & phân tích dữ liệu: Phân tích dữ liệu từ log sự kiện của người dùng, như các sự kiện click chuột, hover hay các thông tin khác để phân tích hành vi, dựa vào đó có chiến lược kinh doanh hợp lý hơn.

2.9 Không được log các thông tin nhạy cảm

Tuyệt đối trong log của bạn không được để lộ các thông tin nhạy cảm của server hoặc người dùng.

Các thông tin có thể là:

• Passwords

• Các thông tin thẻ ngân hàng

• Private key, Secret Key

• Access Token

• Thông tin của khách hàng như email, tên, số điện thoại, địa chỉ...

Các hacker toàn toàn có thể chiếm quyền server lưu log và dựa vào log để thu thâp các thông tin nhạy cảm. Để phòng tránh tối đa nguy cơ bị khai thác thông tin từ log, một số ngân hàng và doanh nghiệp tài chính thậm trí còn mã hóa log của mình 😎

3 Kết luận

Qua ví dụ về câu chuyện của anh Long ở công ty B, chúng ta cũng đã tìm hiểu được

• Logging là một quá trình lưu lại dấu vết, dữ liệu để phục vụ các nhu cầu tái hiện lỗi và phân tích hành vi

• Log thực sự rất quan trọng, nó được coi như hộp đen của phần mềm. Mọi thông tin ghi vào log đều quý giá và cần được lưu trữ có kế hoạch, cẩn thận.

Đồng thời tôi cũng đưa ra các gợi ý về các câu hỏi cần trả lời để có một log đúng chuẩn.

• Who: Dòng log đó dành cho ai hay ai gây ra?

• When: Log này xuất hiện khi nào?

• What: Log này chứa nội dung chính là gì?

• Where: Log này xuất hiện ở file nào, process, thread nào?

Qua bài viết này tôi mong là người đọc có thể hiểu được tầm quan trọng của việc logging, cũng như là cách sử dụng logging đúng hơn, hiệu quả hơn, có nhiều thời gian để phát triển các tính năng hữu ích thay vì phải ngồi đọc lại code mỗi khi gặp lỗi.