feat: configure logger with detail info (#654)

Co-authored-by: ishandhanani <82981111+ishandhanani@users.noreply.github.com>

deploy/dynamo/sdk/src/dynamo/sdk/cli/serve.py

@@ -141,7 +141,7 @@ def build_serve_command() -> click.Group:
             rich.print(f"DYNAMO_SERVICE_CONFIG={json.dumps(service_configs)}")
             sys.exit(0)
 
-        configure_server_logging()
+        configure_server_logging(service_name=service_name)
         # Set environment variable with service configuration
         if service_configs:
             logger.info(f"Running dynamo serve with service configs {service_configs}")

deploy/dynamo/sdk/src/dynamo/sdk/cli/serve_dynamo.py

@@ -68,7 +68,6 @@ def main(
 
     from dynamo.sdk.lib.logging import configure_server_logging
 
-    run_id = service_name
     dynamo_context["service_name"] = service_name
     dynamo_context["runner_map"] = runner_map
     dynamo_context["worker_id"] = worker_id
@@ -89,7 +88,7 @@ def main(
     if service_name and service_name != service.name:
         service = service.find_dependent_by_name(service_name)
 
-    configure_server_logging()
+    configure_server_logging(service_name=service_name, worker_id=worker_id)
     if runner_map:
         BentoMLContainer.remote_runner_mapping.set(
             t.cast(t.Dict[str, str], json.loads(runner_map))
@@ -115,32 +114,30 @@ def main(
 
             # Get Dynamo configuration and create component
             namespace, component_name = service.dynamo_address()
-            logger.info(
-                f"[{run_id}] Registering component {namespace}/{component_name}"
-            )
+            logger.info(f"Registering component {namespace}/{component_name}")
             component = runtime.namespace(namespace).component(component_name)
 
             try:
                 # Create service first
                 await component.create_service()
-                logger.info(f"[{run_id}] Created {service.name} component")
+                logger.info(f"Created {service.name} component")
 
                 # Set runtime on all dependencies
                 for dep in service.dependencies.values():
                     dep.set_runtime(runtime)
-                    logger.debug(f"[{run_id}] Set runtime for dependency: {dep}")
+                    logger.debug(f"Set runtime for dependency: {dep}")
 
                 # Then register all Dynamo endpoints
                 dynamo_endpoints = service.get_dynamo_endpoints()
                 if not dynamo_endpoints:
-                    error_msg = f"[{run_id}] FATAL ERROR: No Dynamo endpoints found in service {service.name}!"
+                    error_msg = f"FATAL ERROR: No Dynamo endpoints found in service {service.name}!"
                     logger.error(error_msg)
                     raise ValueError(error_msg)
 
                 endpoints = []
                 for name, endpoint in dynamo_endpoints.items():
                     td_endpoint = component.endpoint(name)
-                    logger.debug(f"[{run_id}] Registering endpoint '{name}'")
+                    logger.debug(f"Registering endpoint '{name}'")
                     endpoints.append(td_endpoint)
                     # Bind an instance of inner to the endpoint
                 dynamo_context["component"] = component
@@ -161,24 +158,22 @@ def main(
                     if callable(member) and getattr(
                         member, "__bentoml_startup_hook__", False
                     ):
-                        logger.debug(f"[{run_id}] Running startup hook: {name}")
+                        logger.debug(f"Running startup hook: {name}")
                         result = getattr(class_instance, name)()
                         if inspect.isawaitable(result):
                             # await on startup hook async_on_start
                             await result
-                            logger.debug(
-                                f"[{run_id}] Completed async startup hook: {name}"
-                            )
+                            logger.debug(f"Completed async startup hook: {name}")
                         else:
-                            logger.info(f"[{run_id}] Completed startup hook: {name}")
+                            logger.info(f"Completed startup hook: {name}")
                 logger.info(
-                    f"[{run_id}] Starting {service.name} instance with all registered endpoints"
+                    f"Starting {service.name} instance with all registered endpoints"
                 )
                 # TODO:bis: convert to list
                 result = await endpoints[0].serve_endpoint(twm[0])
 
             except Exception as e:
-                logger.error(f"[{run_id}] Error in Dynamo component setup: {str(e)}")
+                logger.error(f"Error in Dynamo component setup: {str(e)}")
                 raise
 
         uvloop.install()

deploy/dynamo/sdk/src/dynamo/sdk/cli/serving.py

@@ -261,7 +261,7 @@ def serve_http(
 
     from .allocator import ResourceAllocator
 
-    configure_server_logging()
+    configure_server_logging(service_name=service_name)
 
     bento_id: str = ""
     namespace: str = ""
@@ -288,8 +288,7 @@ def serve_http(
     # TODO: Only for testing, this will prevent any other dep services from getting started, relying entirely on configured deps in the runner-map
     standalone = False
     if service_name:
-        logger.info("Running in standalone mode")
-        logger.info(f"service_name: {service_name}")
+        logger.info(f"Service '{service_name}' running in standalone mode")
         standalone = True
 
     if service_name and service_name != svc.name:
@@ -421,7 +420,7 @@ def serve_http(
             )
             watchers.append(watcher)
             logger.info(
-                f"Created watcher for {svc.name}'s in the {namespace} namespace"
+                f"Created watcher for {svc.name} with {num_workers} workers in the {namespace} namespace"
             )
         else:
             watchers.append(
@@ -433,6 +432,7 @@ def serve_http(
                     env=env,
                 )
             )
+            logger.info(f"Created watcher for service with {num_workers} workers")
 
         log_host = "localhost" if host in ["0.0.0.0", "::"] else host
         dependency_map[svc.name] = f"{scheme}://{log_host}:{port}"
@@ -461,7 +461,7 @@ def serve_http(
                 ),
                 ignore_errors=True,
             )
-            logger.warn(f"arbiter: {arbiter.endpoint}")
+            logger.warning(f"arbiter: {arbiter.endpoint}")
             # save deployment state for planner
             if not namespace:
                 raise ValueError("No namespace found for service")

deploy/dynamo/sdk/src/dynamo/sdk/lib/bento.py

@@ -174,7 +174,7 @@ class Bento(BaseBento):
                     path = fs.path.combine(dir_path, f.name).lstrip("/")
                     if specs.includes(path):
                         if ctx_fs.getsize(path) > 10 * 1024 * 1024:
-                            logger.warn("File size is larger than 10MiB: %s", path)
+                            logger.warning("File size is larger than 10MiB: %s", path)
                         target_fs.makedirs(dir_path, recreate=True)
                         copy_file(ctx_fs, path, target_fs, path)
             if image is None:

deploy/dynamo/sdk/src/dynamo/sdk/lib/logging.py

@@ -22,7 +22,9 @@ import tempfile
 from dynamo.runtime.logging import configure_logger as configure_dynamo_logger
 
 
-def configure_server_logging():
+def configure_server_logging(
+    service_name: str | None = None, worker_id: int | None = None
+):
     """
     A single place to configure logging for Dynamo.
     """
@@ -32,7 +34,7 @@ def configure_server_logging():
         root_logger.removeHandler(handler)
 
     # Configure the logger with Dynamo's handler
-    configure_dynamo_logger()
+    configure_dynamo_logger(service_name, worker_id)
 
     # map the DYN_LOG variable to a logging level
     dyn_var = os.environ.get("DYN_LOG", "info")

examples/hello_world/hello_world.py

@@ -21,8 +21,6 @@ from dynamo.sdk import DYNAMO_IMAGE, api, depends, dynamo_endpoint, service
 from dynamo.sdk.lib.config import ServiceConfig
 from dynamo.sdk.lib.logging import configure_server_logging
 
-# Configure logging
-configure_server_logging()
 logger = logging.getLogger(__name__)
 
 """
@@ -111,6 +109,9 @@ class Frontend:
     middle = depends(Middle)
 
     def __init__(self) -> None:
+        # Configure logging
+        configure_server_logging(service_name="Frontend")
+
         logger.info("Starting frontend")
         config = ServiceConfig.get_instance()
         self.message = config.get("Frontend", {}).get("message", "front")

lib/bindings/python/src/dynamo/runtime/logging.py

@@ -42,14 +42,30 @@ class LogHandler(logging.Handler):
 
 
 # Configure the Python logger to use the NimLogHandler
-def configure_logger():
+def configure_logger(service_name: str | None, worker_id: int | None):
     """
     Called once to configure the Python logger to use the LogHandler
     """
     logger = logging.getLogger()
     logger.setLevel(logging.DEBUG)
     handler = LogHandler()
+
     # Simple formatter without date and level info since it's already provided by Rust
     formatter = logging.Formatter("%(message)s")
+    formatter_prefix = construct_formatter_prefix(service_name, worker_id)
+    if len(formatter_prefix) != 0:
+        formatter = logging.Formatter(f"[{formatter_prefix}] %(message)s")
+
     handler.setFormatter(formatter)
     logger.addHandler(handler)
+
+
+def construct_formatter_prefix(service_name: str | None, worker_id: int | None) -> str:
+    tmp = ""
+    if service_name is not None:
+        tmp += f"{service_name}"
+
+    if worker_id is not None:
+        tmp += f":{worker_id}"
+
+    return tmp.strip()