From b53e07d2e98e154d1be297363ed0b7e8ea65946f Mon Sep 17 00:00:00 2001 From: Panadestein Date: Tue, 6 Oct 2026 14:56:09 +0200 Subject: [PATCH] =?UTF-8?q?fix:=20=F0=9F=90=9B=20stop=20configuring=20glob?= =?UTF-8?q?al=20logging;=20replace=20structlog=20with=20stdlib=20logging?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Importing src_method no longer calls logging.basicConfig() or structlog.configure(), so the root logger level and handlers of the host application are left untouched. The package now uses logging.getLogger(__name__) per module with a NullHandler on the top-level logger, emits progress messages at DEBUG with lazy %-style arguments, and drops the structlog runtime dependency and the LOG_LEVEL_SRC variable. Fixes #11 Assisted-by: pi:claude-opus-5.5 --- AGENTS.md | 4 +- README.md | 15 ++++ benches/primitives/leonardo/bench_mpo_mpo.py | 24 +++--- benches/primitives/leonardo/run.sh | 3 - benches/stack/README.md | 3 +- benches/stack/bench_depth.py | 7 +- docs/index.md | 15 ++++ pyproject.toml | 2 +- src/src_method/__init__.py | 5 ++ src/src_method/_sweep.py | 20 +++-- src/src_method/stack.py | 22 +++-- src/src_method/utils/__init__.py | 2 - src/src_method/utils/logging_config.py | 50 ----------- tests/test_logging.py | 88 ++++++++++++++++++++ uv.lock | 11 --- 15 files changed, 167 insertions(+), 104 deletions(-) delete mode 100644 src/src_method/utils/logging_config.py create mode 100644 tests/test_logging.py diff --git a/AGENTS.md b/AGENTS.md index 82bbcb7..3fd0018 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -23,7 +23,9 @@ tensor, so there is no wrapper type. - Backend-agnostic code: go through `src_method.utils._backend` instead of importing `numpy` or `cupy` directly in the algorithms, so CPU and GPU paths stay in sync. -- Log with `structlog` via `src_method.utils.logging_config`, never `print`. +- Log with the standard library: `logger = logging.getLogger(__name__)` per + module, lazy `%`-style arguments, never `print`. Never add handlers, levels + or `basicConfig` in the package; progress messages go at `DEBUG`. - **Run `uv run prek run --all-files` and the relevant tests before pushing, and fix every finding.** `lint.yml` runs the same hooks in CI, so a skipped lint is a red PR. diff --git a/README.md b/README.md index 5e866a3..a8862a5 100644 --- a/README.md +++ b/README.md @@ -87,6 +87,21 @@ The result then pairs with a ket by plain contraction, with no further conjugati At runtime, pass `device="gpu"` to use GPU acceleration. The library handles backend dispatch automatically. +### Logging + +`src_method` logs through the standard library `logging` module, under the +`src_method` logger, and stays silent by default: it adds only a `NullHandler` +and never touches the root logger or its handlers. Progress and timing messages +are emitted at `DEBUG`, the small-network fallback at `WARNING`. To see them, +configure logging in your application: + +```python +import logging + +logging.basicConfig(level=logging.INFO) +logging.getLogger("src_method").setLevel(logging.DEBUG) +``` + ## Installation ```bash diff --git a/benches/primitives/leonardo/bench_mpo_mpo.py b/benches/primitives/leonardo/bench_mpo_mpo.py index 2247cfe..9651171 100644 --- a/benches/primitives/leonardo/bench_mpo_mpo.py +++ b/benches/primitives/leonardo/bench_mpo_mpo.py @@ -2,17 +2,16 @@ from __future__ import annotations +import logging from time import perf_counter_ns import cyclopts import numpy as np import quimb.tensor as qtn -import structlog from src_method import apply -# Set up logger -logger = structlog.get_logger() +logger = logging.getLogger(__name__) # Initialize cyclopts app @@ -38,13 +37,13 @@ def main( array_type = np.complex128 logger.info( - "benchmark_start", - n_sites=n_sites, - chi_out=chi_out, - phys_dim=phys_dim, - dtype="complex128", - run=run, - compare=compare, + "benchmark_start: n_sites=%d, chi_out=%d, phys_dim=%d, dtype=complex128, " + "run=%s, compare=%s", + n_sites, + chi_out, + phys_dim, + run, + compare, ) # Generate a random MPO and a perturbed identity MPO @@ -92,4 +91,9 @@ def main( if __name__ == "__main__": + logging.basicConfig( + level=logging.INFO, format="%(asctime)s %(levelname)s %(name)s %(message)s" + ) + # Report the per-sweep timings of src_method too. + logging.getLogger("src_method").setLevel(logging.DEBUG) app() diff --git a/benches/primitives/leonardo/run.sh b/benches/primitives/leonardo/run.sh index baa4400..28962b1 100755 --- a/benches/primitives/leonardo/run.sh +++ b/benches/primitives/leonardo/run.sh @@ -10,9 +10,6 @@ #SBATCH --exclusive #SBATCH --output=logs/1000_%j.out -# Python application's loggin level -export LOG_LEVEL_SRC=DEBUG - # Automatic OpenMP binding export OMP_NUM_THREADS=$SLURM_CPUS_PER_TASK export OMP_PLACES=cores diff --git a/benches/stack/README.md b/benches/stack/README.md index 99e0034..62589c8 100644 --- a/benches/stack/README.md +++ b/benches/stack/README.md @@ -25,8 +25,7 @@ uv run python benches/stack/bench_depth.py accuracy --output accuracy.md uv run python benches/stack/bench_depth.py timing --output timing.md ``` -Tuple options repeat the flag, e.g. `--depths 2 --depths 3`. Set -`LOG_LEVEL_SRC=WARNING` to silence the per-call logs. +Tuple options repeat the flag, e.g. `--depths 2 --depths 3`. ## Results diff --git a/benches/stack/bench_depth.py b/benches/stack/bench_depth.py index 4c233a0..784ad18 100644 --- a/benches/stack/bench_depth.py +++ b/benches/stack/bench_depth.py @@ -11,6 +11,7 @@ from __future__ import annotations +import logging from dataclasses import astuple, dataclass, fields from functools import reduce from pathlib import Path @@ -18,12 +19,11 @@ import cyclopts import numpy as np -import structlog from scipy.linalg import expm from src_method import apply, src -logger = structlog.get_logger() +logger = logging.getLogger(__name__) app = cyclopts.App(help="Benchmark one-shot SRC over stacks against pairwise apply.") X = np.array([[0, 1], [1, 0]], dtype=complex) @@ -188,7 +188,7 @@ class TimingRow: def write_table(rows: list, output: Path | None) -> None: """Log every row and, if requested, write them as a Markdown table.""" for row in rows: - logger.info("result", **vars(row)) + logger.info("result: %s", vars(row)) if output is None: return names = [f.name for f in fields(rows[0])] @@ -323,4 +323,5 @@ def timing( if __name__ == "__main__": + logging.basicConfig(level=logging.INFO, format="%(message)s") app() diff --git a/docs/index.md b/docs/index.md index 326e5f2..913f643 100644 --- a/docs/index.md +++ b/docs/index.md @@ -135,3 +135,18 @@ container. [Visual Studio Code]: https://code.visualstudio.com/ [GitHub CLI]: https://cli.github.com/ [at this link]: https://docs.algorithmiq.fi/src_method + +### Logging + +`src_method` logs through the standard library `logging` module, under the +`src_method` logger, and stays silent by default: it adds only a `NullHandler` +and never touches the root logger or its handlers. Progress and timing messages +are emitted at `DEBUG`, the small-network fallback at `WARNING`. To see them, +configure logging in your application: + +```python +import logging + +logging.basicConfig(level=logging.INFO) +logging.getLogger("src_method").setLevel(logging.DEBUG) +``` diff --git a/pyproject.toml b/pyproject.toml index 5aa71a7..317aae2 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -32,7 +32,7 @@ classifiers = [ "Typing :: Typed", ] dynamic = ["version"] -dependencies = ["numpy>=2.4.4,<3", "opt_einsum>=3.4.0", "structlog>=25.5.0"] +dependencies = ["numpy>=2.4.4,<3", "opt_einsum>=3.4.0"] [project.optional-dependencies] diff --git a/src/src_method/__init__.py b/src/src_method/__init__.py index d531ec2..aeb6679 100644 --- a/src/src_method/__init__.py +++ b/src/src_method/__init__.py @@ -5,10 +5,15 @@ from __future__ import annotations +import logging + from ._version import version as __version__ from ._version import version_tuple as __version_tuple__ from .apply import apply from .compress import compress from .stack import src +# Stay silent unless the application configures logging. +logging.getLogger(__name__).addHandler(logging.NullHandler()) + __all__ = ["__version__", "__version_tuple__", "apply", "compress", "src"] diff --git a/src/src_method/_sweep.py b/src/src_method/_sweep.py index af8a89f..3529b5d 100644 --- a/src/src_method/_sweep.py +++ b/src/src_method/_sweep.py @@ -13,13 +13,13 @@ from __future__ import annotations +import logging from functools import cache from itertools import count from math import prod from time import perf_counter_ns from typing import TYPE_CHECKING, NamedTuple -import structlog from opt_einsum import contract_expression, get_symbol from ._tensor_train import pad, unpad @@ -35,7 +35,7 @@ from ._tensor_train import TrainKind -logger = structlog.get_logger(__name__) +logger = logging.getLogger(__name__) class _Contractions: @@ -125,11 +125,13 @@ def sweep( contract = _Contractions() # sites[j] holds the padded tensors of every layer at site j. sites = list(zip(*(pad([xp.asarray(a) for a in layer]) for layer in layers))) - logger.debug( - "Largest environment (elements)", - size=chi_out - * max(prod(t.shape[1] for t in sites[j]) for j in range(n_sites - 1)), - ) + # Guarded: the max walks every site, wasted work unless it is logged. + if logger.isEnabledFor(logging.DEBUG): + logger.debug( + "Largest environment: %d elements", + chi_out + * max(prod(t.shape[1] for t in sites[j]) for j in range(n_sites - 1)), + ) tms = perf_counter_ns() # C[j] is the sketched environment of sites 0 .. j-1. @@ -138,7 +140,7 @@ def sweep( up, down = sites[j][0].shape[2], sites[j][-1].shape[3] omega = gaussian_sketch(prng, (chi_out, up, down), dtype, xp) C.append(contract(eqs.ltr, C[j], omega, *sites[j])) - logger.debug("Left-to-right sweep", seconds=(perf_counter_ns() - tms) * 1e-9) + logger.debug("Left-to-right sweep: %.3f s", (perf_counter_ns() - tms) * 1e-9) tms = perf_counter_ns() eta_reversed: list[NDArray] = [] @@ -153,6 +155,6 @@ def sweep( eta_reversed.append(eta_j) first = contract(eqs.first, *sites[0], S) eta = [first.reshape(1, *first.shape[depth:]), *reversed(eta_reversed)] - logger.debug("Right-to-left sweep", seconds=(perf_counter_ns() - tms) * 1e-9) + logger.debug("Right-to-left sweep: %.3f s", (perf_counter_ns() - tms) * 1e-9) return [to_numpy(site) for site in unpad(eta, kind)] diff --git a/src/src_method/stack.py b/src/src_method/stack.py index adb661b..a7f7ace 100644 --- a/src/src_method/stack.py +++ b/src/src_method/stack.py @@ -7,10 +7,9 @@ from __future__ import annotations +import logging from typing import TYPE_CHECKING -import structlog - from ._sweep import sweep from ._tensor_train import ( MIN_SRC_SITES, @@ -19,15 +18,14 @@ normalize_stack, ) from ._validation import validate_chi_out, validate_cutoff -from .utils import default_rng, get_xp, setup_logging, sketch_dtype +from .utils import default_rng, get_xp, sketch_dtype if TYPE_CHECKING: from collections.abc import Sequence from numpy.typing import DTypeLike, NDArray -setup_logging() -logger = structlog.get_logger(__name__) +logger = logging.getLogger(__name__) LOG_WARN_SMALL = ( "The current SRC implementation targets tensor networks with 3 or more sites. " @@ -109,12 +107,12 @@ def src( logger.warning(LOG_WARN_SMALL) return exact_stack(layers, chi_out, kind) - logger.info( - "Starting SRC", - n_sites=n_sites, - depth=len(layers), - output=kind, - device=xp.__name__, + logger.debug( + "Starting SRC: n_sites=%d, depth=%d, output=%s, device=%s", + n_sites, + len(layers), + kind, + xp.__name__, ) result = sweep( layers, @@ -125,5 +123,5 @@ def src( cutoff=cutoff, dtype=sketch_dtype(dtype, *layers), ) - logger.info("SRC complete.") + logger.debug("SRC complete") return result diff --git a/src/src_method/utils/__init__.py b/src/src_method/utils/__init__.py index e695123..b78556d 100644 --- a/src/src_method/utils/__init__.py +++ b/src/src_method/utils/__init__.py @@ -4,13 +4,11 @@ from ._backend import default_rng, gaussian_sketch, get_xp, sketch_dtype, to_numpy from .linalg import truncated_qr -from .logging_config import setup_logging __all__ = [ "default_rng", "gaussian_sketch", "get_xp", - "setup_logging", "sketch_dtype", "to_numpy", "truncated_qr", diff --git a/src/src_method/utils/logging_config.py b/src/src_method/utils/logging_config.py deleted file mode 100644 index 9cab1cf..0000000 --- a/src/src_method/utils/logging_config.py +++ /dev/null @@ -1,50 +0,0 @@ -"""Structured logging configuration.""" - -from __future__ import annotations - -import logging -import os -import sys - -import structlog - - -def setup_logging(default_level: str = "INFO") -> None: - """Configure logging for the entire application. - - Args: - default_level: Default logging level. - - The logging level can be overridden by setting the `LOG_LEVEL_SRC` - environment. For example: - - ```bash - LOG_LEVEL_SRC=DEBUG python -m - pytest -o log_cli_level=DEBUG tests/ - ``` - """ - # Configure Python's standard logging - level_name = os.environ.get("LOG_LEVEL_SRC", default_level) - logging.basicConfig( - level=level_name.upper(), - format="%(message)s", - stream=sys.stdout, - ) - - # Remove colors for slurm logs but not for pytest - use_colors = "SLURM_JOB_ID" not in os.environ - - # Configure structlog to use the standard logger - structlog.configure( - processors=[ - structlog.contextvars.merge_contextvars, - structlog.processors.add_log_level, - structlog.processors.StackInfoRenderer(), - structlog.dev.set_exc_info, - structlog.processors.TimeStamper(fmt="%Y-%m-%d %H:%M:%S", utc=False), - structlog.dev.ConsoleRenderer(colors=use_colors), - ], - logger_factory=structlog.stdlib.LoggerFactory(), - wrapper_class=structlog.stdlib.BoundLogger, - cache_logger_on_first_use=True, - ) diff --git a/tests/test_logging.py b/tests/test_logging.py new file mode 100644 index 0000000..2cf7f9e --- /dev/null +++ b/tests/test_logging.py @@ -0,0 +1,88 @@ +"""The package must leave the host application's logging configuration alone.""" + +from __future__ import annotations + +import logging +import subprocess +import sys +import textwrap + +import numpy as np +import pytest + +from src_method import apply, compress + + +def _run(code: str) -> subprocess.CompletedProcess[str]: + """Run ``code`` in a fresh interpreter, so ``src_method`` is imported anew.""" + return subprocess.run( # noqa: S603 + [sys.executable, "-c", textwrap.dedent(code)], + capture_output=True, + text=True, + check=True, + ) + + +def test_import_leaves_root_logger_untouched() -> None: + """Importing the package must not change the root logger level or handlers.""" + result = _run( + """ + import logging + + root = logging.getLogger() + root.setLevel(logging.CRITICAL) + before = (root.level, list(root.handlers)) + + import src_method + + assert (root.level, list(root.handlers)) == before, root.handlers + package = logging.getLogger("src_method") + assert all(isinstance(h, logging.NullHandler) for h in package.handlers) + """ + ) + assert result.stdout == "" + assert result.stderr == "" + + +def test_calls_are_silent_by_default() -> None: + """Without logging configured, neither the SRC path nor the fallback prints.""" + result = _run( + """ + import numpy as np + from src_method import apply, compress + + rng = np.random.default_rng(0) + mpo = [rng.normal(size=(2, 2, 2))] + mpo += [rng.normal(size=(2, 2, 2, 2)) for _ in range(2)] + mpo += [rng.normal(size=(2, 2, 2))] + mps = [rng.normal(size=(2, 2)), rng.normal(size=(2, 2, 2))] + mps += [rng.normal(size=(2, 2, 2)), rng.normal(size=(2, 2))] + + apply(mpo, mps, chi_out=2, seed=0) + compress(mpo, chi_out=2, seed=0) + # The two-site fallback logs a warning, which must stay silent too. + compress([mps[0], mps[0].T], chi_out=2) + """ + ) + assert result.stdout == "" + assert result.stderr == "" + + +@pytest.mark.parametrize("call", ["apply", "compress"]) +def test_debug_records_reach_enabled_logger(call: str, caplog) -> None: + """Progress messages are emitted at DEBUG on the ``src_method`` loggers.""" + rng = np.random.default_rng(0) + mpo = [rng.normal(size=(2, 2, 2))] + mpo += [rng.normal(size=(2, 2, 2, 2)) for _ in range(2)] + mpo += [rng.normal(size=(2, 2, 2))] + caplog.set_level(logging.DEBUG, logger="src_method") + + if call == "apply": + apply(mpo, mpo, chi_out=2, seed=0) + else: + compress(mpo, chi_out=2, seed=0) + + records = [r for r in caplog.records if r.name.startswith("src_method")] + assert records + assert all(r.levelno == logging.DEBUG for r in records) + assert "SRC complete" in caplog.text diff --git a/uv.lock b/uv.lock index 1ace86e..e35a1dd 100644 --- a/uv.lock +++ b/uv.lock @@ -2893,7 +2893,6 @@ source = { editable = "." } dependencies = [ { name = "numpy" }, { name = "opt-einsum" }, - { name = "structlog" }, ] [package.optional-dependencies] @@ -2967,7 +2966,6 @@ requires-dist = [ { name = "nvidia-cusparse-cu12", marker = "extra == 'gpu-nvidia'" }, { name = "nvidia-nvjitlink-cu12", marker = "extra == 'gpu-nvidia'" }, { name = "opt-einsum", specifier = ">=3.4.0" }, - { name = "structlog", specifier = ">=25.5.0" }, ] provides-extras = ["gpu-nvidia", "gpu-rocm"] @@ -3028,15 +3026,6 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/f1/7b/ce1eafaf1a76852e2ec9b22edecf1daa58175c090266e9f6c64afcd81d91/stack_data-0.6.3-py3-none-any.whl", hash = "sha256:d5558e0c25a4cb0853cddad3d77da9891a08cb85dd9f9f91b9f8cd66e511e695", size = 24521, upload-time = "2023-09-30T13:58:03.53Z" }, ] -[[package]] -name = "structlog" -version = "25.5.0" -source = { registry = "https://pypi.org/simple" } -sdist = { url = "https://files.pythonhosted.org/packages/ef/52/9ba0f43b686e7f3ddfeaa78ac3af750292662284b3661e91ad5494f21dbc/structlog-25.5.0.tar.gz", hash = "sha256:098522a3bebed9153d4570c6d0288abf80a031dfdb2048d59a49e9dc2190fc98", size = 1460830, upload-time = "2025-10-27T08:28:23.028Z" } -wheels = [ - { url = "https://files.pythonhosted.org/packages/a8/45/a132b9074aa18e799b891b91ad72133c98d8042c70f6240e4c5f9dabee2f/structlog-25.5.0-py3-none-any.whl", hash = "sha256:a8453e9b9e636ec59bd9e79bbd4a72f025981b3ba0f5837aebf48f02f37a7f9f", size = 72510, upload-time = "2025-10-27T08:28:21.535Z" }, -] - [[package]] name = "tinycss2" version = "1.4.0"