From d632c1b234b13d2abffd22a31ba0b52eb7f4ed2f Mon Sep 17 00:00:00 2001
From: Iisakki Rotko <iisakki.rotko@gmail.com>
Date: Thu, 22 Feb 2024 15:31:49 +0100
Subject: [PATCH] feat: improve logging of reactive variable changes

---
 solara/__main__.py        |  8 ++++++--
 solara/server/settings.py |  1 +
 solara/toestand.py        | 39 ++++++++++++++++++++++++++++++++++++++-
 3 files changed, 45 insertions(+), 3 deletions(-)

diff --git a/solara/__main__.py b/solara/__main__.py
index cea8074f3..62071d704 100644
--- a/solara/__main__.py
+++ b/solara/__main__.py
@@ -11,12 +11,13 @@
 
 import rich
 import rich_click as click
-import solara
 import uvicorn
 from rich import print as rprint
-from solara.server import settings
 from uvicorn.main import LEVEL_CHOICES, LOOP_CHOICES
 
+import solara
+from solara.server import settings
+
 from .server import telemetry
 
 try:
@@ -359,7 +360,10 @@ def open_browser():
 
     if log_level is not None:
         LOGGING_CONFIG["loggers"]["solara"]["level"] = log_level.upper()
+        settings.main.log_level = log_level.upper()
         # LOGGING_CONFIG["loggers"]["reacton"]["level"] = log_level.upper()
+    else:
+        settings.main.log_level = "ERROR"
 
     log_level = log_level_uvicorn
     del log_level_uvicorn
diff --git a/solara/server/settings.py b/solara/server/settings.py
index e1c7cf634..2ccf2afcf 100644
--- a/solara/server/settings.py
+++ b/solara/server/settings.py
@@ -150,6 +150,7 @@ class MainSettings(BaseSettings):
     platform: str = sys.platform
     host: str = HOST_DEFAULT
     experimental_performance: bool = False
+    log_level: str = "INFO"
 
     class Config:
         env_prefix = "solara_"
diff --git a/solara/toestand.py b/solara/toestand.py
index af76efc8b..a3615e8aa 100644
--- a/solara/toestand.py
+++ b/solara/toestand.py
@@ -28,11 +28,13 @@
 
 import solara
 from solara import _using_solara_server
+from solara.server import settings
 
 T = TypeVar("T")
 TS = TypeVar("TS")
 S = TypeVar("S")  # used for state
 logger = logging.getLogger("solara.toestand")
+solara_logger = logging.getLogger("solara")
 
 _DEBUG = False
 
@@ -86,6 +88,38 @@ def __init__(self, merge: Callable = merge_state):
         self.merge = merge
         self.listeners: Dict[str, Set[Tuple[Callable[[T], None], Optional[ContextManager]]]] = defaultdict(set)
         self.listeners2: Dict[str, Set[Tuple[Callable[[T, T], None], Optional[ContextManager]]]] = defaultdict(set)
+        if settings.main.log_level in ["DEBUG", "INFO"]:
+            import inspect
+
+            for frame in inspect.stack():
+                file = frame.filename
+                if (
+                    not (
+                        file.endswith("solara/toestand.py")
+                        or file.endswith("solara/reactive.py")
+                        or file.endswith("solara/hooks/use_reactive.py")
+                        or file.endswith("reacton/core.py")
+                        or file.endswith("components/markdown.py")
+                    )
+                    and frame.code_context is not None
+                ):
+                    if "=" not in frame.code_context[0]:
+                        continue
+                    elif any(op in frame.code_context[0].split("=")[1].lower() for op in ["reactive", "use_memo", "computed", "singleton"]):
+                        declaration = frame.code_context[0].split("=")[0].strip()
+                        if ":" in declaration:
+                            declaration = declaration.split(":")[0].strip()
+                        self._varname = declaration
+                        logger.info("found varname: " + declaration)
+                        break
+                # Markdown case is special, because the stacktrace ends at
+                # https://github.com/widgetti/solara/blob/604d2e54146308d64a209334d0314d2baba75108/solara/components/markdown.py#L368
+                elif file.endswith("components/markdown.py"):
+                    self._varname = "markdown_content"
+                    break
+            if not hasattr(self, "_varname"):
+                logger.info("No varname found")
+                self._varname = None
 
     @property
     def lock(self):
@@ -130,7 +164,10 @@ def cleanup():
         return cleanup
 
     def fire(self, new: T, old: T):
-        logger.info("value change from %s to %s, will fire events", old, new)
+        if settings.main.log_level in ["DEBUG", "INFO"] and self._varname is not None:
+            logger.info(f"value of {self._varname if self._varname is not None else ''} changed from %s to %s, will fire events", old, new)
+        else:
+            logger.info("value changed from %s to %s, will fire events", old, new)
         scope_id = self._get_scope_key()
         scopes = set()
         for listener, scope in self.listeners[scope_id].copy():