(20241008) logging decorator and model improved.
This commit is contained in:
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
+31
-85
@@ -46,13 +46,8 @@ from utils_v2.string import json
|
||||
from utils_v2.date_time import date_time
|
||||
from utils_v2.security import sanitizers
|
||||
from utils_v2.api.codes import StatusCodes, HttpCodes
|
||||
from utils_v2.api.log import APILogModel
|
||||
from utils_v2.api.response import ResponseModel
|
||||
from utils_v2.api.metrics_prometheus import (
|
||||
TOTAL_REQUEST_COUNT,
|
||||
LIVE_REQUEST_COUNT,
|
||||
REQUEST_LATENCY,
|
||||
MetricsAPI
|
||||
)
|
||||
|
||||
# To work with date and time:
|
||||
import time
|
||||
@@ -60,9 +55,6 @@ import datetime
|
||||
|
||||
# System-level activities:
|
||||
import io
|
||||
import distro
|
||||
import socket
|
||||
import platform
|
||||
|
||||
# For Pydantic data-models:
|
||||
import pydantic
|
||||
@@ -90,11 +82,6 @@ import asyncio
|
||||
# *****************************************************************************************************************
|
||||
|
||||
|
||||
# Info for logging that will stay constant during runtime:
|
||||
SERVER_HOSTNAME = socket.gethostname()
|
||||
PLATFORM_INFO = platform.uname()
|
||||
HOST_OS = distro.name(True)
|
||||
|
||||
# Chars to choose from for random strings:
|
||||
ALPHANUMERIC_CHARS = string.ascii_letters + string.digits
|
||||
|
||||
@@ -572,6 +559,8 @@ def validate_input(
|
||||
def log_request_to_mongo(
|
||||
attr_name,
|
||||
collection: str = "logs",
|
||||
api_version: str = None,
|
||||
project: str = None,
|
||||
log_type: str = None,
|
||||
operation: str = None,
|
||||
log_input: bool = True,
|
||||
@@ -586,6 +575,8 @@ def log_request_to_mongo(
|
||||
:param attr_name: The name of the variable that holds the instance of 'AsyncMongo'. It should be accessible in the
|
||||
scope of 'current_app'.
|
||||
:param collection: The name of the collection to write the log into.
|
||||
:param api_version: The version code of the API endpoint that is being logged.
|
||||
:param project: The name of the project that the endpoint was built for.
|
||||
:param log_type: A hint to identify what the log was for.
|
||||
:param operation: A hint to identify what was action was being performed.
|
||||
:param log_input: Whether, or not, you would like to log the input that came in.
|
||||
@@ -602,6 +593,9 @@ def log_request_to_mongo(
|
||||
# Let the next in-line decorator know that it has been wrapped:
|
||||
kwargs["decorator_count"] = kwargs.get("decorator_count", 0) + 1
|
||||
|
||||
# Set the api version as needed:
|
||||
kwargs["api_version"] = kwargs.get("api_version", api_version)
|
||||
|
||||
# Make variables and extract available info.:
|
||||
exception = None
|
||||
response = None
|
||||
@@ -635,7 +629,8 @@ def log_request_to_mongo(
|
||||
elif isinstance(response, tuple): response_to_log, http_code_to_log = response
|
||||
else: response_to_log, http_code_to_log = str(response), 200
|
||||
|
||||
# Try to get the information about the request:
|
||||
# Try to get the information about the request.
|
||||
# There will be no data in any of these if the decorator was used to catch start-up and shut-down events.
|
||||
request_method = None
|
||||
request_url = None
|
||||
request_route = None
|
||||
@@ -653,41 +648,37 @@ def log_request_to_mongo(
|
||||
except: pass
|
||||
|
||||
# Construct the log:
|
||||
# for k in sensitive_keys: kwargs.get("inbound_headers", {}).pop(k, None)
|
||||
# for k in sensitive_keys: kwargs.get("inbound_data", {}).pop(k, None)
|
||||
log_json = {
|
||||
"hostname": SERVER_HOSTNAME,
|
||||
"os": f"{HOST_OS}",
|
||||
"cpu": f"{PLATFORM_INFO.processor} ({PLATFORM_INFO.machine})",
|
||||
"logId": kwargs.get("log_id"),
|
||||
"logChain": kwargs.get("inbound_headers", {}).get("X-Log-Chain"),
|
||||
"log": log_type,
|
||||
"operation": operation,
|
||||
"apiVer": kwargs.get("api_version"),
|
||||
"method": request_method,
|
||||
"url": request_url,
|
||||
"route": request_route,
|
||||
"ts": request_ts,
|
||||
"tat": time.perf_counter() - start_ts,
|
||||
"cpuTime": time.process_time() - cpu_start_ts,
|
||||
"headers": kwargs.get("inbound_headers"),
|
||||
"data": kwargs.get("inbound_data") if log_input else "not logged",
|
||||
"files": {
|
||||
api_log = APILogModel(
|
||||
project = project,
|
||||
log = log_type,
|
||||
operation = operation,
|
||||
apiVer = kwargs.get("api_version"),
|
||||
logId = kwargs.get("log_id"),
|
||||
logChain = kwargs.get("inbound_headers", {}).get("X-Log-Chain"),
|
||||
method = request_method,
|
||||
url = request_url,
|
||||
route = request_route,
|
||||
ts = request_ts,
|
||||
tat = time.perf_counter() - start_ts,
|
||||
cpuTime = time.process_time() - cpu_start_ts,
|
||||
headers = kwargs.get("inbound_headers"),
|
||||
data = kwargs.get("inbound_data") if log_input else "not logged",
|
||||
files = {
|
||||
k: {
|
||||
"name": v["name"],
|
||||
"size": v["size"]
|
||||
} for k, v in kwargs.get("inbound_files", {}).items()
|
||||
},
|
||||
"exception": None if exception is None else describe_exception(exception),
|
||||
"response": response_to_log,
|
||||
"httpCode": http_code_to_log
|
||||
}
|
||||
exception = None if exception is None else describe_exception(exception),
|
||||
response = response_to_log,
|
||||
httpCode = http_code_to_log
|
||||
)
|
||||
|
||||
# Write the log:
|
||||
app_attr = getattr(current_app, attr_name)
|
||||
inserted_id = await app_attr.insert_one(
|
||||
collection = collection,
|
||||
document = log_json
|
||||
document = api_log.model_dump()
|
||||
)
|
||||
|
||||
# Return the response from the wrapped function.
|
||||
@@ -950,51 +941,6 @@ def handle_cancelled_request(cleanup_func = None, cleanup_coro = None):
|
||||
return decorator
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------------------------------------------------
|
||||
|
||||
|
||||
def measure_metrics_for_prometheus():
|
||||
|
||||
"""
|
||||
Use this decorator to automatically measure metrics for using in Prometheus.
|
||||
:return: The decorator factory.
|
||||
"""
|
||||
|
||||
def decorator(func):
|
||||
|
||||
@wraps(func)
|
||||
async def wrapper(*args, **kwargs):
|
||||
|
||||
# Let the next in-line decorator know that it has been wrapped:
|
||||
kwargs["decorator_count"] = kwargs.get("decorator_count", 0) + 1
|
||||
|
||||
# We use the context of the measurement class:
|
||||
async with MetricsAPI(
|
||||
method = f"{request.method}",
|
||||
endpoint = str(request.url_rule.rule)
|
||||
) as metrics:
|
||||
|
||||
# Invoke the wrapped function:
|
||||
response = await func(*args, **kwargs)
|
||||
kwargs["decorator_count"] -= 1
|
||||
|
||||
# Interpret the HTTP code:
|
||||
if isinstance(response, ResponseModel): _, metrics.http_code = response.for_quart()
|
||||
elif isinstance(response, tuple): metrics.http_code = response[1]
|
||||
else: metrics.http_code = 200
|
||||
|
||||
# Done here:
|
||||
if (
|
||||
kwargs["decorator_count"] == 1 and
|
||||
isinstance(response, ResponseModel)
|
||||
): response = response.for_quart()
|
||||
return response
|
||||
|
||||
return wrapper
|
||||
|
||||
return decorator
|
||||
|
||||
|
||||
# *****************************************************************************************************************
|
||||
# ***** ****
|
||||
# *** MAIN PROGRAM ***
|
||||
|
||||
@@ -3,15 +3,14 @@
|
||||
AUTHOR:
|
||||
|
||||
Khushal P Soonderji
|
||||
Sharvil J Daiya
|
||||
|
||||
DATE:
|
||||
|
||||
Saturday, 28th Sept., 2024
|
||||
Thursday, 12th Sept., 2024
|
||||
|
||||
OBJECTIVE:
|
||||
|
||||
To have one place from where several metrics are measured using easy to use context managers.
|
||||
To have a structure to the response sent from the API calls.
|
||||
|
||||
REFERENCES:
|
||||
|
||||
@@ -31,16 +30,21 @@
|
||||
# *****************************************************************************************************************
|
||||
|
||||
|
||||
# To make sibling directories accessible for imports:
|
||||
import sys
|
||||
sys.path.append(".")
|
||||
sys.path.append("..")
|
||||
# System-level activities:
|
||||
import distro
|
||||
import socket
|
||||
import platform
|
||||
|
||||
# To measure time:
|
||||
import time
|
||||
# For data-modelling:
|
||||
from pydantic import BaseModel, Field
|
||||
from typing import Any, Optional, List, Literal
|
||||
|
||||
# To capture metrics for Prometheus:
|
||||
from prometheus_client import Counter, Summary, Gauge
|
||||
# To work with date and time:
|
||||
import datetime
|
||||
|
||||
# My utils:
|
||||
from utils_v2.api.codes import StatusCodes, HttpCodes
|
||||
from utils_v2.date_time import date_time
|
||||
|
||||
|
||||
# *****************************************************************************************************************
|
||||
@@ -50,31 +54,11 @@ from prometheus_client import Counter, Summary, Gauge
|
||||
# *****************************************************************************************************************
|
||||
|
||||
|
||||
# Define the Prometheus metrics.
|
||||
# FOR THE MICROSERVICE AS A WHOLE:
|
||||
WORKER_COUNT = Counter(
|
||||
name = "ms_workers_active_total",
|
||||
documentation = "The number of threads for the microservice being monitored.",
|
||||
labelnames = ["project_name", "service_name", "host_name"]
|
||||
)
|
||||
|
||||
# Define the Prometheus metrics.
|
||||
# FOR INDIVIDUAL API ENDPOINTS:
|
||||
REQUEST_LATENCY = Summary(
|
||||
name = "http_request_latency_seconds",
|
||||
documentation = "Latency of HTTP requests in seconds.",
|
||||
labelnames = ["method", "endpoint", "http_status"]
|
||||
)
|
||||
TOTAL_REQUEST_COUNT = Counter(
|
||||
name = "http_requests_total",
|
||||
documentation = "Total HTTP requests.",
|
||||
labelnames = ["method", "endpoint", "http_status"]
|
||||
)
|
||||
LIVE_REQUEST_COUNT = Gauge(
|
||||
name = "http_requests_live_total",
|
||||
documentation = "To check if an API endpoint is being served right now.",
|
||||
labelnames = ["endpoint"]
|
||||
)
|
||||
# Info for logging that will stay constant during runtime:
|
||||
SERVER_HOSTNAME = str(socket.gethostname())
|
||||
PLATFORM_INFO = platform.uname()
|
||||
HOST_OS = str(distro.name(True))
|
||||
HOST_CPU = f"{PLATFORM_INFO.processor} ({PLATFORM_INFO.machine})"
|
||||
|
||||
|
||||
# *****************************************************************************************************************
|
||||
@@ -94,59 +78,39 @@ LIVE_REQUEST_COUNT = Gauge(
|
||||
# *****************************************************************************************************************
|
||||
|
||||
|
||||
class MetricsAPI:
|
||||
class APILogModel(BaseModel):
|
||||
|
||||
"""
|
||||
Use this class through its context manager to automatically measure all the metrics in one place.
|
||||
This was originally created to measure the performance of API endpoints made in Quart, but it should work with
|
||||
other frameworks as well.
|
||||
"""
|
||||
# To identify the machine the code is running on.
|
||||
# DO NOT MODIFY THESE:
|
||||
hostname: str = SERVER_HOSTNAME
|
||||
os: str = HOST_OS
|
||||
cpu: str = HOST_CPU
|
||||
|
||||
def __init__(
|
||||
self,
|
||||
method = None,
|
||||
endpoint = None,
|
||||
raise_exception = False
|
||||
):
|
||||
# To identify the project and actions:
|
||||
project: Optional[str] = None
|
||||
log: str
|
||||
operation: str
|
||||
apiVer: Optional[str] = None
|
||||
logId: Optional[str] = None
|
||||
logChain: Optional[str] = None
|
||||
|
||||
# Make provisions for things to note.
|
||||
# NOTE: THESE MUST BE SET FROM OUTSIDE:
|
||||
self.method = method
|
||||
self.endpoint = endpoint
|
||||
self.http_code = None
|
||||
self.__raise_exception = raise_exception
|
||||
# Timing metrics:
|
||||
ts: datetime.datetime
|
||||
tat: float
|
||||
cpuTime: float
|
||||
|
||||
async def __aenter__(self):
|
||||
# To understand the request that came in:
|
||||
method: Optional[str] = None
|
||||
url: Optional[str] = None
|
||||
route: Optional[str] = None
|
||||
headers: Optional[Any] = None
|
||||
data: Optional[Any] = None
|
||||
files: Optional[Any] = None
|
||||
|
||||
# Note down the start time immediately:
|
||||
self.__start_ts = time.perf_counter()
|
||||
self.__cpu_start_ts = time.process_time()
|
||||
|
||||
# Note down the metrics:
|
||||
LIVE_REQUEST_COUNT.labels(self.endpoint).inc(1)
|
||||
|
||||
# Setup done:
|
||||
return self
|
||||
|
||||
async def __aexit__(self, exc_type, exc_value, traceback):
|
||||
|
||||
# Note down the metrics:
|
||||
LIVE_REQUEST_COUNT.labels(self.endpoint).dec(1)
|
||||
|
||||
TOTAL_REQUEST_COUNT.labels(
|
||||
self.method,
|
||||
self.endpoint,
|
||||
self.http_code
|
||||
).inc()
|
||||
|
||||
REQUEST_LATENCY.labels(
|
||||
self.method,
|
||||
self.endpoint,
|
||||
self.http_code
|
||||
).observe(time.perf_counter() - self.__start_ts)
|
||||
|
||||
# Handle the exception as per the user's preference:
|
||||
return False if self.__raise_exception else True
|
||||
# To understand the output that went out:
|
||||
exception: Optional[Any] = None
|
||||
response: Optional[Any] = None
|
||||
httpCode: Optional[int] = None
|
||||
|
||||
|
||||
# *****************************************************************************************************************
|
||||
@@ -168,31 +132,8 @@ class MetricsAPI:
|
||||
|
||||
if __name__ == "__main__":
|
||||
|
||||
import asyncio
|
||||
import random
|
||||
from prometheus_client import generate_latest
|
||||
my_log = APILogModel(
|
||||
log = "internal"
|
||||
)
|
||||
|
||||
async def simulate_endpoint():
|
||||
|
||||
async with MetricsAPI(
|
||||
method = random.choice(["GET", "POST"]),
|
||||
endpoint = f"https://my.domain.com/api/{random.choice([0, 1, 2, 3])}"
|
||||
) as metrics:
|
||||
|
||||
# Simulate some action on some endpoint:
|
||||
await asyncio.sleep(1.0)
|
||||
|
||||
# Note down the values:
|
||||
metrics.http_code = 200
|
||||
|
||||
async def main():
|
||||
|
||||
print("Simulating endpoints...")
|
||||
tasks = [simulate_endpoint() for _ in range(250)]
|
||||
await asyncio.gather(*tasks)
|
||||
print("Done!")
|
||||
|
||||
print("METRICS:")
|
||||
print(generate_latest().decode())
|
||||
|
||||
asyncio.run(main())
|
||||
print(my_log)
|
||||
@@ -30,9 +30,11 @@
|
||||
# *****************************************************************************************************************
|
||||
|
||||
|
||||
# For data-modelling:
|
||||
from pydantic import BaseModel
|
||||
from typing import Any, Optional, List
|
||||
|
||||
# My utils:
|
||||
from utils_v2.api.codes import StatusCodes, HttpCodes
|
||||
|
||||
|
||||
@@ -64,6 +66,11 @@ from utils_v2.api.codes import StatusCodes, HttpCodes
|
||||
|
||||
class ResponseModel(BaseModel):
|
||||
|
||||
"""
|
||||
A model for how the response should be when developing API endpoints.
|
||||
"""
|
||||
|
||||
# The fields that you want in your response:
|
||||
status_code: StatusCodes
|
||||
message: Optional[str | List] = None
|
||||
data: Optional[Any] = None
|
||||
@@ -74,6 +81,11 @@ class ResponseModel(BaseModel):
|
||||
|
||||
def for_quart(self):
|
||||
|
||||
"""
|
||||
Call this when you are using either Flask or Quart as your framework.
|
||||
:return: The output as expected by Flask and Quart.
|
||||
"""
|
||||
|
||||
# Construct the basic structure:
|
||||
response_dict = {
|
||||
"status": 1 if self.status_code.value[0] else 0,
|
||||
|
||||
Reference in New Issue
Block a user