|
| 1 | +"""Tests for the new MMCore 12.3.0 logging APIs.""" |
| 2 | + |
| 3 | +from __future__ import annotations |
| 4 | + |
| 5 | +import time |
| 6 | +from typing import TYPE_CHECKING, Callable |
| 7 | + |
| 8 | +import pymmcore_nano as pmn |
| 9 | +import pytest |
| 10 | + |
| 11 | +if TYPE_CHECKING: |
| 12 | + from pathlib import Path |
| 13 | + |
| 14 | + |
| 15 | +def _wait_until(predicate: Callable[[], bool], timeout: float = 2.0, interval=0.05): |
| 16 | + start = time.perf_counter() |
| 17 | + while time.perf_counter() - start < timeout: |
| 18 | + if predicate(): |
| 19 | + return True |
| 20 | + time.sleep(interval) |
| 21 | + raise TimeoutError("Timed out waiting for condition") |
| 22 | + |
| 23 | + |
| 24 | +def _wait_until_stderr( |
| 25 | + capfd: pytest.CaptureFixture, expected: str, timeout: float = 6.0, interval=0.05 |
| 26 | +): |
| 27 | + accumulated = "" |
| 28 | + start = time.perf_counter() |
| 29 | + while time.perf_counter() - start < timeout: |
| 30 | + accumulated += capfd.readouterr().err |
| 31 | + if expected in accumulated: |
| 32 | + return True |
| 33 | + time.sleep(interval) |
| 34 | + raise TimeoutError( |
| 35 | + f"Timed out waiting for {expected!r} in stderr. Got: {accumulated!r}" |
| 36 | + ) |
| 37 | + |
| 38 | + |
| 39 | +# ── LogLevel enum ───────────────────────────────────────────────────────────── |
| 40 | + |
| 41 | + |
| 42 | +def test_log_level_enum_values() -> None: |
| 43 | + assert int(pmn.LogLevel.LogLevelTrace) == 0 |
| 44 | + assert int(pmn.LogLevel.LogLevelDebug) == 1 |
| 45 | + assert int(pmn.LogLevel.LogLevelInfo) == 2 |
| 46 | + assert int(pmn.LogLevel.LogLevelWarning) == 3 |
| 47 | + assert int(pmn.LogLevel.LogLevelError) == 4 |
| 48 | + assert int(pmn.LogLevel.LogLevelCritical) == 5 |
| 49 | + |
| 50 | + |
| 51 | +def test_log_level_is_arithmetic() -> None: |
| 52 | + # nb::is_arithmetic() lets the enum participate in int comparisons |
| 53 | + assert pmn.LogLevel.LogLevelInfo < pmn.LogLevel.LogLevelWarning |
| 54 | + assert pmn.LogLevel.LogLevelCritical > pmn.LogLevel.LogLevelTrace |
| 55 | + |
| 56 | + |
| 57 | +@pytest.mark.skipif( |
| 58 | + not pmn._pymmcore_nano._MATCH_SWIG, reason="SWIG compat not enabled" |
| 59 | +) |
| 60 | +def test_log_level_swig_compat() -> None: |
| 61 | + """Module-level int attrs exist for SWIG compatibility.""" |
| 62 | + assert pmn.LogLevelTrace == 0 |
| 63 | + assert pmn.LogLevelDebug == 1 |
| 64 | + assert pmn.LogLevelInfo == 2 |
| 65 | + assert pmn.LogLevelWarning == 3 |
| 66 | + assert pmn.LogLevelError == 4 |
| 67 | + assert pmn.LogLevelCritical == 5 |
| 68 | + |
| 69 | + |
| 70 | +# ── setPrimaryLogLevel / getPrimaryLogLevel ─────────────────────────────────── |
| 71 | + |
| 72 | + |
| 73 | +def test_set_get_primary_log_level(core: pmn.CMMCore) -> None: |
| 74 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelWarning) |
| 75 | + assert core.getPrimaryLogLevel() == pmn.LogLevel.LogLevelWarning |
| 76 | + |
| 77 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelTrace) |
| 78 | + assert core.getPrimaryLogLevel() == pmn.LogLevel.LogLevelTrace |
| 79 | + |
| 80 | + |
| 81 | +def test_set_primary_log_level_accepts_all_values(core: pmn.CMMCore) -> None: |
| 82 | + for level in pmn.LogLevel: |
| 83 | + core.setPrimaryLogLevel(level) |
| 84 | + assert core.getPrimaryLogLevel() == level |
| 85 | + |
| 86 | + |
| 87 | +# ── log() ───────────────────────────────────────────────────────────────────── |
| 88 | + |
| 89 | + |
| 90 | +def test_log_to_file(core: pmn.CMMCore, tmp_path: Path) -> None: |
| 91 | + logfile = tmp_path / "test.log" |
| 92 | + core.setPrimaryLogFile(logfile) |
| 93 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelTrace) |
| 94 | + |
| 95 | + core.log("hello from test", pmn.LogLevel.LogLevelInfo) |
| 96 | + _wait_until(lambda: "hello from test" in logfile.read_text()) |
| 97 | + |
| 98 | + text = logfile.read_text() |
| 99 | + assert "[IFO,App] hello from test" in text |
| 100 | + |
| 101 | + |
| 102 | +def test_log_with_logger_name(core: pmn.CMMCore, tmp_path: Path) -> None: |
| 103 | + logfile = tmp_path / "test.log" |
| 104 | + core.setPrimaryLogFile(logfile) |
| 105 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelTrace) |
| 106 | + |
| 107 | + core.log("named log msg", pmn.LogLevel.LogLevelWarning, "my-component") |
| 108 | + _wait_until(lambda: "named log msg" in logfile.read_text()) |
| 109 | + |
| 110 | + text = logfile.read_text() |
| 111 | + assert "[WRN,my-component] named log msg" in text |
| 112 | + |
| 113 | + |
| 114 | +def test_log_all_levels_to_file(core: pmn.CMMCore, tmp_path: Path) -> None: |
| 115 | + logfile = tmp_path / "test.log" |
| 116 | + core.setPrimaryLogFile(logfile) |
| 117 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelTrace) |
| 118 | + |
| 119 | + level_tags = { |
| 120 | + pmn.LogLevel.LogLevelTrace: "[trc,", |
| 121 | + pmn.LogLevel.LogLevelDebug: "[dbg,", |
| 122 | + pmn.LogLevel.LogLevelInfo: "[IFO,", |
| 123 | + pmn.LogLevel.LogLevelWarning: "[WRN,", |
| 124 | + pmn.LogLevel.LogLevelError: "[ERR,", |
| 125 | + pmn.LogLevel.LogLevelCritical: "[CRT,", |
| 126 | + } |
| 127 | + for level, tag in level_tags.items(): |
| 128 | + core.log(f"msg-{level.name}", level) |
| 129 | + |
| 130 | + # wait for the last message to appear |
| 131 | + _wait_until(lambda: "msg-LogLevelCritical" in logfile.read_text()) |
| 132 | + |
| 133 | + text = logfile.read_text() |
| 134 | + for level, tag in level_tags.items(): |
| 135 | + assert f"{tag}App] msg-{level.name}" in text |
| 136 | + |
| 137 | + |
| 138 | +def test_log_filtered_by_level(core: pmn.CMMCore, tmp_path: Path) -> None: |
| 139 | + logfile = tmp_path / "test.log" |
| 140 | + core.setPrimaryLogFile(logfile) |
| 141 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelWarning) |
| 142 | + |
| 143 | + core.log("should-appear", pmn.LogLevel.LogLevelError) |
| 144 | + _wait_until(lambda: "should-appear" in logfile.read_text()) |
| 145 | + |
| 146 | + core.log("should-not-appear", pmn.LogLevel.LogLevelDebug) |
| 147 | + # give async logging a moment to flush, then verify it's absent |
| 148 | + time.sleep(0.2) |
| 149 | + text = logfile.read_text() |
| 150 | + assert "should-appear" in text |
| 151 | + assert "should-not-appear" not in text |
| 152 | + |
| 153 | + |
| 154 | +def test_log_to_stderr( |
| 155 | + core: pmn.CMMCore, capfd: pytest.CaptureFixture, tmp_path: Path |
| 156 | +) -> None: |
| 157 | + core.enableStderrLog(True) |
| 158 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelTrace) |
| 159 | + core.log("stderr-test-msg", pmn.LogLevel.LogLevelWarning, "test-logger") |
| 160 | + _wait_until_stderr(capfd, "[WRN,test-logger] stderr-test-msg") |
| 161 | + core.enableStderrLog(False) |
| 162 | + |
| 163 | + |
| 164 | +# ── setPrimaryLogFileRotation ───────────────────────────────────────────────── |
| 165 | + |
| 166 | + |
| 167 | +def test_set_primary_log_file_rotation(core: pmn.CMMCore, tmp_path: Path) -> None: |
| 168 | + logfile = tmp_path / "test.log" |
| 169 | + core.setPrimaryLogFile(logfile) |
| 170 | + # should not raise |
| 171 | + core.setPrimaryLogFileRotation(1024 * 1024, 3) |
| 172 | + |
| 173 | + |
| 174 | +def test_rotation_creates_backup_files(core: pmn.CMMCore, tmp_path: Path) -> None: |
| 175 | + logfile = tmp_path / "test.log" |
| 176 | + core.setPrimaryLogFile(logfile) |
| 177 | + core.setPrimaryLogLevel(pmn.LogLevel.LogLevelTrace) |
| 178 | + # very small max size to trigger rotation quickly |
| 179 | + core.setPrimaryLogFileRotation(512, 2) |
| 180 | + |
| 181 | + # write enough to trigger rotation |
| 182 | + for i in range(200): |
| 183 | + core.log(f"rotation-fill-{i:04d}-padding-to-make-line-longer", pmn.LogLevel.LogLevelInfo) |
| 184 | + |
| 185 | + def _all_log_text() -> str: |
| 186 | + return "".join(f.read_text() for f in tmp_path.iterdir()) |
| 187 | + |
| 188 | + _wait_until(lambda: "rotation-fill-0199" in _all_log_text()) |
| 189 | + |
| 190 | + # check that at least one rotated file was created |
| 191 | + rotated = [f for f in tmp_path.iterdir() if f.name.startswith("test") and f != logfile] |
| 192 | + assert len(rotated) > 0, f"Expected rotated log files in {tmp_path}" |
| 193 | + # should not exceed maxBackupCount |
| 194 | + assert len(rotated) <= 2 |
| 195 | + |
| 196 | + |
| 197 | +# ── setStderrLogLevel / getStderrLogLevel ───────────────────────────────────── |
| 198 | + |
| 199 | + |
| 200 | +def test_set_get_stderr_log_level(core: pmn.CMMCore) -> None: |
| 201 | + core.setStderrLogLevel(pmn.LogLevel.LogLevelWarning) |
| 202 | + assert core.getStderrLogLevel() == pmn.LogLevel.LogLevelWarning |
| 203 | + |
| 204 | + core.setStderrLogLevel(pmn.LogLevel.LogLevelTrace) |
| 205 | + assert core.getStderrLogLevel() == pmn.LogLevel.LogLevelTrace |
| 206 | + |
| 207 | + |
| 208 | +def test_set_stderr_log_level_accepts_all_values(core: pmn.CMMCore) -> None: |
| 209 | + for level in pmn.LogLevel: |
| 210 | + core.setStderrLogLevel(level) |
| 211 | + assert core.getStderrLogLevel() == level |
| 212 | + |
| 213 | + |
| 214 | +def test_stderr_log_level_filters_output( |
| 215 | + core: pmn.CMMCore, capfd: pytest.CaptureFixture |
| 216 | +) -> None: |
| 217 | + core.enableStderrLog(True) |
| 218 | + core.setStderrLogLevel(pmn.LogLevel.LogLevelWarning) |
| 219 | + |
| 220 | + core.log("stderr-should-appear", pmn.LogLevel.LogLevelError) |
| 221 | + _wait_until_stderr(capfd, "stderr-should-appear") |
| 222 | + |
| 223 | + core.log("stderr-should-not-appear", pmn.LogLevel.LogLevelDebug) |
| 224 | + time.sleep(0.2) |
| 225 | + captured = capfd.readouterr().err |
| 226 | + assert "stderr-should-not-appear" not in captured |
| 227 | + core.enableStderrLog(False) |
| 228 | + |
| 229 | + |
| 230 | +# ── interaction with legacy APIs ────────────────────────────────────────────── |
| 231 | + |
| 232 | + |
| 233 | +def test_enable_debug_log_sets_level(core: pmn.CMMCore) -> None: |
| 234 | + core.enableDebugLog(True) |
| 235 | + assert core.debugLogEnabled() |
| 236 | + # enableDebugLog(True) should set level to Trace |
| 237 | + assert core.getPrimaryLogLevel() == pmn.LogLevel.LogLevelTrace |
| 238 | + |
| 239 | + core.enableDebugLog(False) |
| 240 | + assert not core.debugLogEnabled() |
| 241 | + # enableDebugLog(False) should set level to Info |
| 242 | + assert core.getPrimaryLogLevel() == pmn.LogLevel.LogLevelInfo |
0 commit comments