WIP

Author: mithenks

.github/workflows/publish-tag.yaml

@@ -28,6 +28,11 @@ jobs:
           service_account: github-actions-sa@ai-accounting-405809.iam.gserviceaccount.com
           access_token_lifetime: 600s
 
+      - name: Set application version
+        run: |
+            sed -i 's|version = "\(.*\)"|version = "${{ github.ref_name }}"|g' app/pyproject.toml && 
+            cat app/pyproject.toml
+
       - name: Setup Python
         uses: actions/setup-python@v3
 

app/pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta"
 
 [project]
 name = "zcs-python-core"
-version = "0.3.0"
+version = "0.dev0"
 description = "A Python library that provides core functionalities for ZCS projects"
 
 [tool.setuptools.packages.find]

app/src/zcs/core/logger/logger.py

@@ -1,7 +1,10 @@
 import json
 import logging
+import time
+from logging import LogRecord
 
 from zcs.core.exception import ZcsException
+from zcs.core.session import request_context, RequestState
 
 old_factory = logging.getLogRecordFactory()
 
@@ -31,6 +34,9 @@ def record_factory(*args, **kwargs):
 class CloudJsonFormatter(logging.Formatter):
     def format(self, record):
 
+        # FIXME
+        # log op_code, request_id and time deltas
+
         message = record.getMessage()
         if record.exc_info and record.original_exception:
             message = str(record.original_exception)
@@ -79,8 +85,19 @@ def __init__(self, verbose=False):
             logging.CRITICAL: logging.Formatter(set_bold_red + base_format + reset)
         }
 
-    def format(self, record):
+    def format(self, record: LogRecord) -> str:
         formatter = self.FORMATTERS.get(record.levelno)
+
+        # Retrieve request state from request context
+        request_state: RequestState = request_context.get()
+        if request_state:
+            time_ns = time.perf_counter_ns()
+            delta_ns = time_ns - request_state.getCheckpointNs()
+            total_ns = time_ns - request_state.getRequestStartNs()
+            request_state.setCheckpointNs(time_ns)
+            record.msg = "[OP_CODE:{}][REQ_ID:{}] {} ({:.2f}s delta - {:.2f}s total)".format(
+                request_state.getOpCode(), request_state.getRequestId(), record.msg, delta_ns / 1e9, total_ns / 1e9)
+
         return formatter.format(record)
 
 

app/src/zcs/core/session/__init__.py

@@ -0,0 +1,3 @@
+from .request_context import request_context
+from .operation_details import OperationDetails
+from .request_state import RequestState

app/src/zcs/core/session/operation_details.py

@@ -0,0 +1,63 @@
+import time
+import logging
+from typing import Literal, Optional
+import uuid
+from dataclasses import dataclass
+
+
+@dataclass
+class OperationDetailsConfig:
+    time_threshold_ms: int
+
+
+@dataclass
+class OperationDetails:
+    """
+    Class used to record and manage detailed data about a specific operation.
+    """
+
+    def __init__(self, operation_code: str, logger: Optional[logging.Logger] = None):
+        self.__operation_code = operation_code
+        self.__logger = logger if logger else logging.getLogger()
+        self.__start_time_ns = time.perf_counter_ns()
+        self.__last_time_ns = self.__start_time_ns
+
+    def getStartTimeNs(self) -> int:
+        return self.__start_time_ns
+
+    def getOpCode(self) -> str:
+        return self.__operation_code
+
+    def logCheckpoint(self, message: Optional[str] = None, level: Literal[20] = logging.INFO):
+        time_ns = time.perf_counter_ns()
+        self.__logger.log(
+            level,
+            "[{}] {} ({:.2f}s delta - {:.2f}s total)".format(
+                self.__operation_code,
+                message,
+                (time_ns - self.__last_time_ns) / 1e9,
+                (time_ns - self.__start_time_ns) / 1e9
+            )
+        )
+        self.__last_time_ns = time_ns
+
+    @staticmethod
+    def create(op_code: Optional[str] = None, prefix: Optional[str] = None, logger=None) -> "OperationDetails":
+
+        # Use passed operation code if present, otherwise generate a new one
+        operation_code = op_code if op_code else OperationDetails.generate_op_code(prefix)
+
+        operation_details = OperationDetails(operation_code, logger)
+
+        return operation_details
+
+    @staticmethod
+    def generate_op_code(prefix: Optional[str] = None) -> str:
+        """
+        Generate a new unique operation code.
+        If prefix is provided, prepend it to the generated code.
+        """
+        op_code = str(uuid.uuid4())
+        if prefix:
+            return f"{prefix}_{op_code}"
+        return op_code

app/src/zcs/core/session/request_context.py

@@ -0,0 +1,3 @@
+import contextvars
+
+request_context = contextvars.ContextVar("request_state", default=None)

app/src/zcs/core/session/request_state.py

@@ -0,0 +1,63 @@
+import time
+import uuid
+from typing import Optional
+
+
+class RequestState():
+
+    def __init__(
+            self,
+            request_id: Optional[str] = None,
+            prefix: Optional[str] = None,
+            op_code: Optional[str] = None):
+
+        self.__request_id = request_id if request_id else RequestState.generate_op_code(prefix=prefix)
+        self.__op_code = op_code if op_code else self.__request_id
+        self.__request_start_ns = time.perf_counter_ns()
+        self.__checkpoint_ns = self.__request_start_ns
+
+    def getOpCode(self) -> str:
+        """
+        Get operation code value.
+        """
+
+        return self.__op_code
+
+    def getRequestId(self) -> str:
+        """
+        Get request id value.
+        """
+
+        return self.__request_id
+
+    def getRequestStartNs(self) -> int:
+        """
+        Get request start time in nanoseconds.
+        """
+
+        return self.__request_start_ns
+
+    def getCheckpointNs(self) -> int:
+        """
+        Get checkpoint time in nanoseconds.
+        """
+
+        return self.__checkpoint_ns
+
+    def setCheckpointNs(self, time_ns: int):
+        """
+        Set checkpoint time in nanoseconds.
+        """
+
+        self.__checkpoint_ns = time_ns
+
+    @staticmethod
+    def generate_op_code(prefix: Optional[str] = None) -> str:
+        """
+        Generate a new unique operation code.
+        If prefix is provided, prepend it to the generated code.
+        """
+        op_code = str(uuid.uuid4())
+        if prefix:
+            return f"{prefix}_{op_code}"
+        return op_code