security: redact raw chat payloads from service logs (fixes #197) (#198)

* security: redact raw chat payloads from service logs (fixes #197)

* chore: fix pylint findings for security log hardening

* fix: align chat_service logging levels with maintainer feedback

* chore: retrigger CI

* fix: simplify sub-query debug logging

* security: sanitize chat-service payload logs while preserving behavior

---------

Co-authored-by: Bervianto Leo Pratama <[email protected]>

Author: Flamki

chatbot-core/api/services/chat_service.py

@@ -20,6 +20,7 @@
 
 from api.services.memory import get_session, get_session_async
 from api.services.file_service import format_file_context
+from api.tools.sanitizer import sanitize_logs
 from api.tools.tools import TOOL_REGISTRY
 from api.tools.utils import (
     get_default_tools_call,
@@ -40,6 +41,16 @@
 )
 
 
+def _sanitize_log_payload(payload: object) -> str:
+    """
+    Convert payloads to strings and redact common secrets before logging them.
+    """
+    if payload is None:
+        return ""
+
+    return sanitize_logs(str(payload))
+
+
 def get_chatbot_reply(
     session_id: str,
     user_input: str,
@@ -58,21 +69,21 @@ def get_chatbot_reply(
         ChatResponse: The generated assistant response.
     """
     logger.info("New message from session '%s'", session_id)
-    logger.info("Handling the user query: %s", user_input)
+    logger.debug("Handling the user query: %s", _sanitize_log_payload(user_input))
 
     memory = get_session(session_id)
     if memory is None:
         raise RuntimeError(f"Session '{session_id}' not found in the memory store.")
 
     context = retrieve_context(user_input)
-    logger.info("Context retrieved: %s", context)
+    logger.debug("Context retrieved: %s", _sanitize_log_payload(context))
 
     # Process file context if files are provided
     context = _process_file_context(context, files)
 
     prompt = build_prompt(user_input, context, memory)
 
-    logger.info("Generating answer with prompt: %s", prompt)
+    logger.debug("Generating answer with prompt: %s", _sanitize_log_payload(prompt))
     reply = generate_answer(prompt)
 
     # Format user message with file info for memory
@@ -129,7 +140,7 @@ def get_chatbot_reply_new_architecture(
         ChatResponse: The generated assistant response.
     """
     logger.info("New message from session '%s'", session_id)
-    logger.info("Handling the user query: %s", user_input)
+    logger.debug("Handling the user query: %s", _sanitize_log_payload(user_input))
 
     memory = get_session(session_id)
     if memory is None:
@@ -188,11 +199,11 @@ def _handle_query_type(query: str, query_type: QueryType, memory) -> str:
 
         answers = []
         for sub_query in sub_queries:
-            logger.info("Handling the sub-query: %s.", sub_query)
+            logger.debug("Handling sub-query: %s.", _sanitize_log_payload(sub_query))
             answers.append(_get_reply_simple_query_pipeline(sub_query, memory))
 
         reply = _assemble_response(answers)
-        logger.info("Final response: %s", reply)
+        logger.debug("Final response: %s", _sanitize_log_payload(reply))
     else:
         reply = _get_reply_simple_query_pipeline(query, memory)
 
@@ -216,10 +227,8 @@ def _get_sub_queries(query: str) -> List[str]:
     try:
         queries = ast.literal_eval(queries_string)
     except (ValueError, TypeError, SyntaxError, MemoryError, RecursionError):
-        logger.warning(
-            "Error in parsing the subqueries. The string may be not formed"
-            " correctly: %s. Setting to default array with 1 element.",
-            queries_string)
+        logger.warning("Error in parsing sub-queries. Falling back to single query mode.")
+        logger.debug("Failed sub-query payload: %s", _sanitize_log_payload(queries_string))
         queries = [query]
 
     queries = [q.strip() for q in queries]
@@ -257,7 +266,7 @@ def _get_reply_simple_query_pipeline(query: str, memory) -> str:
 
         retrieved_context = _execute_search_tools(tool_calls)
 
-        logger.info("Retrieved context: %s", retrieved_context)
+        logger.debug("Retrieved context: %s", _sanitize_log_payload(retrieved_context))
 
         relevance = _get_query_context_relevance(query, retrieved_context)
         logger.info("Query context relevance %s", relevance)
@@ -286,25 +295,24 @@ def _get_agent_tool_calls(query: str):
     tool_calls = generate_answer(
         retriever_agent_prompt, llm_config["max_tokens_retriever_agent"] + (len(query) * 3))
 
-    logger.warning("Tool calls: %s", tool_calls)
+    logger.debug("Tool calls: %s", _sanitize_log_payload(tool_calls))
     try:
         tool_calls_parsed = json.loads(tool_calls)
         if not validate_tool_calls(tool_calls_parsed, logger):
             logger.warning("Tool calls are not respecting the signatures."
                            "Going for the default config")
             tool_calls_parsed = get_default_tools_call(query)
     except json.JSONDecodeError:
-        logger.warning(
-            "Invalid JSON syntax in the tools output: %s.",
-            tool_calls)
+        logger.warning("Invalid JSON syntax in the tools output.")
+        logger.debug("Raw tool calls payload: %s", _sanitize_log_payload(tool_calls))
         logger.warning("Calling all the search tools with default settings.")
         tool_calls_parsed = get_default_tools_call(query)
     except (KeyError, ValueError, TypeError, AttributeError) as e:
         logger.warning(
-            "JSON structure or value error(%s %s) in the tools output: %s.",
+            "JSON structure or value error(%s %s) in the tools output.",
             type(e).__name__,
-            e,
-            tool_calls)
+            e)
+        logger.debug("Raw tool calls payload: %s", _sanitize_log_payload(tool_calls))
         logger.warning("Calling all the search tools with default settings.")
         tool_calls_parsed = get_default_tools_call(query)
 
@@ -434,10 +442,15 @@ def generate_answer(prompt: str, max_tokens: Optional[int] = None) -> str:
         logger.error("LLM provider unavailable: %s", e)
         return "LLM is not available. Please install llama-cpp-python and configure a model."
     except (ValueError, RuntimeError) as exc:
-        logger.error("LLM generation failed for prompt: %r. Error: %r", prompt, exc)
+        logger.error("LLM generation failed: %s", _sanitize_log_payload(repr(exc)))
+        logger.debug("Failed prompt payload: %s", _sanitize_log_payload(prompt))
         return "Sorry, I'm having trouble generating a response right now."
-    except Exception:  # pylint: disable=broad-except
-        logger.exception("Unexpected error during LLM generation for prompt: %r", prompt)
+    except Exception as exc:  # pylint: disable=broad-except
+        logger.error(
+            "Unexpected error during LLM generation: %s",
+            _sanitize_log_payload(repr(exc))
+        )
+        logger.debug("Failed prompt payload: %s", _sanitize_log_payload(prompt))
         return "Sorry, an unexpected error occurred. Please contact support."
 
 
@@ -484,7 +497,7 @@ async def get_chatbot_reply_stream(
         str: Individual tokens from LLM response
     """
     logger.info("Streaming message from session '%s'", session_id)
-    logger.info("Handling user query: %s", user_input)
+    logger.debug("Handling user query: %s", _sanitize_log_payload(user_input))
 
     memory = await get_session_async(session_id)
 
@@ -493,10 +506,13 @@ async def get_chatbot_reply_stream(
             f"Session '{session_id}' not found in memory store.")
 
     context = retrieve_context(user_input)
-    logger.info("Context retrieved: %s", context)
+    logger.debug("Context retrieved: %s", _sanitize_log_payload(context))
 
     prompt = build_prompt(user_input, context, memory)
-    logger.info("Generating streaming answer with prompt: %s", prompt)
+    logger.debug(
+        "Generating streaming answer with prompt: %s",
+        _sanitize_log_payload(prompt)
+    )
 
     full_reply = ""
     async for token in generate_answer_stream(prompt):

chatbot-core/tests/unit/services/test_chat_service.py

@@ -1,8 +1,9 @@
 """Unit tests for chat service logic."""
 
 import logging
+from unittest.mock import MagicMock
 import pytest
-from api.services.chat_service import get_chatbot_reply, retrieve_context
+from api.services.chat_service import generate_answer, get_chatbot_reply, retrieve_context
 from api.config.loader import CONFIG
 from api.models.schemas import ChatResponse
 
@@ -40,6 +41,86 @@ def test_get_chatbot_reply_session_not_found(mock_get_session):
     assert "Session 'missing-session-id' not found in the memory store." in str(exc_info.value)
 
 
+def test_get_chatbot_reply_does_not_log_raw_content(
+    mock_get_session,
+    mock_retrieve_context,
+    mock_prompt_builder,
+    mock_llm_provider,
+    caplog
+):
+    """Ensure sensitive payloads are not logged at INFO level."""
+    logging.getLogger("API").propagate = True
+
+    sensitive_query = "token=abc123"
+    sensitive_context = "internal secret context"
+    sensitive_prompt = "prompt contains password=top-secret"
+
+    mock_chat_memory = MagicMock()
+    mock_session = mock_get_session.return_value
+    mock_session.chat_memory = mock_chat_memory
+    mock_retrieve_context.return_value = sensitive_context
+    mock_prompt_builder.return_value = sensitive_prompt
+    mock_llm_provider.generate.return_value = "safe response"
+
+    with caplog.at_level(logging.INFO):
+        get_chatbot_reply("session-id", sensitive_query)
+
+    assert sensitive_query not in caplog.text
+    assert sensitive_context not in caplog.text
+    assert sensitive_prompt not in caplog.text
+    assert "New message from session 'session-id'" in caplog.text
+
+
+def test_get_chatbot_reply_debug_logs_are_sanitized(
+    mock_get_session,
+    mock_retrieve_context,
+    mock_prompt_builder,
+    mock_llm_provider,
+    caplog
+):
+    """Ensure payload-heavy debug logs keep structure but redact secrets."""
+    logging.getLogger("API").propagate = True
+
+    sanitized_query = "api_key=[REDACTED]"
+    sanitized_context = "password=[REDACTED]"
+    sanitized_prompt = "Bearer [REDACTED_TOKEN]"
+
+    mock_chat_memory = MagicMock()
+    mock_session = mock_get_session.return_value
+    mock_session.chat_memory = mock_chat_memory
+    mock_retrieve_context.return_value = "context password=top-secret"
+    mock_prompt_builder.return_value = (
+        "prompt Authorization: Bearer "
+        "ghp_1234567890abcdef1234567890abcdef1234"
+    )
+    mock_llm_provider.generate.return_value = "safe response"
+
+    with caplog.at_level(logging.DEBUG, logger="API"):
+        get_chatbot_reply("session-id", "api_key=abc123")
+
+    assert "api_key=abc123" not in caplog.text
+    assert "password=top-secret" not in caplog.text
+    assert "ghp_1234567890abcdef1234567890abcdef1234" not in caplog.text
+    assert sanitized_query in caplog.text
+    assert sanitized_context in caplog.text
+    assert sanitized_prompt in caplog.text
+
+
+def test_generate_answer_error_logs_sanitized_prompt(mock_llm_provider, caplog):
+    """Ensure failed prompt logging is sanitized across ERROR and DEBUG paths."""
+    logging.getLogger("API").propagate = True
+    sensitive_prompt = "api_key=very-secret-key"
+    mock_llm_provider.generate.side_effect = RuntimeError("provider failure")
+
+    with caplog.at_level(logging.DEBUG, logger="API"):
+        response = generate_answer(sensitive_prompt)
+
+    assert response == "Sorry, I'm having trouble generating a response right now."
+    assert sensitive_prompt not in caplog.text
+    assert "LLM generation failed" in caplog.text
+    assert "api_key=[REDACTED]" in caplog.text
+
+
 def test_retrieve_context_with_placeholders(mock_get_relevant_documents):
     """Test retrieve_context replaces placeholders with code blocks correctly."""
     mock_documents = get_mock_documents("with_placeholders")