技術文章 » 【Python】如何在FastAPI中使用UUID標記紀錄檔，以跟蹤一個請求的完整生命週期

【Python】如何在FastAPI中使用UUID標記紀錄檔，以跟蹤一個請求的完整生命週期

2023-06-04 06:00:38

為什麼要使用uuid標記紀錄檔？

在分散式系統中，一個請求可能會經過多個服務，每個服務都會生成自己的紀錄檔。如果我們只使用普通的紀錄檔記錄，那麼很難將這些紀錄檔串聯在一起，以至難以跟蹤一個請求的完整生命週期。

如果能夠使用uuid標記紀錄檔，為每個請求生成一個唯一的uuid，且這個紀錄檔可以在不同的系統間傳遞，就可以解決這個問題。

FastAPI和Loguru是兩個非常流行的Python庫。FastAPI是一個現代的Web框架，具有高效能和易於使用的特點。Loguru是一個靈活的紀錄檔記錄庫，具有簡單、易用和強大的特點。在這篇文章中，我們將介紹如何使用FastAPI和Loguru進行紀錄檔記錄，並使用同一個uuid標記來標記每個請求的紀錄檔鏈路。

安裝FastAPI和Loguru

首先，我們需要安裝FastAPI和Loguru。可以使用pip命令來安裝它們：

pip install fastapi
pip install loguru

建立FastAPI應用程式

接下來，我們需要建立一個FastAPI應用程式。在這個例子中，我們將建立一個簡單的應用程式，它對外提供一個根路徑存取，我們在根路徑被存取時會記錄紀錄檔，並且會呼叫hello函數，hello函數自身也新增了紀錄檔記錄。

import uvicorn
from fastapi import FastAPI
from loguru import logger

app = FastAPI()

logger.add("log.log")


@app.get("/{name}")
async def root(name):
    logger.info("Hello from the root path")
    hello()
    return {"message": f"Hello {name}"}


def hello():
    logger.info("hello() called!")


if __name__ == '__main__':
    uvicorn.run("main:app", port=10001, reload=True)

tips uvicorn.run("main:app", port=10001, reload=True) 中的 main 表示執行 main.py 檔案中的 app

服務啟動後，如果我們存取 http://localhost:10001/Bingo，會收到響應 {"message":"Hello Bingo"}, log.log檔案中會記錄

2023-06-01 21:24:13.471 | INFO     | main:root:19 - Root path is Visited!
2023-06-01 21:24:13.472 | INFO     | main:hello:26 - hello() called!
2023-06-01 21:24:13.472 | INFO     | main:root:21 - Bingo Visited!

新增uuid標記

上面的三條紀錄檔雖然都是因為 我們存取一個地址產生的，但是他們之間除了時間，沒有其他的管理；如果同一時間有多個請求，我們就難以跟蹤隨呼叫了 hello()做了什麼 ，那麼如何才能將他們關聯起來呢？

這需要用到 with 上下文管理函數 和** FastAPI中介軟體** 的概念。

with 上下文管理函數

with 是 Python 中的一個上下文管理器，它可以在程式碼塊執行完畢後自動釋放資源，避免資源洩漏等問題，提高程式碼的可讀性和可維護性。
with 語句的語法如下：

with expression [as variable]:
    with-block

其中，expression 是一個上下文管理器物件，可以是一個函數或一個類，必須實現 __enter__ 和 __exit__ 方法。as variable 是可選的，用來指定一個變數名，將 expression.__enter__() 方法的返回值賦值給該變數。with-block 是一個程式碼塊，用來執行需要被管理的程式碼。

with 語句的執行流程如下：

  1. 執行 expression.__enter__() 方法，獲取上下文管理器物件。
  2. 如果指定了 as variable，將 __enter__() 方法的返回值賦值給該變數。
  3. 執行 with-block 中的程式碼。
  4. 如果 with-block 中的程式碼執行過程中丟擲異常，則執行 expression.__exit__(exc_type, exc_value, traceback) 方法，釋放資源。
  5. 如果 with-block 中的程式碼執行完畢，則執行 expression.__exit__(None, None, None) 方法，釋放資源。

with 語句可以用來管理檔案、網路連線、鎖等資源，例如：

with open('file.txt', 'r') as f:
    content = f.read()
    print(content)

上述程式碼使用 with 語句來管理檔案資源，當程式碼塊執行完畢後，會自動關閉檔案控制程式碼，釋放資源。

FastAPI中介軟體

FastAPI中介軟體是一種機制，允許我們在請求到達應用程式之前或之後執行一些操作。它們可以用於新增請求頭、驗證身份、記錄紀錄檔等。在FastAPI中，中介軟體是使用裝飾器實現的。我們可以使用@app.middleware()裝飾器來定義中介軟體。中介軟體函數接收一個Request物件和一個call_next函數作為引數。它可以在請求到達應用程式之前或之後執行一些操作，並呼叫call_next函數來繼續處理請求。

程式碼實現

改造後的程式碼如下：

