diff --git a/_appmap/configuration.py b/_appmap/configuration.py index ed1965e3..ab370436 100644 --- a/_appmap/configuration.py +++ b/_appmap/configuration.py @@ -508,5 +508,13 @@ def initialize(): logger.info("file: %s", c._file if c.file_present else "[no appmap.yml]") logger.info("config: %r", c) logger.debug("package_functions: %s", c.package_functions) - logger.info("env: %r", os.environ) + # Only log AppMap's own settings, never the full environment: arbitrary + # environment variables (API keys, credentials, tokens, etc.) must never + # end up in application logs. + appmap_env = { + k: v + for k, v in os.environ.items() + if k in ("APPMAP", "_APPMAP") or k.startswith(("APPMAP_", "_APPMAP_")) + } + logger.info("env: %r", appmap_env) os.environ["_APPMAP_MESSAGES_SHOWN"] = "true" diff --git a/_appmap/env.py b/_appmap/env.py index be23a61d..09844269 100644 --- a/_appmap/env.py +++ b/_appmap/env.py @@ -168,7 +168,10 @@ def _configure_logging(self): trace_logger.install() log_level = self.get("APPMAP_LOG_LEVEL", "warn").upper() - disable_log = os.environ.get("APPMAP_DISABLE_LOG_FILE", "false").upper() != "FALSE" + # No log file unless the user opts in: it can contain data (e.g. + # rendered parameter values) that shouldn't be written to disk or + # committed to source control by default. + disable_log = os.environ.get("APPMAP_DISABLE_LOG_FILE", "true").upper() != "FALSE" log_config = self.get("APPMAP_LOG_CONFIG") config_dict = { "version": 1, diff --git a/_appmap/test/test_runner.py b/_appmap/test/test_runner.py index 140df2e2..118c60e3 100644 --- a/_appmap/test/test_runner.py +++ b/_appmap/test/test_runner.py @@ -1,3 +1,4 @@ +import os import re import pytest @@ -37,6 +38,20 @@ def test_runner_multi_recording_type(script_runner, flag, expected): assert len(re.findall("(?m)^APPMAP_RECORD_PYTEST=true$", result.stdout)) == expected +@pytest.mark.parametrize( + "flags,expected", + [ + ([], "true"), + (["--no-enable-log"], "true"), + (["--enable-log"], "false"), + ], +) +def test_runner_log_file_disabled_by_default(script_runner, flags, expected): + result = script_runner.run(["appmap-python", *flags, "--record", "process"]) + assert result.returncode == 0 + assert re.search(f"(?m)^APPMAP_DISABLE_LOG_FILE={expected}$", result.stdout) is not None + + @pytest.mark.script_launch_mode("subprocess") class TestEnv: def test_appmap_present(self, script_runner): @@ -50,3 +65,19 @@ def test_recording_type_present(self, script_runner): ) assert result.returncode == 0 assert re.match(r"true", result.stdout) is not None + + def test_internal_state_not_leaked_to_child(self, script_runner): + # appmap-python is itself instrumented at interpreter startup (via + # appmap.pth), which can set internal, process-scoped _APPMAP* + # markers using whatever it inherited, before this script has + # computed the environment the child command should actually run + # with. Simulate that by pre-setting one such marker (the + # once-per-process "startup messages already shown" guard) and + # confirm it doesn't leak into the child's environment, which would + # otherwise silently suppress the child's own startup logging. + env = {**os.environ, "_APPMAP_MESSAGES_SHOWN": "true"} + result = script_runner.run( + ["appmap-python", "printenv", "_APPMAP_MESSAGES_SHOWN"], env=env + ) + assert result.returncode != 0 + assert result.stdout == "" diff --git a/appmap/command/runner.py b/appmap/command/runner.py index dd5a8e4b..a5c0bbe8 100644 --- a/appmap/command/runner.py +++ b/appmap/command/runner.py @@ -122,7 +122,7 @@ def run(): envvars[f"APPMAP_RECORD_{disabled.upper()}"] = "false" envvars["APPMAP_DISABLE_LOG_FILE"] = ( - "true" if parsed_args.get("no_enable_log", set()) else "false" + "false" if parsed_args.get("enable_log", False) else "true" ) if len(cmd) == 0: @@ -130,7 +130,17 @@ def run(): print(f"{k}={v}") sys.exit(0) - os.execvpe(cmd[0], cmd, {**os.environ, **envvars}) + # appmap-python is itself instrumented on interpreter startup (via + # appmap.pth), before this point, using whatever environment it inherited + # rather than the envvars computed above. That incidental self-init can + # set internal, process-scoped state under _APPMAP*-prefixed names (e.g. + # the once-per-process "startup messages already shown" guard); left in + # place, it would carry over into the child's environment and suppress + # or corrupt the child's own startup behavior. Drop all of it and let + # envvars below re-set whatever the child actually needs. + child_env = {k: v for k, v in os.environ.items() if not k.startswith("_APPMAP")} + child_env.update(envvars) + os.execvpe(cmd[0], cmd, child_env) if __name__ == "__main__": diff --git a/ci/tests/smoketest.sh b/ci/tests/smoketest.sh index cd0abade..f7f8dc7a 100755 --- a/ci/tests/smoketest.sh +++ b/ci/tests/smoketest.sh @@ -26,7 +26,9 @@ test_log_file_not_writable() import appmap EOF - python test_log_file_not_writable.py + # Log file creation is opt-in, so force it on to exercise the fallback + # when the log file can't be created (e.g. read-only mount). + APPMAP_DISABLE_LOG_FILE=false python test_log_file_not_writable.py if [[ $? -eq 0 ]]; then echo 'Script executed successfully'