Python / logging === ###### tags: `Python` ###### tags: `Python`, `logging` <br> [TOC] <br> ## 範例程式 ### 範例1 ```python import logging print('>'*20 + 'print') logging.debug('>'*20 + 'debug') logging.info('>'*20 + 'info') logging.warning('>'*20 + 'warning') logging.error('>'*20 + 'error') logging.critical('>'*20 + 'critical') ``` 執行結果: ![](https://i.imgur.com/3uOMmqM.png) <br> ### 範例2 > https://docs.python.org/zh-tw/3/howto/logging.html#displaying-the-date-time-in-messages ```python import logging logging.basicConfig(format='[%(asctime)s][%(levelname)s] %(message)s', datefmt='%Y-%m-%d %H:%M:%S') ogging.warning('is when this event was logged.') ``` 執行結果: ``` [2022-09-23 16:01:21][WARNING] is when this event was logged. ``` <br> ### 範例3 ```pyhtn= import logging logging.basicConfig(format='[%(asctime)s][%(levelname)s][%(pathname)s][%(filename)s][%(module)s][%(funcName)s][%(lineno)s] %(message)s', datefmt='%Y-%m-%d %H:%M:%S') logging.warning('here is a demo message) ``` > [2022-09-23 16:34:35][WARNING][/tmp/ipykernel_76557/294564305.py][294564305.py][294564305][<module>][3] here is a demo message - [How to log source file name and line number in Python](https://stackoverflow.com/a/533077/4359712) <br> ### 範例4:更新 logger level > 使用情境:jupyterlab / notebook ```python= import logging import traceback logger = logging.getLogger() current_level = logger.getEffectiveLevel() print('getLevelName:', logging.getLevelName(current_level)) logger.setLevel(level=logging.DEBUG) logger = logging.getLogger() current_level = logger.getEffectiveLevel() print('getLevelName:', logging.getLevelName(current_level)) try: x = 5/0 except Exception as e: print(e) print('-' * 60) print(traceback.format_exc()) print('-' * 60) logging.info("Failed!!") print('-' * 60) logging.info("Failed!!", exc_info=True) ``` ![](https://hackmd.io/_uploads/SJ01-M7tll.png) <br> ## API ### [`logging.debug(msg, *args, **kwargs)`](https://docs.python.org/zh-tw/3/library/logging.html#logging.debug) <br> ## 教學文件 - [如何使用 Logging 模組](https://docs.python.org/zh-tw/3/howto/logging.html) <br> <hr> <br> ## 進階設定:彩色 logging > ![](https://hackmd.io/_uploads/B1TRCQe-xg.png) > - ✅ 終極 Logging Utility 範本 > - 這是一份模組化 logging utility,具備你要的功能: > - ✅ 功能一覽 > - 支援 console + file 同時輸出 > - 彩色 console log(等級顏色區分) > - Log 檔案自動輪替(`RotatingFileHandler`) > - 可整合 Pydantic `Settings` ### logging_config.py ```python= import logging import sys from logging.handlers import RotatingFileHandler from pathlib import Path from typing import Optional class ColorFormatter(logging.Formatter): """彩色的 log formatter,CLI 用起來比較爽。""" COLORS = { "DEBUG": "\033[36m", # 青色 "INFO": "\033[32m", # 綠色 "WARNING": "\033[33m", # 黃色 "ERROR": "\033[31m", # 紅色 "CRITICAL": "\033[41m", # 紅底白字 } RESET = "\033[0m" def format(self, record: logging.LogRecord) -> str: level_color = self.COLORS.get(record.levelname, "") reset = self.RESET if level_color else "" msg = super().format(record) return f"{level_color}{msg}{reset}" def configure_logging( name: str = "SyncPilot", level: int = logging.INFO, log_file: Optional[Path] = None, log_to_console: bool = True, max_bytes: int = 5 * 1024 * 1024, backup_count: int = 3, ) -> logging.Logger: """ Configure logger with optional file and colored console. Parameters ---------- name : str Logger name. level : int Log level (e.g., logging.DEBUG). log_file : Path, optional Path to the log file. If None, no file logging. log_to_console : bool Whether to log to stdout. max_bytes : int Max file size before rotation. backup_count : int How many rotated logs to keep. Returns ------- logging.Logger Configured logger instance. """ logger = logging.getLogger(name) logger.setLevel(level) logger.propagate = False # 防止重複 log formatter = logging.Formatter( fmt="%(asctime)s [%(levelname)s] %(name)s: %(message)s", datefmt="%Y-%m-%d %H:%M:%S" ) # Console log with color if log_to_console and not any( isinstance(h, logging.StreamHandler) for h in logger.handlers ): ch = logging.StreamHandler(sys.stdout) ch.setLevel(level) ch.setFormatter(ColorFormatter( fmt="%(asctime)s [%(levelname)s] %(name)s: %(message)s", datefmt="%H:%M:%S" )) logger.addHandler(ch) # File log with rotation if log_file and not any( isinstance(h, RotatingFileHandler) for h in logger.handlers ): fh = RotatingFileHandler( log_file, maxBytes=max_bytes, backupCount=backup_count, encoding="utf-8" ) fh.setLevel(level) fh.setFormatter(formatter) logger.addHandler(fh) return logger ``` <br> ### settings.py ```python= # settings.py from pydantic_settings import BaseSettings from typing import Literal import logging from pathlib import Path class Settings(BaseSettings): APP_NAME: str = "SyncPilot" LOGGING_LEVEL: Literal[ "DEBUG", "INFO", "WARNING", "ERROR" ] = "DEBUG" LOG_FILE: Path = Path("syncpilot.log") @property def logging_level(self) -> int: return { "DEBUG": logging.DEBUG, "INFO": logging.INFO, "WARNING": logging.WARNING, "ERROR": logging.ERROR, }.get(self.LOGGING_LEVEL, logging.INFO) settings = Settings() ``` <br> ### main.py ``` # main.py from logging_config import configure_logging from settings import settings logger = configure_logging( name=settings.APP_NAME, level=settings.logging_level, log_file=settings.LOG_FILE, log_to_console=True ) logger.debug("Debug message") logger.info("Application started.") logger.warning("Warning issued.") logger.error("Something went wrong.") ``` ### 執行結果 ![](https://hackmd.io/_uploads/B1TRCQe-xg.png) <br> <hr> <br> ## 討論 ### python 中,要用 debug flag 來控制更詳細的 log,以及輸出 warning log,通常要如何做? [ChatGPT] 在 Python 中,你可以使用內建的 `logging` 模組來實現日誌記錄,並透過設定不同的日誌等級來控制詳細程度。 以下是一個簡單的例子,示範如何根據 debug 標誌以及輸出 warning 資訊: ```python= import logging def setup_logging(debug=False): logging.basicConfig(level=logging.DEBUG if debug else logging.INFO, format='%(asctime)s - %(levelname)s - %(message)s') def main(): debug_flag = True # 設定為 True 表示開啟詳細日誌記錄 setup_logging(debug=debug_flag) logging.debug("This is a debug message.") logging.info("This is an info message.") logging.warning("This is a warning message.") if __name__ == "__main__": main() ``` 在這個範例中,我們使用 `setup_logging` 函數來初始化日誌記錄配置。 透過將 `debug` 參數設為 `True`,我們開啟了 DEBUG 等級的日誌記錄,這將輸出更詳細的資訊。 如果將 `debug` 參數設為 `False`,則僅輸出 INFO 等級及以上的日誌。 你可以根據需要調整日誌級別,包括 `DEBUG`、`INFO`、`WARNING`、`ERROR` 和 `CRITICAL`。 <br> ### level=logging.DEBUG,為何設過一次後,就無法在變更 level ? [ChatGPT] 在使用 basicConfig 進行配置的情況下,一旦配置完成,就無法再次變更其配置。 這是因為 basicConfig 只應該在應用程式的早期階段呼叫一次,以配置根記錄器。 如果你想要動態變更記錄器的配置,可以使用 getLogger 取得記錄器對象,然後為其設定處理程序、格式等。 例如: ```python= import logging # 在應用程式的早期階段進行一次配置 logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(levelname)s - %(message)s') # 取得根記錄器 logger = logging.getLogger() # 動態變更記錄器的 level logger.setLevel(logging.DEBUG) # 新增處理程序、設定格式等 # handler = logging.StreamHandler() # formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s') # handler.setFormatter(formatter) # logger.addHandler(handler) # 現在可以使用 logger.debug("...") 輸出 DEBUG 等級的日誌 ``` 這樣就可以在運行時動態更改日誌等級和進行其他配置。 - 參考資料 - [Get Output From the logging Module in IPython Notebook](https://stackoverflow.com/questions/18786912/) <br> ### 如何查看當前 logging 套件的 level 是 INFO ? VERBOSE? [ChatGPT] 在 Python 中,您可以使用 `logging` 模組的 `getLogger` 方法來取得一個日誌記錄器(logger),然後使用該記錄器的 `getEffectiveLevel` 方法來查看目前的日誌等級。 以下是一個範例,展示如何檢查預設記錄器(root logger)的目前日誌等級: ```python import logging # 取得預設記錄器 logger = logging.getLogger() # 取得並列印目前日誌等級 current_level = logger.getEffectiveLevel() print("目前日誌等級:", logging.getLevelName(current_level)) ``` 這段程式碼會列印出目前日誌層級的名稱,如 `INFO`、`DEBUG` 等。 請注意,日誌等級是以整數形式儲存的,`getEffectiveLevel` 方法傳回的是這個整數值。 `logging.getLevelName` 函數可以將這個整數轉換為對應的等級名稱。 如果您想檢查特定記錄器的日誌級別,只需在 `getLogger` 方法中傳入該記錄器的名稱即可。 例如: ```python= Copy code # 取得名為'my_logger'的記錄器的日誌級別 my_logger = logging.getLogger('my_logger') current_level = my_logger.getEffectiveLevel() print("目前日誌等級:", logging.getLevelName(current_level)) ``` 請注意,`VERBOSE` 並不是 Python 標準 `logging` 模組的一個預先定義日誌等級。 如果您在應用程式中看到了 `VERBOSE` 級別,這可能是自訂級別或由第三方程式庫添加的。 您可以檢查應用程式的配置或程式碼,看看是否定義了這樣的自訂等級。 如果是,您可能需要查看該程式庫或套用的文件來了解如何檢索該層級的資訊。 <br> ### 使用 Python logging 套件,想要加上檔名,logging 要如何使用? - ### gpt-4o (2025/04/17) 你可以在設定 `logging` 時,加上 `format` 格式字串,讓 log 訊息中顯示目前執行的 **檔名 (module)**,方法如下: ### ✅ 建議用法:加入 `%(filename)s` ```python import logging logging.basicConfig( level=logging.DEBUG, format='%(asctime)s [%(levelname)s] %(filename)s: %(message)s', ) ``` ### 🔍 格式參考 | 格式符號 | 說明 | |----------------|----------------------------| | `%(asctime)s` | 時間戳記 | | `%(levelname)s`| 日誌等級(DEBUG, INFO 等) | | `%(filename)s` | 執行此 log 的 Python 檔名 | | `%(lineno)d` | 執行此 log 的 Python 檔名 | | `%(message)s` | 真正的 log 內容 | --- ### 🧪 範例輸出: ``` 2025-04-17 14:08:22,114 [DEBUG] my_script.py: Contents of zip file: [...] ``` 如果你想加上行號,可以用 `%(lineno)d`: ``` format='%(asctime)s [%(levelname)s] %(filename)s:%(lineno)d - %(message)s' ``` 需要我幫你加上 log formatter 給 `uvicorn` 或 FastAPI 也能用嗎? <br> ### `logging.basicConfig()` 是每個檔案設定一次,還是入口點所在程式設定就好? - ### gpt-4o (2025/04/17) ### ✅ 正確做法: 通常 **只需要在「入口點」的程式設定一次 `logging.basicConfig()`** 就好。 --- ### 🔧 詳細說明: - `logging.basicConfig()` 是全域設定,全程只會生效一次(第一次呼叫時)。 - 一旦設定完成,其他模組只要用 `logging.getLogger(__name__)` 或直接用 `logging.debug/info/warning()` 就會依照該設定運作。 - **不需要每個檔案都設定 `basicConfig()`**,這樣反而可能導致設定失效或重複。 --- ### 📁 範例架構: ``` project/ ├── main.py ← 入口點,這裡設定 logging ├── utils/ │ └── helper.py ← 只需使用 logging,不用再設定 basicConfig ``` #### main.py ```python import logging from utils import helper logging.basicConfig( level=logging.DEBUG, format='%(asctime)s [%(levelname)s] %(filename)s: %(message)s' ) helper.do_something() ``` #### utils/helper.py ```python import logging def do_something(): logging.info("Helper is working!") ``` --- ### 🚫 錯誤用法: - 每個檔案都呼叫 `basicConfig()` - 👉 會造成只有第一個呼叫的地方生效,其他不會覆蓋 --- 如你是用 FastAPI + Uvicorn,還可以加強控制 log formatter 和 handler,要我幫你示範嗎? <br> ### 為什麼 `logging.basicConfig()` 在 FastAPI 中無效? - ### gpt-4o (2025/04/17) 這個問題的核心是:**`uvicorn` 自帶的 log 設定會「搶先」載入並主控 log 行為**,導致你在 `main.py` 裡的 `logging.basicConfig(...)` 不生效。 --- ### 🔍 為什麼 `basicConfig()` 沒生效? 因為 Python 的 `logging.basicConfig()` **只會對第一次設定生效**。而當你用 `uvicorn` 執行 FastAPI app 時,它會在載入 app 之前就先設定好 log handler。 所以你後面再呼叫 `basicConfig()` 根本不會改變現有的 log 設定。 --- ### ✅ 解法 1:使用 `force=True`(Python 3.8+) 讓 `basicConfig()` 強制重設所有 logging handler。 ```python logging.basicConfig( level=logging.DEBUG, format='%(asctime)s [%(levelname)s] %(filename)s: %(message)s', force=True ) ``` ✔ 這是最簡單也最推薦的方式,但需要 Python 3.8 以上。 --- ### ✅ 解法 2:自己定義 root logger 與 handler(不靠 `basicConfig`) ```python= import logging logger = logging.getLogger() logger.setLevel(logging.DEBUG) # 移除 uvicorn 預設 handler(避免重複) for handler in logger.handlers[:]: logger.removeHandler(handler) # 自訂 handler console_handler = logging.StreamHandler() console_handler.setLevel(logging.DEBUG) console_handler.setFormatter(logging.Formatter( '%(asctime)s [%(levelname)s] %(filename)s: %(message)s' )) logger.addHandler(console_handler) ``` --- ### ✅ 補充:如果你用 `uvicorn main:app` 啟動,可以加上 `--log-config` 或調整 log level: ``` uvicorn main:app --reload --log-level debug ``` --- 需要我幫你整合進 FastAPI 專案的最佳 log 設定範本嗎?包含 uvicorn + 自訂 logger? <br> ### Python Logging 設定與 FastAPI 整合使用者資訊 - ### gpt-4o (2025/04/17) ### ✅ 基本 logging 設定 設定時間戳記(asctime)、log 等級、檔名與行號: ```python import logging logging.basicConfig( level=logging.DEBUG, format='%(asctime)s [%(levelname)s] %(filename)s:%(lineno)d - %(message)s', datefmt='%Y/%m/%d %H:%M:%S', ) ``` 輸出範例: ``` 2025/04/17 14:20:10 [DEBUG] zip_handler.py:45 - Contents of zip file: [...] ``` --- ### ✅ 進階版:整合 FastAPI,加入 IP、Token、使用者 ID #### 步驟 1:定義 ContextVar 儲存用戶資訊 ```python from contextvars import ContextVar log_context = ContextVar("log_context", default={}) ``` --- ### 步驟 2:定義自訂 Formatter 加入使用者資訊 ```python class ContextAwareFormatter(logging.Formatter): def format(self, record): context = log_context.get({}) record.user = context.get("user", "unknown") record.ip = context.get("ip", "unknown") record.token = context.get("token", "none") return super().format(record) ``` --- ### 步驟 3:設置 logging handler 與格式 ```python formatter = ContextAwareFormatter( fmt='%(asctime)s [%(levelname)s] [user:%(user)s ip:%(ip)s token:%(token)s] %(filename)s:%(lineno)d - %(message)s', datefmt='%Y/%m/%d %H:%M:%S' ) handler = logging.StreamHandler() handler.setFormatter(formatter) logger = logging.getLogger() logger.setLevel(logging.DEBUG) logger.handlers = [handler] ``` --- ### 步驟 4:在 FastAPI 加入 Middleware 注入 log context ```python from fastapi import FastAPI, Request app = FastAPI() @app.middleware("http") async def inject_log_context(request: Request, call_next): ip = request.client.host token = request.headers.get("authorization", "none") user = request.headers.get("x-user-id", "guest") log_context.set({ "ip": ip, "token": token, "user": user, }) return await call_next(request) ``` --- ### 🧪 實際使用 ``` logger.info("收到 ZIP 檔案,開始解壓縮...") ``` 輸出範例: ``` 2025/04/17 14:25:12 [INFO] [user:admin ip:127.0.0.1 token:Bearer xyz...] file_upload.py:88 - 收到 ZIP 檔案,開始解壓縮... ``` --- 如需將 log 輸出到檔案並每日輪替,可使用 `TimedRotatingFileHandler`,若需要請告知我。 <br> {%hackmd vaaMgNRPS4KGJDSFG0ZE0w %}