Address review: real ERROR back-compat, summary contract, dead code

Three review fixes on top of the post-only rejection tracker:

1. **Default ERROR level now byte-identical to the legacy line**
   (review item 1, should-fix). Previously the tracker emitted the
   richer ``[reject:post_only_match] coin — …`` line at every level
   including the default ERROR, so log scrapers / templated alerts
   keying off the historical ``Order rejected: …`` prefix would no
   longer match. ``OrderRejectionTracker.record`` now branches: at
   ``ERROR`` (default) it emits the legacy line verbatim, only
   downgraded levels get the categorised format. Counter aggregation
   is unchanged so ``[reject-summary]`` still works at any level.

2. **``log_summary_if_due`` return value matches its docstring**
   (review item 3, nit). The docstring promised "True iff a summary
   was emitted" but the function returned True whenever the interval
   elapsed, even on idle intervals with nothing to log. ``_emit_summary``
   now returns a bool indicating whether anything was actually logged
   and ``log_summary_if_due`` propagates it. The strategy main loop
   discards the value, but tests / external observers can rely on it.

3. **Drop dead ``return None if any_emitted else None``** (review item
   2, nit). The conditional collapsed to ``None`` either way; replaced
   with the meaningful ``return any_emitted`` from item 2.

Tests updated:
- ``test_default_log_level_emits_legacy_line_at_error`` (renamed) —
  now asserts the legacy line at ERROR and explicitly that the
  categorised format is absent at default level.
- ``test_unknown_log_level_string_falls_back_to_error`` — same
  legacy-line shape after fallback.
- ``test_summary_skipped_when_no_events`` — pins the new
  ``True iff emitted`` contract; also asserts the cursor still
  advances to prevent the next call re-firing on every loop.
- New integration test ``TestSingleRejectionWithTrackerAtDefaultError``
  pins back-compat at the order_manager → tracker boundary.

README updated to drop the stale claim about ``[reject-summary]``
being the only new line and to describe the actual two-mode behaviour
(legacy line at ERROR, categorised line at downgraded levels).

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

Author: keitaj

README.md

@@ -363,7 +363,7 @@ The `market_making` strategy uses **progressive close pricing**: as a position a
 
 **Adverse selection logging** (`--enable-adverse-selection-log`): Measures mid-price movement 5s/30s/60s after each fill, logging per-coin summaries every 300s. Observation only — no trading impact.
 
-**Order rejection log aggregation** (`--rejection-log-level`, `--rejection-summary-interval`): Routine post-only rejections (`Post only order would have immediately matched`) are an expected retry signal under maker-only quoting, but they were historically logged at ERROR — drowning out genuine errors as MM size grows. The strategy now classifies each rejection by API error text and routes routine matches through a small aggregator that logs a single `[reject-summary]` INFO line every `--rejection-summary-interval` seconds (default 300, set to 0 to disable). The default per-rejection log level stays `error` to preserve historical behaviour; flip `--rejection-log-level warning` (or `info`) once the summary line is trusted. Unknown rejection text always falls through to ERROR so format changes / new reject reasons stay visible.
+**Order rejection log aggregation** (`--rejection-log-level`, `--rejection-summary-interval`): Routine post-only rejections (`Post only order would have immediately matched`) are an expected retry signal under maker-only quoting, but they were historically logged at ERROR — drowning out genuine errors as MM size grows. The strategy now classifies each rejection by API error text and adds a single `[reject-summary]` INFO line every `--rejection-summary-interval` seconds (default 300, set to 0 to disable). The default per-rejection log level stays `error` and emits the same byte-identical `Order rejected: …` line as before, so existing log scrapers and ERROR-rate alerts keep working. Flipping `--rejection-log-level warning` (or `info`) opts into a richer `[reject:tag] coin — …` categorised format at the chosen level; unknown rejection text always falls through to ERROR with the legacy line so format changes / new reject reasons stay visible.
 
 **Dynamic offset** (`--dynamic-offset`): Auto-adjusts per-coin BBO offset based on adverse selection severity from the tracker. Coins with higher adverse selection get wider offsets; favorable coins get tighter offsets. Requires `--enable-ws` and `--enable-adverse-selection-log`. Manual `--coin-offset-overrides` serve as the baseline; dynamic adjustment adds/subtracts from it.
 

order_rejection_tracker.py

@@ -130,6 +130,13 @@ def record(self, coin: str, raw_msg: str) -> str:
         Emits the per-rejection log at the configured level for routine
         matches; unknown patterns are forwarded to ERROR so format
         changes / new reject reasons remain visible.
