diff --git a/litellm/_logging.py b/litellm/_logging.py index 36fd51206c2..7f0df92de5b 100644 --- a/litellm/_logging.py +++ b/litellm/_logging.py @@ -656,6 +656,7 @@ def _enable_debugging(): def print_verbose(print_statement): try: + verbose_logger.debug(redact_secrets(str(print_statement))) if set_verbose: print(redact_secrets(str(print_statement))) # noqa: T201 except Exception: diff --git a/tests/test_litellm/test_logging.py b/tests/test_litellm/test_logging.py index db8dfaa3ad6..818a9860d4e 100644 --- a/tests/test_litellm/test_logging.py +++ b/tests/test_litellm/test_logging.py @@ -294,6 +294,39 @@ def test_initialize_loggers_with_handler_sets_propagate_false(): ) +def test_print_verbose_emits_debug_record_without_set_verbose(): + """Regression for #32318. + + print_verbose in litellm/_logging.py only wrote to stdout when + litellm.set_verbose was True and never routed through verbose_logger, so + cache/debug logs were suppressed when only LITELLM_LOG=DEBUG (logger at DEBUG) + was set. It must emit a DEBUG record through verbose_logger regardless of + set_verbose. + """ + import litellm._logging as _logging_module + + records: List[logging.LogRecord] = [] + + class _Capture(logging.Handler): + def emit(self, record): + records.append(record) + + handler = _Capture() + verbose_logger.addHandler(handler) + prev_level = verbose_logger.level + prev_set_verbose = _logging_module.set_verbose + verbose_logger.setLevel(logging.DEBUG) + _logging_module.set_verbose = False + try: + _logging_module.print_verbose("cache debug marker 32318") + finally: + verbose_logger.removeHandler(handler) + verbose_logger.setLevel(prev_level) + _logging_module.set_verbose = prev_set_verbose + + assert any("cache debug marker 32318" in record.getMessage() for record in records) + + @pytest.mark.asyncio async def test_cache_hit_includes_custom_llm_provider(): """