fix(iorails): Logger defaults to non-verbose (#2310)

Author: tgasser-nv

docs/observability/logging/index.mdx

@@ -39,6 +39,21 @@ This outputs detailed information about:
 - Action executions
 - Flow transitions
 
+### Verbose mode on `Guardrails` and `LLMRails`
+
+The two entry points interpret `verbose=True` differently.
+
+| Entry point | Effect of `verbose=True` |
+|-------------|--------------------------|
+| `LLMRails(config, verbose=True)` | Adds a verbose console handler at `INFO` to the root logger and logs LLM prompts and completions. |
+| `Guardrails(config, verbose=True)` | Calls `configure_logging(logging.DEBUG)`, attaching a stderr handler to the `nemoguardrails.guardrails` logger and setting it to `DEBUG`. |
+
+When `Guardrails` falls back to `LLMRails` — because an `llm` was passed, or the config contains flows IORails does not support — both apply, because `verbose` is forwarded to the `LLMRails` instance it creates.
+
+Note that `configure_logging` also stops the `nemoguardrails.guardrails` logger propagating to the root logger; see [OpenTelemetry logs](/observability/tracing/opentelemetry-logs) for what that means for handlers you attach yourself.
+
+A default `Guardrails(config)` construction configures no logging at all, leaving handlers, levels, and formatting to your application.
+
 ## Explain Method
 
 Get a quick summary of the last generation using the `explain()` method:

docs/observability/tracing/opentelemetry-logs.mdx

@@ -150,7 +150,7 @@ Log records emitted outside any guardrails request, such as startup, engine regi
 - Performance
   : At high log volumes or DEBUG level, log export can add measurable overhead. Use `BatchLogRecordProcessor` (as shown) rather than the synchronous `SimpleLogRecordProcessor` in production, and consider filtering at the logger level (`logging.getLogger("nemoguardrails").setLevel(logging.INFO)`) to limit what crosses the bridge.
 - Interaction with `propagate=False`
-  : If your application calls `nemoguardrails.guardrails.configure_logging()` on a freshly initialized logger, that helper sets `propagate=False` on the `nemoguardrails.guardrails` logger to prevent duplicate console output. The flag is only set on the first call, when no handlers exist yet. Records from submodules under `nemoguardrails.guardrails.*` will then not reach the handler attached to `nemoguardrails`. To capture them, attach the handler to `nemoguardrails.guardrails` instead of (or in addition to) `nemoguardrails`.
+  : `nemoguardrails.guardrails.configure_logging()` sets `propagate=False` on the `nemoguardrails.guardrails` logger to prevent duplicate console output. It runs when your application calls it directly, and when you construct `Guardrails(..., verbose=True)`. The flag is only set on the first call, when no handlers exist yet. Records from submodules under `nemoguardrails.guardrails.*` will then not reach the handler attached to `nemoguardrails`. To capture them, attach the handler to `nemoguardrails.guardrails` instead of (or in addition to) `nemoguardrails`. A default `Guardrails(...)` construction does not configure logging, so its records propagate normally.
 
 ## Related Resources
 

nemoguardrails/guardrails/guardrails.py

@@ -68,15 +68,18 @@ def __init__(
         LLMRails and logs a warning. Set ``require_iorails=True`` to raise a
         ``ValueError`` instead — use this when IORails-only features such as
         OpenTelemetry metrics are required.
+
+        ``verbose=True`` also routes this package's logs to stderr through ``configure_logging``;
+        without it, handlers, levels and formatting are left to the calling application.
         """
 
         self.config = config
         self.verbose = verbose
 
+        # configure_logging attaches a handler and stops the package logger propagating, detaching
+        # nemoguardrails.guardrails from the handlers the application installed on the root logger.
         if verbose:
             configure_logging(logging.DEBUG)
-        else:
-            configure_logging(logging.INFO)
 
         if use_iorails:
             fallback_reason = IORails.unsupported_reason(config, llm)

tests/guardrails/test_guardrails.py

@@ -20,6 +20,7 @@ class correctly delegates method calls with properly formatted parameters.
 """
 
 import json
+import logging
 from unittest.mock import AsyncMock, MagicMock, patch
 
 import pytest
@@ -101,6 +102,25 @@ def mock_llm():
     return llm
 
 
+@pytest.fixture
+def pristine_package_logger():
+    """Hand back an unconfigured ``nemoguardrails.guardrails`` logger, restoring it afterward."""
+    # A test inheriting the configured state cannot tell a fixed constructor from a broken one.
+    logger = logging.getLogger("nemoguardrails.guardrails")
+    saved_handlers = list(logger.handlers)
+    saved_propagate = logger.propagate
+    saved_level = logger.level
+    logger.handlers.clear()
+    logger.propagate = True
+    logger.setLevel(logging.NOTSET)
+    try:
+        yield logger
+    finally:
+        logger.handlers[:] = saved_handlers
+        logger.propagate = saved_propagate
+        logger.setLevel(saved_level)
+
+
 class TestGuardrailsRouting:
     """Tests to check the routing of requests to Guardrails between LLMRails and IORails"""
 
@@ -304,7 +324,7 @@ def test_init_without_llm(self, mock_llmrails_class, _nemoguards_rails_config):
         assert guardrails.rails_engine == mock_llmrails_instance
 
     @patch("nemoguardrails.guardrails.guardrails.LLMRails")
-    def test_init_with_llm(self, mock_llmrails_class, _nemoguards_rails_config, mock_llm):
+    def test_init_with_llm(self, mock_llmrails_class, _nemoguards_rails_config, mock_llm, pristine_package_logger):
         """Test initialization with a custom LLM."""
         mock_llmrails_instance = MagicMock()
         mock_llmrails_class.return_value = mock_llmrails_instance
@@ -348,6 +368,52 @@ def test_init_without_llm_uses_iorails(self, mock_iorails_init, _content_safety_
         mock_iorails_init.assert_called_once_with(_content_safety_rails_config)
 
 
+class TestConstructionLoggingSideEffects:
+    """Constructing Guardrails must not take over the ``nemoguardrails.guardrails`` logger.
+
+    Doing so detaches it from the application's root handlers, silencing that subtree with no error.
+    """
+
+    @patch.object(IORails, "__init__", return_value=None)
+    def test_default_construction_leaves_the_package_logger_propagating(
+        self, _mock_iorails_init, _content_safety_rails_config, pristine_package_logger
+    ):
+        """A default construction leaves package records reaching ancestor handlers."""
+        Guardrails(config=_content_safety_rails_config, use_iorails=True)
+
+        assert pristine_package_logger.propagate is True
+
+    @patch.object(IORails, "__init__", return_value=None)
+    def test_default_construction_adds_no_handler_of_its_own(
+        self, _mock_iorails_init, _content_safety_rails_config, pristine_package_logger
+    ):
+        """A default construction attaches no handler, leaving output routing to the application."""
+        Guardrails(config=_content_safety_rails_config, use_iorails=True)
+
+        assert pristine_package_logger.handlers == []
+
+    @patch.object(IORails, "__init__", return_value=None)
+    def test_records_logged_after_a_default_construction_stay_visible(
+        self, _mock_iorails_init, _content_safety_rails_config, pristine_package_logger, caplog
+    ):
+        """A package record emitted after a construction still reaches caplog, which listens at root."""
+        with caplog.at_level(logging.WARNING):
+            Guardrails(config=_content_safety_rails_config, use_iorails=True)
+            logging.getLogger("nemoguardrails.guardrails.iorails").warning("visible after construction")
+
+        assert "visible after construction" in caplog.text
+
+    @patch.object(IORails, "__init__", return_value=None)
+    def test_verbose_construction_still_configures_the_package_logger(
+        self, _mock_iorails_init, _content_safety_rails_config, pristine_package_logger
+    ):
+        """verbose=True still opts in to the package's own handler and debug level."""
+        Guardrails(config=_content_safety_rails_config, use_iorails=True, verbose=True)
+
+        assert pristine_package_logger.handlers
+        assert pristine_package_logger.level == logging.DEBUG
+
+
 class TestIORailsUnsupportedReason:
     """Direct tests for ``IORails.unsupported_reason`` and ``IORails.can_handle``."""
 
@@ -1777,7 +1843,9 @@ def test_pickle_preserves_llmrails_when_llm_was_passed(
         assert mock_llmrails_init.call_count == 2
 
     @patch.object(IORails, "__init__", return_value=None)
-    def test_getstate_preserves_verbose_true(self, mock_iorails_init, _nemoguards_rails_config):
+    def test_getstate_preserves_verbose_true(
+        self, mock_iorails_init, _nemoguards_rails_config, pristine_package_logger
+    ):
         """__getstate__ captures verbose=True so a verbose Guardrails round-trips
         with logging configuration intact."""
         guardrails = Guardrails(config=_nemoguards_rails_config, verbose=True)
@@ -1793,7 +1861,9 @@ def test_setstate_restores_verbose_true(self, mock_iorails_init, _nemoguards_rai
         assert guardrails.verbose is True
 
     @patch.object(IORails, "__init__", return_value=None)
-    def test_pickle_round_trip_preserves_verbose(self, mock_iorails_init, _nemoguards_rails_config):
+    def test_pickle_round_trip_preserves_verbose(
+        self, mock_iorails_init, _nemoguards_rails_config, pristine_package_logger
+    ):
         """Full round-trip: a Guardrails constructed with verbose=True must come
         back from __getstate__/__setstate__ with verbose=True. Regression for the
         bug where verbose was hardcoded to False on restore, silently obscuring

tests/recorded/rails/library/test_iorails_parity.py

@@ -103,27 +103,27 @@ def vcr_cassette_dir(request: pytest.FixtureRequest) -> str:
 
 @pytest.fixture
 def rail_ran_cleanly(caplog: pytest.LogCaptureFixture):
-    """Fail the test if any rail errored, which is what an unreplayed cassette looks like.
-
-    Without this a blocked-case assertion is vacuous: a cassette that fails to replay raises
-    inside the action, the fail-closed envelope turns that into a block naming the same rail
-    with the same refusal text, and status, rail and content all still match. The rail logs at
-    ERROR when it fails and does not when it reaches a verdict, so that is the difference.
-    """
-    with caplog.at_level(logging.ERROR):
-        yield
-        # get_records("call") rather than .records: during teardown the latter reports the
-        # teardown phase, which is empty, and the check would pass no matter what the rail did.
-        # Restricted to this package's loggers because the question is whether a *rail* failed,
-        # which rail_guard reports. Anything at ERROR would also catch aiohttp's unclosed-session
-        # message, which the asyncio exception handler emits from __del__ whenever the collector
-        # happens to run -- so an unrelated leak elsewhere in the suite would fail this test.
+    """Fail the test if any rail errored, which is what an unreplayed cassette looks like."""
+    # caplog listens at root, so rail_guard's records only arrive while this logger propagates.
+    # Set it rather than trust it: a verbose=True construction earlier closes it process-wide.
+    package_logger = logging.getLogger("nemoguardrails.guardrails")
+    was_propagating = package_logger.propagate
+    package_logger.propagate = True
+    try:
+        with caplog.at_level(logging.ERROR):
+            yield
+            # Closed mid-test it is captured nowhere, leaving the errors below empty either way.
+            assert package_logger.propagate, "the nemoguardrails.guardrails logger stopped propagating mid-test"
+        # get_records("call"): .records would report the empty teardown phase here. Package loggers
+        # only, so aiohttp's unclosed-session ERROR from an unrelated leak cannot fail the test.
         errors = [
             record.getMessage()
             for record in caplog.get_records("call")
             if record.levelno >= logging.ERROR and record.name.startswith("nemoguardrails")
         ]
         assert not errors, f"a rail errored, so the cassette did not replay: {errors}"
+    finally:
+        package_logger.propagate = was_propagating
 
 
 async def check_iorails(config, messages: list[dict], rail_types: tuple[RailType, ...]):