fix: log to a file by default

Create a log file by default, messages at INFO and above to it. Provide
the env var APPMAP_DISABLE_LOG_FILE to instead log (at WARNING, by
default) to stderr.

_appmap/configuration.py

@@ -142,8 +142,6 @@ def __init__(self):
 
         self._load_config()
         self._load_functions()
-        logger.info("config: %s", self._config)
-        logger.debug("package_functions: %s", self.package_functions)
 
         if "labels" in self._config:
             self.labels.append(self._config["labels"])
@@ -415,3 +413,8 @@ def initialize():
 
 
 initialize()
+
+c = Config()
+logger.info("config: %s", c._config)
+logger.debug("package_functions: %s", c.package_functions)
+logger.info("env: %r", os.environ)

_appmap/env.py

@@ -4,6 +4,7 @@
 import logging.config
 import os
 from contextlib import contextmanager
+from datetime import datetime
 from os import environ
 from pathlib import Path
 from typing import cast
@@ -124,11 +125,10 @@ def getLogger(self, name) -> trace_logger.TraceLogger:
     def _configure_logging(self):
         trace_logger.install()
 
-        log_level = self.get("APPMAP_LOG_LEVEL", "warning").upper()
-
+        log_level = self.get("APPMAP_LOG_LEVEL", "warn").upper()
+        disable_log = os.environ.get("APPMAP_DISABLE_LOG_FILE", "false").upper() != "FALSE"
         log_config = self.get("APPMAP_LOG_CONFIG")
-        log_stream = self.get("APPMAP_LOG_STREAM", "stderr")
-        log_stream = "ext://sys.%s" % (log_stream)
+        now = datetime.now()
         config_dict = {
             "version": 1,
             "disable_existing_loggers": False,
@@ -138,9 +138,7 @@ def _configure_logging(self):
                     "format": "[{asctime}] {levelname} {name}: {message}",
                 }
             },
-            "handlers": {
-                "default": {"class": "logging.StreamHandler", "formatter": "default"}
-            },
+            "handlers": {"default": {"class": "logging.StreamHandler", "formatter": "default"}},
             "loggers": {
                 "appmap": {
                     "level": log_level,
@@ -154,6 +152,20 @@ def _configure_logging(self):
                 },
             },
         }
+        if not disable_log:
+            # Default to being more verbose if we're logging to a file, but
+            # still allow the level to be overridden.
+            log_level = self.get("APPMAP_LOG_LEVEL", "info").upper()
+            loggers = config_dict["loggers"]
+            loggers["appmap"]["level"] = loggers["_appmap"]["level"] = log_level
+            config_dict["handlers"] = {
+                "default": {
+                    "class": "logging.FileHandler",
+                    "formatter": "default",
+                    "filename": f"appmap-{now:%Y%m%d%H%M%S}-{os.getpid()}.log",
+                }
+            }
+
         if log_config is not None:
             name, level = log_config.split("=", 2)
             config_dict["loggers"].update(

pyproject.toml

@@ -78,6 +78,7 @@ urllib3 = "^1"
 uvicorn = "^0.27.1"
 fastapi = "^0.110.0"
 httpx = "^0.27.0"
+pytest-env = "^1.1.3"
 
 [build-system]
 requires = ["poetry-core>=1.1.0"]

pytest.ini

@@ -17,3 +17,6 @@ addopts = --runpytest subprocess --ignore vendor
 # We're stuck at pytest ~6.1.2. This warning got removed in a later
 # version.
 filterwarnings = ignore:testdir.copy_example is an experimental api that may change over time
+
+env =
+    APPMAP_DISABLE_LOG_FILE = true