Giới thiệu
Flask là tuyệt vời, vô cùng linh hoạt để xây dựng một ứng dụng web. Nó nhỏ gọn hơn rất nhiều so với người anh em Django. Trong suốt một vài dự án tại GMO Z.com vietnam lab center, chúng tôi đã phát triển một số phần liên quan đế sử lý log mà tôi thấy hữu ích và muốn chia sẻ với bạn.
Flask loging
Log mặc định của flask dược hiện thị trên màn hình như sau
# Default settings - meh
[2020-06-12 08:46:44,202] ERROR in app: <Lightsaber noises>
[2020-06-12 08:46:44,202] WARNING in app: General Kenobi
127.0.0.1 - - [12/Jun/2020 08:46:44] "GET / HTTP/1.1" 200 -Thêm config log có thể set ở app.config . Ví dụ mình đã thêm vào 2 config là LOG_TYPE và LOG_LEVEL
from flask import Flask, current_app
from flask_logs import LogSetup
import os
app = Flask(__name__)
app.config["LOG_TYPE"] = os.environ.get("LOG_TYPE", "stream")
app.config["LOG_LEVEL"] = os.environ.get("LOG_LEVEL", "INFO")
logs = LogSetup()
logs.init_app(app)
@app.route("/")
def hello_world():
current_app.logger.info("Hello REM")
current_app.logger.error("<Lightsaber noises>")
current_app.logger.warning("General Kenobi")
return "Hello World!"
if __name__ == "__main__":
app.run()Tiếp đó cần phải ghi log ra file để có thể rotation về sau này
from flask import Flask, current_app
from flask_logs import LogSetup
import os
app = Flask(__name__)
app.config["LOG_TYPE"] = os.environ.get("LOG_TYPE", "watched")
app.config["LOG_LEVEL"] = os.environ.get("LOG_LEVEL", "INFO")
# File Logging Setup
app.config['LOG_DIR'] = os.environ.get("LOG_DIR", "./")
app.config['APP_LOG_NAME'] = os.environ.get("APP_LOG_NAME", "app.log")
app.config['WWW_LOG_NAME'] = os.environ.get("WWW_LOG_NAME", "www.log")
logs = LogSetup()
logs.init_app(app)
@app.route("/")
def hello_world():
current_app.logger.info("Hello REM")
current_app.logger.error("<Lightsaber noises>")
current_app.logger.warning("General Kenobi")
return "Hello World!"
if __name__ == "__main__":
app.run()Như ở trên mình đã thêm các config LOG_DIR và APP_LOG_NAME và WWW_LOG_NAME
Class LogSetup của mình như sau
from logging.config import dictConfig
class LogSetup(object):
def __init__(self, app=None, **kwargs):
if app is not None:
self.init_app(app, **kwargs)
def init_app(self, app):
log_type = app.config["LOG_TYPE"]
logging_level = app.config["LOG_LEVEL"]
if log_type != "stream":
try:
log_directory = app.config["LOG_DIR"]
app_log_file_name = app.config["APP_LOG_NAME"]
access_log_file_name = app.config["WWW_LOG_NAME"]
except KeyError as e:
exit(code="{} is a required parameter for log_type '{}'".format(e, log_type))
app_log = "/".join([log_directory, app_log_file_name])
www_log = "/".join([log_directory, access_log_file_name])
if log_type == "stream":
logging_policy = "logging.StreamHandler"
elif log_type == "watched":
logging_policy = "logging.handlers.WatchedFileHandler"
else:
log_max_bytes = app.config["LOG_MAX_BYTES"]
log_copies = app.config["LOG_COPIES"]
logging_policy = "logging.handlers.RotatingFileHandler"
std_format = {
"formatters": {
"default": {
"format": "[%(asctime)s.%(msecs)03d] %(levelname)s %(name)s:%(funcName)s: %(message)s",
"datefmt": "%d/%b/%Y:%H:%M:%S",
},
"access": {"format": "%(message)s"},
}
}
std_logger = {
"loggers": {
"": {"level": logging_level, "handlers": ["default"], "propagate": True},
"app.access": {
"level": logging_level,
"handlers": ["access_logs"],
"propagate": False,
},
"root": {"level": logging_level, "handlers": ["default"]},
}
}
if log_type == "stream":
logging_handler = {
"handlers": {
"default": {
"level": logging_level,
"formatter": "default",
"class": logging_policy,
},
"access_logs": {
"level": logging_level,
"class": logging_policy,
"formatter": "access",
},
}
}
elif log_type == "watched":
logging_handler = {
"handlers": {
"default": {
"level": logging_level,
"class": logging_policy,
"filename": app_log,
"formatter": "default",
"delay": True,
},
"access_logs": {
"level": logging_level,
"class": logging_policy,
"filename": www_log,
"formatter": "access",
"delay": True,
},
}
}
else:
logging_handler = {
"handlers": {
"default": {
"level": logging_level,
"class": logging_policy,
"filename": app_log,
"backupCount": log_copies,
"maxBytes": log_max_bytes,
"formatter": "default",
"delay": True,
},
"access_logs": {
"level": logging_level,
"class": logging_policy,
"filename": www_log,
"backupCount": log_copies,
"maxBytes": log_max_bytes,
"formatter": "access",
"delay": True,
},
}
}
log_config = {
"version": 1,
"formatters": std_format["formatters"],
"loggers": std_logger["loggers"],
"handlers": logging_handler["handlers"],
}
dictConfig(log_config)Trong hàm init_app(self, app): sẽ lấy các config đã được set ở trên như là log_type=app.config["LOG_TYPE"]
Sau đó sẽ chỉ định clask Log Handler nào được thực thi tùy theo config
- logging.StreamHandler
- logging.handlers.WatchedFileHandler
- logging.handlers.RotatingFileHandler
logging_handler Sẽ định nghĩa các setting cho từng loại log handler ở trên
StreamHander
https://docs.python.org/3/library/logging.handlers.html
Đây là class log base, class Handler cha chó các class Log handler khác. Sử dụng khi muốn chia log theo level và cần format cho log. Sử dụng class này log sẽ được hiện thị trực tiếp ra console
Các setting cần thiết cở bản như là level và formatter
WatchedFileHandler
Đây là class con của class logging.FileHander . Tuy nhiên nó được mở rộng để ghi log ra file
RotatingFileHandler
Đây là class để ghi log ra file và có các hàm hỗ trợ rotation theo file size.
TimedRotatingFileHandler
Đây là class để ghi log ra file và có các hàm hỗ trợ rotation theo thời gian. Có thể chỉ định thời gian rotation, tuy nhiên với handler này thì thời gian không được set cố định mà chỉ set được một khoảng thời gian.
Ví dụ mình muốn rotation theo từng tiếng và log sẽ chạy từ phút thứ 15 thì đến phút thứ 15 của giờ tiếp theo sẽ được tách ra thành 1 file. Tức là không thể cố định được theo thời gian cụ thể mả chỉ có thể set được khoảng thời gian.
Tạo Log rotation handler mới
Dưới đây mình đã thử viết một class log handle mới và tự ghi ra file mới khi đã hết khoảng thời gian là 1 ngày. Khi ghi ra file mới cần phải close stream và mở lai stream mới
class TimedFileHandler(logging.FileHandler):
def __init__(self, filename, encoding='utf8', delay=False):
"""
Use the specified filename for streamed logging
"""
# self.current_half_hour = half_hour()
current_time = int(time.time())
self.current_date = time.strftime("%Y%m%d", time.localtime(current_time))
filename = filename + "." + self.current_date
logging.FileHandler.__init__(self, filename, 'a', encoding, delay)
def should_rollover(self):
t = int(time.time())
new_date = time.strftime("%Y%m%d", time.localtime(t))
if new_date > self.current_date:
self.current_date = new_date
return 1
return 0
def do_rollover(self):
if self.stream:
self.stream.close()
self.stream = None
self.baseFilename = self.baseFilename[:-8] + self.current_date
self.stream = self._open()
def emit(self, record):
try:
if self.should_rollover():
self.do_rollover()
logging.FileHandler.emit(self, record)
except Exception:
self.handleError(record)
def _open(self):
file_exists = os.path.exists(self.baseFilename)
stream = logging.FileHandler._open(self)
if not file_exists:
stream.write(LOG_HEADER)
return stream
Kết luật
Nước sơn thì giống UI của hệ thống, còn gỗ tốt hay không thì cái vụ logging này nó cũng quyết định lắm nè! Nếu không coi trọng logging, khi hệ thống bị bug hay bị attack (gọi là gỗ bị sâu) thì, hoặc là chả coi được log hoặc là log có đó mà không xài được dẫn đến hoàn cảnh bế tắc, lâu dần càng ngày gỗ càng mục nát mà! Cuối cùng người đau khổ và phải hấng chịu nhiều nhất vẫn chính là các bạn - người làm ra hệ thống.
Với những hệ thống quy mô trung bình, được thiết kế scale ngang nhiều server chẳng hạn đi nữa, mình nghĩ log cực kỳ quan trọng trong việc sử lý lỗi và phân tích hệ thống. Vì thế rất recommend mọi người cài đặt và cải thiện hệ thống để nó ngày càng “tốt gỗ” hơn nhé.
