Internal logging and tracing improvements. (#1886)

Author: ganeshrvel

src/ragas/sdk.py

@@ -7,8 +7,10 @@
 
 import requests
 
+from ragas._analytics import get_userid
 from ragas._version import __version__
 from ragas.exceptions import UploadException
+from ragas.utils import base_logger
 
 # endpoint for uploading results
 RAGAS_API_URL = "https://api.ragas.io"
@@ -46,6 +48,7 @@ def upload_packet(path: str, data_json_string: str):
             "x-app-token": app_token,
             "x-source": RAGAS_API_SOURCE,
             "x-app-version": __version__,
+            "x-ragas-lib-user-uuid": get_userid(),
         },
     )
     check_api_response(response)
@@ -67,6 +70,11 @@ def check_api_response(response: requests.Response) -> None:
         If authentication fails or other API errors occur
     """
     if response.status_code == 403:
+        base_logger.error(
+            "[AUTHENTICATION_ERROR] The app token is invalid. "
+            "Please check your RAGAS_APP_TOKEN environment variable. "
+            f"Response Status: {response.status_code}, URL: {response.url}"
+        )
         raise UploadException(
             status_code=response.status_code,
             message="AUTHENTICATION_ERROR: The app token is invalid. Please check your RAGAS_APP_TOKEN environment variable.",
@@ -85,6 +93,11 @@ def check_api_response(response: requests.Response) -> None:
         except Exception as _e:
             error_msg = f"\nStatus Code: {response.status_code}"
 
+        base_logger.error(
+            f"[API_ERROR] Request failed. "
+            f"Status Code: {response.status_code}, URL: {response.url}, "
+            f"Error Message: {error_msg}"
+        )
         raise UploadException(
             status_code=response.status_code, message=f"Request failed: {error_msg}"
         )

src/ragas/utils.py

@@ -12,6 +12,8 @@
 import tiktoken
 from datasets import Dataset
 
+from datetime import datetime
+
 if t.TYPE_CHECKING:
     from ragas.metrics.base import Metric
 
@@ -238,20 +240,69 @@ def batched(iterable: t.Iterable, n: int) -> t.Iterator[t.Tuple]:
         yield batch
 
 
-def set_logging_level(logger_name: str, level: int):
+_LOGGER_DATE_TIME = "%Y-%m-%d %H:%M:%S"
+
+
+def set_logging_level(logger_name: str = __name__, level: int = logging.DEBUG):
     """
     Set the logging level for a logger. Useful for debugging.
     """
     logger = logging.getLogger(logger_name)
     logger.setLevel(level)
 
+    log_format = (
+        "[%(local_time)s - (%(utc_time)s UTC)] "
+        "[%(levelname)s] [%(name)s] "
+        "[RagasID: %(ragas_id)s, App-Version: %(app_version)s] %(message)s"
+    )
+
+    # Create a formatter with the custom formatter
+    formatter = _ContextualFormatter(log_format, datefmt=_LOGGER_DATE_TIME)
+
     # Create a console handler and set its level
     console_handler = logging.StreamHandler()
-    console_handler.setLevel(logging.DEBUG)
+    console_handler.setLevel(level)
 
-    # Create a formatter and add it to the handler
-    formatter = logging.Formatter("%(name)s - %(levelname)s - %(message)s")
+    # Apply the formatter to the handler
     console_handler.setFormatter(formatter)
 
     # Add the handler to the logger
     logger.addHandler(console_handler)
+
+    return logger
+
+
+class _ContextualFormatter(logging.Formatter):
+    """
+    Custom logging formatter that adds context to the log records.
+    """
+
+    def format(self, record):
+        from ragas._analytics import get_userid
+        from ragas import __version__
+
+        # Add UTC time
+        record.utc_time = self.format_time(record, _LOGGER_DATE_TIME)
+        # Add local time
+        record.local_time = self.format_time(record, _LOGGER_DATE_TIME, local_time=True)
+        # Add additional context
+        record.ragas_id = get_userid()
+        record.app_version = __version__
+        return super().format(record)
+
+    def format_time(self, record, datefmt=None, local_time=False):
+        dt = (
+            self.utc_converter(record.created)
+            if not local_time
+            else datetime.fromtimestamp(record.created)
+        )
+        if datefmt:
+            return dt.strftime(datefmt)
+        return dt.isoformat()
+
+    @staticmethod
+    def utc_converter(timestamp):
+        return datetime.utcfromtimestamp(timestamp)  # UTC time conversion
+
+
+base_logger = set_logging_level()