Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 24 additions & 3 deletions lib/python/base_cli/logging.py
Original file line number Diff line number Diff line change
Expand Up @@ -237,8 +237,8 @@ def emit(self, record: logging.LogRecord) -> None:
_unlock_log_stream(self._lock_stream)
except RecursionError:
raise
except Exception:
self.handleError(record)
except Exception as exc:
_report_persistence_failure(exc)

def close(self) -> None:
self.acquire()
Expand All @@ -248,12 +248,33 @@ def close(self) -> None:
try:
if stream is not None:
stream.close()
except RecursionError:
raise
except Exception as exc:
_report_persistence_failure(exc)
finally:
super().close()
try:
super().close()
except RecursionError:
raise
except Exception as exc:
_report_persistence_failure(exc)
finally:
self.release()


def _report_persistence_failure(exc: Exception) -> None:
"""Report a logging persistence failure without routing through logging."""

detail = str(exc) or type(exc).__name__
try:
sys.stderr.write(f"base-cli: logging persistence failed: {detail}\n")
except Exception:
# Diagnostics must not turn a best-effort logging failure into a command
# failure when stderr is closed or otherwise unavailable.
pass


def _open_log_lock(path: Path) -> BinaryIO:
path.parent.mkdir(parents=True, exist_ok=True)
stream = path.open("a+b")
Expand Down
80 changes: 79 additions & 1 deletion tests/test_logging_hot_path.py
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
from __future__ import annotations

import io
import json
import logging
import os
from concurrent.futures import ThreadPoolExecutor
Expand Down Expand Up @@ -103,7 +104,84 @@ def main(ctx: base_cli.Context) -> None:

result = invoke(app, [], home=tmp_path)
assert result.exit_code == 0
assert "Logging error" in result.stderr
assert "logging persistence failed" in result.stderr


@pytest.mark.parametrize("failure_point", ("open", "lock", "unlock"))
def test_logging_sidecar_io_failures_do_not_fail_native_command(
tmp_path: Path,
failure_point: str,
) -> None:
app = base_cli.App(name=f"logging-sidecar-{failure_point}")
failure = {
"open": ("_open_log_lock", OSError("sidecar open failed")),
"lock": ("_lock_log_stream", OSError("sidecar lock failed")),
"unlock": ("_unlock_log_stream", OSError("sidecar unlock failed")),
}[failure_point]

@app.command()
def main(ctx: base_cli.Context) -> None:
if failure_point == "open":
for handler in ctx.log.handlers:
if isinstance(handler, module.SecureLogFileHandler):
stream = handler._lock_stream
handler._lock_stream = None
handler._lock_identity = None
if stream is not None:
stream.close()
with patch.object(module, failure[0], side_effect=failure[1]):
ctx.log.info("ordinary command progress")
print("handler reached end")

result = invoke(app, [], home=tmp_path)

assert result.exit_code == 0, result.output
assert "handler reached end" in result.stdout
assert "logging persistence failed" in result.stderr


def test_logging_sidecar_io_failure_does_not_fail_attached_json_command(tmp_path: Path) -> None:
import click

@click.command(name="attached-logging-sidecar")
def attached_command() -> None:
context = base_cli.get_current_context()
for handler in context.log.handlers:
if isinstance(handler, module.SecureLogFileHandler):
stream = handler._lock_stream
handler._lock_stream = None
handler._lock_identity = None
if stream is not None:
stream.close()
with patch.object(module, "_open_log_lock", side_effect=OSError("sidecar open failed")):
context.log.info("attached progress")
click.echo("attached handler reached end")

app = base_cli.App(
name="attached-logging-sidecar",
lifecycle_options=base_cli.LifecycleOptions(json=base_cli.LifecycleOption("--json")),
)
attached = app.attach(attached_command)

result = invoke(attached, ["--json"], home=tmp_path)
payload = json.loads(result.stdout)

assert result.exit_code == 0, result.output
assert payload["code"] == "ok"
assert "attached handler reached end" in payload["details"]["stdout"]
assert "logging persistence failed" in result.stderr


def test_logging_sidecar_preserves_process_control_exceptions(tmp_path: Path) -> None:
handler = module.SecureLogFileHandler(tmp_path / "run.log")
record = logging.LogRecord("test", logging.INFO, __file__, 1, "message", (), None)
try:
for exception in (KeyboardInterrupt(), SystemExit(7)):
with patch.object(module, "_open_log_lock", side_effect=exception):
with pytest.raises(type(exception)):
handler.emit(record)
finally:
handler.close()


def test_formatter_repeated_paths_do_not_resolve_again(tmp_path: Path) -> None:
Expand Down
Loading