Add trace_id to GolemNode startup and shutdown to improve multiple Go…

…lemNode instances tracing (#158)

golem/event_bus/in_memory/event_bus.py

@@ -30,7 +30,9 @@ def __init__(self):
     @trace_span()
     async def start(self):
         if self.is_started():
-            raise EventBusError("Event bus is already started!")
+            err_msg = "Event bus is already started!"
+            logger.error(err_msg)
+            raise EventBusError(err_msg)
 
         self._process_event_queue_loop_task = create_task_with_logging(
             self._process_event_queue_loop(),

golem/node/node.py

@@ -26,6 +26,7 @@
     Resource,
     TResource,
 )
+from golem.utils.logging import get_trace_id_name, set_trace_id
 from golem.utils.low import ApiConfig, ApiFactory
 
 
@@ -97,16 +98,18 @@ def app_key(self) -> str:
     #   Start/stop interface
     async def __aenter__(self) -> "GolemNode":
         """Start. Initialize all the APIs and the event bus."""
-        await self.start()
-        return self
+        with set_trace_id(get_trace_id_name(self, "golem-node-start")):
+            await self.start()
+            return self
 
     async def __aexit__(self, *exc_info: Any) -> None:
         """Shutdown.
 
         Stop collecting yagna events, close all resources created with autoclose=True, close
         APIs etc.
         """
-        await self.aclose()
+        with set_trace_id(get_trace_id_name(self, "golem-node-shutdown")):
+            await self.aclose()
 
     async def start(self) -> None:
         await self.event_bus.start()

golem/utils/logging.py

@@ -2,6 +2,7 @@
 import inspect
 import logging
 import sys
+from contextlib import contextmanager
 from datetime import datetime, timezone
 from functools import wraps
 from typing import TYPE_CHECKING, Any, Callable, Dict, Optional, Sequence, Union
@@ -149,6 +150,15 @@ async def on_event(self, event: "Event") -> None:
 trace_id_var = contextvars.ContextVar("trace_id", default="root")
 
 
+@contextmanager
+def set_trace_id(trace_id):
+    token = trace_id_var.set(trace_id)
+    try:
+        yield
+    finally:
+        trace_id_var.reset(token)
+
+
 def get_trace_id_name(obj: Any, postfix: str) -> str:
     return f"{obj.__class__.__name__}-{id(obj)}-{postfix}"
 

tests/unit/test_payload_parsers.py

@@ -26,7 +26,10 @@ def test_parse_raises_exception_on_bad_syntax(demand_offer_parser):
         ("(float.value=1.5)", Constraint("float.value", "=", "1.5")),
         ("(float.!exp.value=1.5)", Constraint("float.!exp.value", "=", "1.5")),
         ("(foo=bar)", Constraint("foo", "=", "bar")),
-        ("(foo=multiple words with spaces and   double  tabs)", Constraint("foo", "=", "multiple words with spaces and   double  tabs")),
+        (
+            "(foo=multiple words with spaces and   double  tabs)",
+            Constraint("foo", "=", "multiple words with spaces and   double  tabs"),
+        ),
         (r"(foo=escaped\2Acharacters)", Constraint("foo", "=", r"escaped\2Acharacters")),
         (
             "(foo=more.complex.value)",