+
+        At the default ERROR level the line is byte-identical to the
+        legacy ``logger.error("Order rejected: …")`` produced by
+        ``order_manager.py`` so existing log scrapers / ERROR-rate alert
+        templates continue to match. The richer
+        ``[reject:tag] coin — …`` format is reserved for the opt-in
+        downgraded levels (warning / info / debug).
         """
         tag = classify_rejection(raw_msg)
         bbo = _extract_bbo(raw_msg)
@@ -138,7 +145,9 @@ def record(self, coin: str, raw_msg: str) -> str:
         if tag == UNKNOWN_TAG:
             with self._lock:
                 self._unknown_count += 1
-            logger.error(f"Order rejected ({coin}): {raw_msg}")
+            # Legacy ``Order rejected: <msg>`` format preserved so
+            # back-compat with log scrapers holds for unknowns too.
+            logger.error(f"Order rejected: {raw_msg}")
             return tag
 
         with self._lock:
@@ -151,7 +160,14 @@ def record(self, coin: str, raw_msg: str) -> str:
 
         # Logger call deliberately outside the lock: the lock guards
         # only the in-memory counters.
-        logger.log(self._level, f"[reject:{tag}] {coin} — {raw_msg}")
+        if self._level == logging.ERROR:
+            # Default deployment: emit the legacy line verbatim so back-
+            # compat with existing log scrapers / templated alerts holds.
+            logger.error(f"Order rejected: {raw_msg}")
+        else:
+            # Downgraded — operator has opted in, give them the richer
+            # categorised line that carries coin + tag for grep-ability.
+            logger.log(self._level, f"[reject:{tag}] {coin} — {raw_msg}")
         return tag
 
     # ------------------------------------------------------------------ #
@@ -160,8 +176,14 @@ def record(self, coin: str, raw_msg: str) -> str:
     def log_summary_if_due(self, now_monotonic: Optional[float] = None) -> bool:
         """Emit a summary line if the configured interval has elapsed.
 
-        Returns ``True`` iff a summary was emitted.
-        ``summary_interval <= 0`` disables the summary entirely.
+        Returns ``True`` iff a summary line was actually emitted, ``False``
+        when:
+
+        * ``summary_interval <= 0`` (feature disabled), or
+        * the interval has not elapsed yet, or
+        * the interval elapsed but no rejections occurred (counters were
+          flushed silently — the strategy main loop discards the return
+          value, but tests / external observers can rely on this signal).
         """
         if self._summary_interval <= 0:
             return False
@@ -176,8 +198,7 @@ def log_summary_if_due(self, now_monotonic: Optional[float] = None) -> bool:
             self._unknown_count = 0
             self._last_summary_ts = now
 
-        self._emit_summary(snapshot, unknown)
-        return True
+        return self._emit_summary(snapshot, unknown)
 
     # ------------------------------------------------------------------ #
     # Internal helpers
@@ -186,7 +207,13 @@ def _emit_summary(
         self,
         snapshot: Dict[str, Dict[str, _CoinStats]],
         unknown: int,
-    ) -> None:
+    ) -> bool:
+        """Emit summary lines and return ``True`` iff anything was logged.
+
+        Returns ``False`` when both *snapshot* and *unknown* are empty —
+        the helper stays silent during idle periods rather than emitting
+        a meaningless ``total=0`` line every interval.
+        """
         any_emitted = False
         for tag, by_coin in snapshot.items():
             if not by_coin:
@@ -209,10 +236,7 @@ def _emit_summary(
                 f"count={unknown} (unknown patterns logged at ERROR individually)"
             )
             any_emitted = True
-        # No-op when both snapshot and unknown are empty: keeps the log
-        # quiet during idle periods rather than emitting a meaningless
-        # "total=0" line every interval.
-        return None if any_emitted else None
+        return any_emitted
 
     # ------------------------------------------------------------------ #
     # Operational helpers (read-only)

tests/test_order_manager_rejection_routing.py

@@ -124,6 +124,48 @@ def test_single_rejection_routed_through_tracker(self, caplog):
         assert tracker_lines[0].levelno == logging.WARNING
 
 
+class TestSingleRejectionWithTrackerAtDefaultError:
+    """Back-compat: tracker registered at default ERROR level emits the
+    legacy ``Order rejected: ...`` line (no categorised prefix), so log
+    scrapers / templated alerts that key off that exact prefix continue
+    to match. The categorised ``[reject:tag]`` format is reserved for
+    opt-in downgraded levels.
+    """
+
+    def test_default_error_level_emits_legacy_format(self, caplog):
+        mgr = _make_order_manager()
+        tracker = OrderRejectionTracker(
+            routine_log_level='error', summary_interval=0,
+        )
+        mgr.set_rejection_tracker(tracker)
+
+        mgr.exchange.order.return_value = {
+            'status': 'ok',
+            'response': {'data': {'statuses': [{'error': _POST_ONLY}]}},
+        }
+
+        with caplog.at_level(logging.DEBUG):
+            mgr._place_order(_make_order(coin='xyz:NVDA'))
+
+        # Counter still incremented (so summary aggregation works).
+        assert tracker.get_stats_snapshot()['post_only_match']['xyz:NVDA'] == 1
+
+        # Legacy line emitted at ERROR — matches what order_manager would
+        # produce without any tracker registered.
+        legacy = [
+            r for r in caplog.records
+            if r.message == f"Order rejected: {_POST_ONLY}"
+            and r.levelno == logging.ERROR
+        ]
+        assert len(legacy) == 1
+
+        # Categorised format must NOT appear at the default level.
+        categorised = [
+            r for r in caplog.records if "[reject:post_only_match]" in r.message
+        ]
+        assert categorised == []
+
+
 class TestUnknownPatternRouted:
     """Unknown text is still surfaced at ERROR via the tracker path."""
 

tests/test_order_rejection_tracker.py

@@ -82,16 +82,25 @@ def test_unknown_returns_unknown_tag_and_increments_separately(self):
         assert "unknown" not in t.get_stats_snapshot()
         assert t.get_unknown_count() == 1
 
-    def test_default_log_level_is_error(self, caplog):
+    def test_default_log_level_emits_legacy_line_at_error(self, caplog):
+        """At default ERROR level the line is byte-identical to the
+        legacy ``order_manager`` log so back-compat with log scrapers
+        holds. The richer ``[reject:tag]`` format is reserved for
+        opt-in downgraded levels."""
         t = OrderRejectionTracker()
         with caplog.at_level(logging.DEBUG, logger="order_rejection_tracker"):
             t.record("xyz:NVDA", _POST_ONLY_MSG)
-        # The routine log line is emitted at ERROR by default.
-        records = [
+        legacy = [
+            r for r in caplog.records
+            if r.message == f"Order rejected: {_POST_ONLY_MSG}"
+        ]
+        assert len(legacy) == 1
+        assert legacy[0].levelno == logging.ERROR
+        # The categorised format must NOT appear at the default level.
+        categorised = [
             r for r in caplog.records if "[reject:post_only_match]" in r.message
         ]
-        assert len(records) == 1
-        assert records[0].levelno == logging.ERROR
+        assert categorised == []
 
     def test_log_level_downgrade_to_warning(self, caplog):
         t = OrderRejectionTracker(routine_log_level="warning", summary_interval=0)
@@ -126,15 +135,18 @@ def test_unknown_pattern_always_logs_at_error(self, caplog):
 
     def test_unknown_log_level_string_falls_back_to_error(self, caplog):
         """A typo'd config value must not crash and must not silently skip
