From 545ba3dba4a9d52591ac8d9a9c5d344acc3136c5 Mon Sep 17 00:00:00 2001 From: "Haoran Sun (Business Central)" Date: Fri, 2 Oct 2026 14:08:29 +0200 Subject: [PATCH] Show bcbench-core logs and pass logging inputs explicitly The app raised only the `bcbench` logger above the root's WARNING level, so INFO logs from bcbench_core modules would be dropped once code that logs at INFO moves into core. - setup_logger raises both `bcbench` and `bcbench_core` to INFO (DEBUG with debug); third-party loggers stay at WARNING - setup_logger takes debug and github_actions instead of reading config; the CLI callback derives them from --verbose and the environment Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: 3fa47b3c-f5d6-4c36-9be3-c4fdf2bebe47 --- .github/copilot-instructions.md | 2 ++ packages/bcbench-core/README.md | 4 +++ src/bcbench/cli.py | 3 +- src/bcbench/logger.py | 28 +++++++--------- tests/test_logger.py | 58 +++++++++++++++++++++++++++++++-- 5 files changed, 76 insertions(+), 19 deletions(-) diff --git a/.github/copilot-instructions.md b/.github/copilot-instructions.md index 54e207756..d131177bf 100644 --- a/.github/copilot-instructions.md +++ b/.github/copilot-instructions.md @@ -36,6 +36,8 @@ Preserve one-way dependency flow from orchestration toward lower-level abstracti `bcbench.types` is the central category registry. Extend `EvaluationCategory` for category-owned mappings such as datasets, pipelines, results, and scoring behavior instead of duplicating those decisions elsewhere. Keep imports following the existing direction and avoid circular dependencies. +Only the CLI entry point configures logging (`bcbench.logger.setup_logger`); library and runtime code never add handlers or set levels. + ### Readable code over documentation or comments Function names should be self-explanatory. Do NOT add docstrings to functions unless absolutely necessary. When a docstring is necessary, keep it short and use Google style. Include only useful sections such as `Args:` and `Returns:`; skip details that are obvious from names and type hints. diff --git a/packages/bcbench-core/README.md b/packages/bcbench-core/README.md index 75fd84817..921a9d506 100644 --- a/packages/bcbench-core/README.md +++ b/packages/bcbench-core/README.md @@ -15,6 +15,10 @@ Reusable, strongly typed building blocks for evaluating coding agents on Busines The import and environment rules are enforced by ruff (`banned-api` in [`pyproject.toml`](pyproject.toml)); imports of undeclared dependencies are rejected by ty's `missing-direct-dependency` rule. +## Logging + +Modules log through `logging.getLogger(__name__)`, so every record is under the `bcbench_core` logger namespace. The library never adds handlers or sets levels; applications configure logging and choose what to show. + ## Development The package is a [uv workspace](https://docs.astral.sh/uv/concepts/projects/workspaces/) member of the BC-Bench repository. From the repository root: diff --git a/src/bcbench/cli.py b/src/bcbench/cli.py index c7804b150..b006ec636 100644 --- a/src/bcbench/cli.py +++ b/src/bcbench/cli.py @@ -75,7 +75,8 @@ def logging_callback( verbose: Annotated[bool, typer.Option("--verbose", "-v", help="Enable debug logging")] = False, ) -> None: """Setup logging for all commands.""" - setup_logger(verbose) + env = get_config().env + setup_logger(debug=verbose or env.runner_debug, github_actions=env.github_actions) if __name__ == "__main__": diff --git a/src/bcbench/logger.py b/src/bcbench/logger.py index db6e4dfd1..0e4f04dac 100644 --- a/src/bcbench/logger.py +++ b/src/bcbench/logger.py @@ -5,8 +5,6 @@ import sys from typing import ClassVar -from bcbench.config import get_config - __all__ = ["get_logger", "setup_logger"] @@ -155,28 +153,26 @@ def filter(self, record: logging.LogRecord) -> bool: return not getattr(record, "gh_actions_handled", False) +# Loggers owned by BC-Bench; everything else (third-party libraries) stays at WARNING +_APPLICATION_LOGGERS = ("bcbench", "bcbench_core") + _logging_configured = False -def setup_logger(verbose: bool = False) -> None: +def setup_logger(*, debug: bool, github_actions: bool) -> None: """ - Configure logging for the entire bcbench package. + Configure logging for bcbench and bcbench-core. Args: - verbose: If True, set bcbench loggers to DEBUG level, otherwise INFO. + debug: If True, set bcbench and bcbench-core loggers to DEBUG level, otherwise INFO. + github_actions: If True, also emit warnings and errors as GitHub Actions annotations. """ global _logging_configured # noqa: PLW0603 if _logging_configured: return - config = get_config() - - bcbench_level = logging.DEBUG if verbose else logging.INFO - - # Check for GitHub Actions debug mode - if config.env.runner_debug: - bcbench_level = logging.DEBUG + bcbench_level = logging.DEBUG if debug else logging.INFO # Configure root logger (for 3rd party libraries) to WARNING root_logger = logging.getLogger() @@ -188,7 +184,7 @@ def setup_logger(verbose: bool = False) -> None: # Add GitHub Actions handler FIRST if running in GitHub Actions # This ensures records are marked before the console handler sees them - if config.env.github_actions: + if github_actions: github_handler = GitHubActionsHandler() github_handler.setLevel(logging.WARNING) # Only warnings and errors github_handler.setFormatter(logging.Formatter("%(message)s")) @@ -202,9 +198,9 @@ def setup_logger(verbose: bool = False) -> None: console_handler.addFilter(GitHubActionsSkipFilter()) root_logger.addHandler(console_handler) - # Configure bcbench loggers to use the desired level - bcbench_logger = logging.getLogger("bcbench") - bcbench_logger.setLevel(bcbench_level) + # Configure bcbench and bcbench-core loggers to use the desired level + for name in _APPLICATION_LOGGERS: + logging.getLogger(name).setLevel(bcbench_level) _logging_configured = True diff --git a/tests/test_logger.py b/tests/test_logger.py index f6fd2407a..0e0e1b4d1 100644 --- a/tests/test_logger.py +++ b/tests/test_logger.py @@ -1,10 +1,12 @@ -"""Tests for logger module, focusing on sensitive data filtering.""" +"""Tests for logging setup, sensitive data filtering, and GitHub Actions annotations.""" import logging +from collections.abc import Iterator import pytest -from bcbench.logger import GitHubActionsHandler, GitHubActionsSkipFilter, SensitiveDataFilter +from bcbench import logger as bcbench_logger +from bcbench.logger import ColoredFormatter, GitHubActionsHandler, GitHubActionsSkipFilter, SensitiveDataFilter, setup_logger class TestSensitiveDataFilter: @@ -123,3 +125,55 @@ def test_allows_unhandled_records(self, filter_instance, log_record): def test_skips_handled_records(self, filter_instance, log_record): log_record.gh_actions_handled = True assert filter_instance.filter(log_record) is False + + +class TestSetupLogger: + @pytest.fixture(autouse=True) + def isolated_logging(self, monkeypatch: pytest.MonkeyPatch) -> Iterator[None]: + root = logging.getLogger() + root_level = root.level + application_levels = {name: logging.getLogger(name).level for name in ("bcbench", "bcbench_core")} + monkeypatch.setattr(bcbench_logger, "_logging_configured", False) + + yield + + # Remove only the handlers setup_logger installed; pytest manages its own capture handlers + for handler in root.handlers[:]: + if isinstance(handler, GitHubActionsHandler) or isinstance(handler.formatter, ColoredFormatter): + root.removeHandler(handler) + root.setLevel(root_level) + for name, level in application_levels.items(): + logging.getLogger(name).setLevel(level) + + def test_application_loggers_log_info_while_third_party_stays_at_warning(self, capsys): + setup_logger(debug=False, github_actions=False) + + logging.getLogger("bcbench.evaluate").info("app info") + logging.getLogger("bcbench_core.projects").info("core info") + logging.getLogger("urllib3").info("library info") + logging.getLogger("bcbench_core.projects").debug("core debug") + + err = capsys.readouterr().err + assert "app info" in err + assert "core info" in err + assert "library info" not in err + assert "core debug" not in err + + def test_debug_enables_debug_for_application_loggers(self, capsys): + setup_logger(debug=True, github_actions=False) + + logging.getLogger("bcbench.evaluate").debug("app debug") + logging.getLogger("bcbench_core.projects").debug("core debug") + + err = capsys.readouterr().err + assert "app debug" in err + assert "core debug" in err + + def test_github_actions_annotates_errors_without_duplicating_console_output(self, capsys): + setup_logger(debug=False, github_actions=True) + + logging.getLogger("bcbench_core.projects").error("categorization failed") + + captured = capsys.readouterr() + assert "::error title=bcbench_core.projects::categorization failed" in captured.out + assert "categorization failed" not in captured.err