Merge pull request #215 from runpod/json-logging

Json logging

Author: justinmerrell

examples/serverless/logger.py

@@ -0,0 +1,30 @@
+""" Example of using the RunPodLogger class. """""
+
+import runpod
+
+JOB_ID = '1234567890'
+log = runpod.RunPodLogger()
+
+
+log.debug('A debug message')
+log.info('An info message')
+log.warn('A warning message')
+log.error('An error message')
+
+# Output:
+# DEBUG   | A debug message
+# INFO    | An info message
+# WARN    | A warning message
+# ERROR   | An error message
+
+
+log.debug('A debug message', job_id=JOB_ID)
+log.info('An info message', job_id=JOB_ID)
+log.warn('A warning message', job_id=JOB_ID)
+log.error('An error message', job_id=JOB_ID)
+
+# Output:
+# {"requestId": "1234567890", "message": "A debug message", "level": "DEBUG"}
+# {"requestId": "1234567890", "message": "An info message", "level": "INFO"}
+# {"requestId": "1234567890", "message": "A warning message", "level": "WARN"}
+# {"requestId": "1234567890", "message": "An error message", "level": "ERROR"}

requirements.txt

@@ -9,12 +9,10 @@ fastapi[all] >= 0.94.0
 paramiko >= 3.3.1
 prettytable >= 3.9.0
 py-cpuinfo >= 9.0.0
-python-dotenv >= 1.0.0
 inquirerpy == 0.3.4
 requests >= 2.31.0
 tomli >= 2.0.1
 tomlkit >= 0.12.2
 tqdm-loggable >= 0.1.4
 urllib3 >= 1.26.6
-setuptools_scm >= 8.0.4
 watchdog >= 3.0.0

runpod/__init__.py

@@ -4,10 +4,11 @@
 import logging
 
 from . import serverless
+from .serverless.modules.rp_logger import RunPodLogger
 from .endpoint import Endpoint
 from .endpoint import AsyncioEndpoint, AsyncioJob
 from .version import __version__
-from .api.ctl_commands import(
+from .api.ctl_commands import (
     get_user, update_user_settings,
     get_gpu, get_gpus,
     get_pod, get_pods, create_pod, stop_pod, resume_pod, terminate_pod,

runpod/serverless/modules/rp_logger.py

@@ -11,10 +11,8 @@
 '''
 
 import os
-from dotenv import load_dotenv
+import json
 
-env_path = os.path.join(os.getcwd(), '.env')
-load_dotenv(env_path)  # Load environment variables
 
 LOG_LEVELS = ['NOTSET', 'DEBUG', 'INFO', 'WARN', 'ERROR']
 
@@ -46,7 +44,8 @@ class RunPodLogger:
     __instance = None
     level = _validate_log_level(os.environ.get(
         'RUNPOD_LOG_LEVEL',
-        os.environ.get('RUNPOD_DEBUG_LEVEL', 'DEBUG')))
+        os.environ.get('RUNPOD_DEBUG_LEVEL', 'DEBUG'))
+    )
 
     def __new__(cls):
         if RunPodLogger.__instance is None:
@@ -61,7 +60,7 @@ def set_level(self, new_level):
         self.level = _validate_log_level(new_level)
         self.info(f'Log level set to {self.level}')
 
-    def log(self, message, message_level='INFO'):
+    def log(self, message, message_level='INFO', job_id=None):
         '''
         Log message to stdout if RUNPOD_DEBUG is true.
         '''
@@ -72,6 +71,15 @@ def log(self, message, message_level='INFO'):
         if level_index > LOG_LEVELS.index(message_level) and message_level != 'TIP':
             return
 
+        if job_id:
+            log_json = {
+                'requestId': job_id,
+                'message': message,
+                'level': message_level
+            }
+            print(json.dumps(log_json), flush=True)
+            return
+
         print(f'{message_level.ljust(7)}| {message}', flush=True)
         return
 
@@ -84,29 +92,29 @@ def secret(self, secret_name, secret):
         redacted_secret = secret[0] + '*' * (len(secret)-2) + secret[-1]
         self.info(f"{secret_name}: {redacted_secret}")
 
-    def debug(self, message):
+    def debug(self, message, job_id=None):
         '''
         debug log
         '''
-        self.log(message, 'DEBUG')
+        self.log(message, 'DEBUG', job_id)
 
-    def info(self, message):
+    def info(self, message, job_id=None):
         '''
         info log
         '''
-        self.log(message, 'INFO')
+        self.log(message, 'INFO', job_id)
 
-    def warn(self, message):
+    def warn(self, message, job_id=None):
         '''
         warn log
         '''
-        self.log(message, 'WARN')
+        self.log(message, 'WARN', job_id)
 
-    def error(self, message):
+    def error(self, message, job_id=None):
         '''
         error log
         '''
-        self.log(message, 'ERROR')
+        self.log(message, 'ERROR', job_id)
 
     def tip(self, message):
         '''

tests/test_serverless/test_modules/test_logger.py

@@ -57,15 +57,15 @@ def test_call_log(self):
 
             log.warn("Test log message")
 
-            mock_log.assert_called_once_with("Test log message", "WARN")
+            mock_log.assert_called_once_with("Test log message", "WARN", None)
 
         log.set_level(0)
         with patch("runpod.serverless.modules.rp_logger.RunPodLogger.log") as mock_log, \
-            patch("builtins.print") as mock_print:
+                patch("builtins.print") as mock_print:
 
             log.debug("Test log message")
 
-            mock_log.assert_called_once_with("Test log message", "DEBUG")
+            mock_log.assert_called_once_with("Test log message", "DEBUG", None)
             mock_print.assert_not_called()
 
         # Reset log level
@@ -99,7 +99,7 @@ def test_log_secret(self):
         '''
         with patch("runpod.serverless.modules.rp_logger.RunPodLogger.log") as mock_log:
             self.logger.secret("test_secret", "test_secret_value")
-            mock_log.assert_called_once_with("test_secret: t***************e", "INFO")
+            mock_log.assert_called_once_with("test_secret: t***************e", "INFO", None)
 
     def test_log_tip(self):
         '''
@@ -108,3 +108,16 @@ def test_log_tip(self):
         with patch("runpod.serverless.modules.rp_logger.RunPodLogger.log") as mock_log:
             self.logger.tip("test_tip")
             mock_log.assert_called_once_with("test_tip", "TIP")
+
+    def test_log_job_id(self):
+        """ Tests that the log method logs a job id """
+        logger = rp_logger.RunPodLogger()
+        job_id = "test_job_id"
+
+        # Patch print to capture stdout
+        with patch("builtins.print") as mock_print:
+            logger.log("test_message", "INFO", job_id)
+            mock_print.assert_called_once_with(
+                '{"requestId": "test_job_id", "message": "test_message", "level": "INFO"}',
+                flush=True
+            )