-        logging — fall back to ERROR so the operator sees output."""
+        logging — fall back to ERROR (legacy line format) so the
+        operator still sees output."""
         t = OrderRejectionTracker(routine_log_level="WARN_typo", summary_interval=0)
         with caplog.at_level(logging.DEBUG, logger="order_rejection_tracker"):
             t.record("xyz:NVDA", _POST_ONLY_MSG)
-        records = [
-            r for r in caplog.records if "[reject:post_only_match]" in r.message
+        # Falls back to ERROR → emits the legacy "Order rejected: ..." line.
+        legacy = [
+            r for r in caplog.records
+            if r.message == f"Order rejected: {_POST_ONLY_MSG}"
+            and r.levelno == logging.ERROR
         ]
-        assert len(records) == 1
-        assert records[0].levelno == logging.ERROR
+        assert len(legacy) == 1
 
     def test_uppercase_log_level_accepted(self):
         """Config values like ``WARNING`` should still resolve."""
@@ -233,18 +245,21 @@ def test_summary_includes_unknown_when_present(self, caplog):
         assert "count=1" in unknown_lines[0].message
 
     def test_summary_skipped_when_no_events(self, caplog):
-        """An empty interval should not emit any summary line at all."""
+        """An empty interval emits no summary line and the helper
+        returns False — the contract is "True iff a line was logged"."""
         t = OrderRejectionTracker(summary_interval=300)
         future = t._last_summary_ts + 301.0
         with caplog.at_level(logging.INFO, logger="order_rejection_tracker"):
             emitted = t.log_summary_if_due(now_monotonic=future)
-        # log_summary_if_due returns True (interval elapsed) but no summary
-        # line is emitted because there's nothing to report.
-        assert emitted is True
+        # No counters, so nothing was logged → False per the contract.
+        assert emitted is False
         summaries = [
             r for r in caplog.records if "[reject-summary]" in r.message
         ]
-        assert len(summaries) == 0
+        assert summaries == []
+        # The internal cursor *was* still advanced so the next due check
+        # waits another full interval rather than re-firing every loop.
+        assert t._last_summary_ts == future
 
     def test_top_8_truncation(self, caplog):
         t = OrderRejectionTracker(summary_interval=300)