135 lines
4.7 KiB
Python
135 lines
4.7 KiB
Python
from __future__ import annotations
|
|
|
|
import ctypes
|
|
import os
|
|
import time
|
|
from typing import Callable
|
|
|
|
from fastapi import FastAPI, Request
|
|
|
|
|
|
class _ProcessMemoryCounters(ctypes.Structure):
|
|
_fields_ = [
|
|
("cb", ctypes.c_ulong),
|
|
("PageFaultCount", ctypes.c_ulong),
|
|
("PeakWorkingSetSize", ctypes.c_size_t),
|
|
("WorkingSetSize", ctypes.c_size_t),
|
|
("QuotaPeakPagedPoolUsage", ctypes.c_size_t),
|
|
("QuotaPagedPoolUsage", ctypes.c_size_t),
|
|
("QuotaPeakNonPagedPoolUsage", ctypes.c_size_t),
|
|
("QuotaNonPagedPoolUsage", ctypes.c_size_t),
|
|
("PagefileUsage", ctypes.c_size_t),
|
|
("PeakPagefileUsage", ctypes.c_size_t),
|
|
]
|
|
|
|
|
|
def _get_process_cpu_seconds() -> float:
|
|
cpu_times = os.times()
|
|
return cpu_times.user + cpu_times.system
|
|
|
|
|
|
def _get_process_rss_bytes() -> int | None:
|
|
if os.name == "nt":
|
|
try:
|
|
kernel32 = ctypes.WinDLL("kernel32", use_last_error=True)
|
|
psapi = ctypes.WinDLL("psapi", use_last_error=True)
|
|
kernel32.GetCurrentProcess.restype = ctypes.c_void_p
|
|
psapi.GetProcessMemoryInfo.argtypes = [ctypes.c_void_p, ctypes.c_void_p, ctypes.c_ulong]
|
|
psapi.GetProcessMemoryInfo.restype = ctypes.c_int
|
|
|
|
counters = _ProcessMemoryCounters()
|
|
counters.cb = ctypes.sizeof(_ProcessMemoryCounters)
|
|
ok = psapi.GetProcessMemoryInfo(
|
|
kernel32.GetCurrentProcess(),
|
|
ctypes.byref(counters),
|
|
counters.cb,
|
|
)
|
|
if ok:
|
|
return int(counters.WorkingSetSize)
|
|
except Exception:
|
|
return None
|
|
return None
|
|
|
|
try:
|
|
with open("/proc/self/statm", "r", encoding="ascii") as handle:
|
|
resident_pages = int(handle.read().split()[1])
|
|
return resident_pages * os.sysconf("SC_PAGE_SIZE")
|
|
except Exception:
|
|
return None
|
|
|
|
|
|
def _format_megabytes(value: int | None) -> str:
|
|
if value is None:
|
|
return "unknown"
|
|
return f"{value / (1024 * 1024):.1f}"
|
|
|
|
|
|
def _format_megabyte_delta(start: int | None, end: int | None) -> str:
|
|
if start is None or end is None:
|
|
return "unknown"
|
|
return f"{(end - start) / (1024 * 1024):.1f}"
|
|
|
|
|
|
def _get_caller(request: Request) -> str:
|
|
forwarded_for = request.headers.get("x-forwarded-for")
|
|
if forwarded_for:
|
|
return forwarded_for.split(",", 1)[0].strip()
|
|
if request.client is not None:
|
|
return request.client.host
|
|
return "unknown"
|
|
|
|
|
|
def install_request_logging(app: FastAPI, logger, service_name: str) -> None:
|
|
@app.middleware("http")
|
|
async def log_request(request: Request, call_next: Callable):
|
|
started_at = time.perf_counter()
|
|
cpu_started = _get_process_cpu_seconds()
|
|
rss_started = _get_process_rss_bytes()
|
|
caller = _get_caller(request)
|
|
forwarded_for = request.headers.get("x-forwarded-for", "-")
|
|
user_agent = request.headers.get("user-agent", "-")
|
|
request_id = request.headers.get("x-request-id") or request.headers.get("x-correlation-id") or "-"
|
|
content_length = request.headers.get("content-length", "0")
|
|
error_type = "-"
|
|
status_code = 500
|
|
|
|
logger.info(
|
|
"incoming_request service=%s caller=%s forwarded_for=%s method=%s path=%s query=%s user_agent=%r request_id=%s content_length=%s",
|
|
service_name,
|
|
caller,
|
|
forwarded_for,
|
|
request.method,
|
|
request.url.path,
|
|
request.url.query or "-",
|
|
user_agent,
|
|
request_id,
|
|
content_length,
|
|
)
|
|
|
|
try:
|
|
response = await call_next(request)
|
|
status_code = response.status_code
|
|
return response
|
|
except Exception as exc:
|
|
error_type = type(exc).__name__
|
|
raise
|
|
finally:
|
|
elapsed_ms = (time.perf_counter() - started_at) * 1000
|
|
cpu_time_ms = max(0.0, (_get_process_cpu_seconds() - cpu_started) * 1000)
|
|
cpu_percent = 0.0 if elapsed_ms <= 0 else (cpu_time_ms / elapsed_ms) * 100
|
|
rss_finished = _get_process_rss_bytes()
|
|
logger.info(
|
|
"completed_request service=%s caller=%s method=%s path=%s status_code=%s response_time_ms=%.1f cpu_time_ms=%.1f cpu_percent=%.1f rss_mb=%s rss_delta_mb=%s request_id=%s error_type=%s",
|
|
service_name,
|
|
caller,
|
|
request.method,
|
|
request.url.path,
|
|
status_code,
|
|
elapsed_ms,
|
|
cpu_time_ms,
|
|
cpu_percent,
|
|
_format_megabytes(rss_finished),
|
|
_format_megabyte_delta(rss_started, rss_finished),
|
|
request_id,
|
|
error_type,
|
|
) |