feat: add logging

Dockerfile

@@ -1,4 +1,4 @@
-FROM python:3.11-slim as python-base
+FROM python:3.11-slim AS python-base
 
 # https://python-poetry.org/docs#ci-recommendations
 ENV POETRY_VERSION=1.6.0
@@ -9,15 +9,15 @@ ENV POETRY_VENV=/opt/poetry-venv
 ENV POETRY_CACHE_DIR=/opt/.cache
 
 # Create stage for Poetry installation
-FROM python-base as poetry-base
+FROM python-base AS poetry-base
 
 # Creating a virtual environment just for poetry and install it with pip
 RUN python3 -m venv $POETRY_VENV \
     && $POETRY_VENV/bin/pip install -U pip setuptools \
     && $POETRY_VENV/bin/pip install poetry==${POETRY_VERSION}
 
 # Create a new stage from the base python image
-FROM python-base as build
+FROM python-base AS build
 
 # Copy Poetry to app image
 COPY --from=poetry-base ${POETRY_VENV} ${POETRY_VENV}

app/helpers/postgres.py

@@ -7,6 +7,7 @@
 from psycopg2.extensions import connection, cursor
 
 from helpers.hasura import untrack_table, track_table
+from helpers.timer import Timer
 from models import Metadata, BatchRequest, CreateTableResult
 
 conn: connection = None
@@ -148,6 +149,7 @@ def execute_delete(metadata: Metadata, payload: list[Any]):
 
 
 def do_insert(metadata: Metadata, payload: list[Any]):
+    t = Timer(f"sql_before of {metadata.table_name}").start()
     if metadata.sql_before:
         try:
             cur.execute(metadata.sql_before)
@@ -156,7 +158,9 @@ def do_insert(metadata: Metadata, payload: list[Any]):
                 status_code=400,
                 detail=f"Error while executing sql_before of '{metadata.table_name}':\n{e}"
             )
+    t.stop()
 
+    t = Timer(f"insert of {metadata.table_name}").start()
     try:
         execute_upsert(metadata, payload)
         if metadata.write_mode == 'overwrite':
@@ -167,7 +171,9 @@ def do_insert(metadata: Metadata, payload: list[Any]):
             status_code=400,
             detail=f"Error while inserting tuples into '{metadata.table_name}':\n{e}"
         )
+    t.stop()
 
+    t = Timer(f"sql_after of {metadata.table_name}").start()
     if metadata.sql_after:
         try:
             cur.execute(metadata.sql_after)
@@ -176,6 +182,7 @@ def do_insert(metadata: Metadata, payload: list[Any]):
                 status_code=400,
                 detail=f"Error while executing sql_after of '{metadata.table_name}':\n{e}"
             )
+    t.stop()
 
 
 def do_batch_insert(requests: list[BatchRequest]):

app/helpers/timer.py

@@ -0,0 +1,35 @@
+import time
+
+class TimerError(Exception):
+    """A custom exception used to report errors in use of Timer class"""
+
+class Timer:
+    def __init__(
+        self,
+        label="Elapsed time",
+        logger=print
+    ):
+        self._start_time = None
+        self.label = label
+        self.logger = logger
+
+    def start(self):
+        """Start a new timer"""
+        if self._start_time is not None:
+            raise TimerError(f"Timer is running. Use .stop() to stop it")
+
+        self._start_time = time.perf_counter()
+        return self
+
+    def stop(self):
+        """Stop the timer, and report the elapsed time"""
+        if self._start_time is None:
+            raise TimerError(f"Timer is not running. Use .start() to start it")
+
+        elapsed_time = time.perf_counter() - self._start_time
+        self._start_time = None
+
+        if self.logger:
+            self.logger((self.label + ": {:0.4f} seconds").format(elapsed_time))
+
+        return elapsed_time

docker-compose.yaml

@@ -1,4 +1,3 @@
-version: "3.6"
 services:
   hasuragres:
     build: .