import uvicorn
import uuid
from fastapi import FastAPI
from loguru import logger
from starlette.responses import JSONResponse

app = FastAPI()

logger.add(
    "log.log",
    format="{time:YYYY-MM-DD HH:mm:ss.ms} [{extra[request_id]}] | {level} | {module}.{function}:{line} : {message}"
)


@app.middleware("http")
async def request_middleware(request, call_next):
    request_id = str(uuid.uuid4())
    with logger.contextualize(request_id=request_id):
        logger.info("Request started")
        try:
            return await call_next(request)

        except Exception as ex:
            logger.error(f"Request failed: {ex}")
            return JSONResponse(content={"success": False}, status_code=500)

        finally:
            logger.info("Request ended")


@app.get("/{name}")
async def root(name):
    logger.info("Root path is Visited!")
    hello()
    logger.info(f"{name} Visited!")
    return {"message": f"Hello {name}"}


def hello():
    logger.info("hello() called!")


if __name__ == '__main__':
    uvicorn.run("main:app", port=10001, reload=True)

當我們再次存取 http://localhost:10001/Bingo，收到的響應 {"message":"Hello Bingo"}不會有變化, 但是log.log檔案中會記錄：

2023-06-01 21:35:55.3555 [b61c693f-97c0-4c84-9f44-3b855bea2568] | INFO | main.request_middleware:29 : Request started
2023-06-01 21:35:55.3555 [b61c693f-97c0-4c84-9f44-3b855bea2568] | INFO | main.root:43 : Root path is Visited!
2023-06-01 21:35:55.3555 [b61c693f-97c0-4c84-9f44-3b855bea2568] | INFO | main.hello:50 : hello() called!
2023-06-01 21:35:55.3555 [b61c693f-97c0-4c84-9f44-3b855bea2568] | INFO | main.root:45 : Bingo Visited!
2023-06-01 21:35:55.3555 [b61c693f-97c0-4c84-9f44-3b855bea2568] | INFO | main.request_middleware:38 : Request ended

再次請求時，uuid 會發生變化:

2023-06-01 21:35:55.3555 [b0e02e34-51ee-4cbb-838b-8222ec8f0483] | INFO | main.request_middleware:29 : Request started
2023-06-01 21:35:55.3555 [b0e02e34-51ee-4cbb-838b-8222ec8f0483] | INFO | main.root:43 : Root path is Visited!
2023-06-01 21:35:55.3555 [b0e02e34-51ee-4cbb-838b-8222ec8f0483] | INFO | main.hello:50 : hello() called!
2023-06-01 21:35:55.3555 [b0e02e34-51ee-4cbb-838b-8222ec8f0483] | INFO | main.root:45 : Bingo Visited!
2023-06-01 21:35:55.3555 [b0e02e34-51ee-4cbb-838b-8222ec8f0483] | INFO | main.request_middleware:38 : Request ended

實現原理是我們在每個請求的狀態中儲存uuid，並在紀錄檔記錄中使用它。

程式碼解釋：

  1. @app.middleware("http") 表示註冊一個 HTTP 中介軟體，用於處理 HTTP 請求。
  2. request 是一個請求物件，call_next 是一個回撥函數，用於呼叫下一個中介軟體或路由處理常式。
  3. uuid.uuid4() 生成一個唯一的請求 ID，用於在紀錄檔中標識該請求。
  4. logger.contextualize(request_id=request_id) 用於在紀錄檔中新增請求 ID 上下文。
  5. logger.info("Request started") 記錄請求開始的紀錄檔資訊。
  6. await call_next(request) 呼叫下一個中介軟體或路由處理常式，並返回響應物件。
  7. logger.error(f"Request failed: {ex}") 記錄請求失敗的紀錄檔資訊，其中 ex 是捕獲到的異常物件。
  8. JSONResponse(content={"success": False}, status_code=500) 返回一個 HTTP 500 錯誤響應，表示請求處理失敗。
  9. logger.info("Request ended") 記錄請求結束的紀錄檔資訊。

這個中介軟體只用實現一次，對後續所有其他介面的開發沒有任何的侵入，一勞永逸。

tips: 為什麼使用uuid.uuid4()而不是uuid.uuid()？

uuid.uuid()生成的UUID是根據主機ID、序列號和當前時間生成的。這意味著在同一臺計算機上生成的UUID可能會重複，尤其是在高負載情況下。為了避免這種情況，我們可以使用uuid.uuid4()生成隨機UUID。uuid.uuid4()生成的UUID是完全隨機的，幾乎不可能重複。因此，它是生成唯一識別符號的最佳選擇。

總結

在這個例子中，我們使用FastAPI和Loguru進行了紀錄檔記錄，並使用同一個uuid標記來標記每個請求的紀錄檔鏈路。這使得我們能夠輕鬆地跟蹤每個請求的紀錄檔，並識別它們的來源，如果上游也使用了這樣方式記錄紀錄檔， 那做到跟蹤一個請求的完整生命週期就不難辦到了。