Refactor observability message capture loop

python/packages/core/agent_framework/observability.py

@@ -2157,14 +2157,12 @@ def _capture_messages(
 
     normalized_messages = normalize_messages(messages)
     logging_messages = prepend_instructions_to_messages(normalized_messages, system_instructions)
-    span_messages = [_to_otel_message(message) for message in normalized_messages]
     prepended_count = len(logging_messages) - len(normalized_messages)
-    prepended_messages = [_to_otel_message(message) for message in logging_messages[:prepended_count]]
-    for index, (message, otel_message) in enumerate(
-        zip(logging_messages[:prepended_count], prepended_messages, strict=True)
-    ):
+    span_messages = []
+    for index, message in enumerate(logging_messages):
         # Reuse the otel message representation for logging instead of calling to_dict()
         # to avoid expensive Pydantic serialization overhead
+        otel_message = _to_otel_message(message)
         logger.info(
             otel_message,
             extra={
@@ -2173,17 +2171,8 @@ def _capture_messages(
                 MessageListTimestampFilter.INDEX_KEY: index,
             },
         )
-    for index, (message, otel_message) in enumerate(
-        zip(normalized_messages, span_messages, strict=True), start=prepended_count
-    ):
-        logger.info(
-            otel_message,
-            extra={
-                OtelAttr.EVENT_NAME: OtelAttr.CHOICE if output else ROLE_EVENT_MAP.get(message.role),
-                OtelAttr.PROVIDER_NAME: provider_name,
-                MessageListTimestampFilter.INDEX_KEY: index,
-            },
-        )
+        if index >= prepended_count:
+            span_messages.append(otel_message)
     if finish_reason:
         span_messages[-1]["finish_reason"] = FINISH_REASON_MAP[finish_reason]
     span.set_attribute(

python/packages/core/tests/core/test_observability.py

@@ -3056,6 +3056,44 @@ def test_capture_messages_logs_prepended_instructions_without_serializing_them(
     assert logged_messages[1]["parts"][0]["content"] == "Test"
 
 
+def test_capture_messages_logs_framework_and_chat_history_system_messages_once(
+    span_exporter: InMemorySpanExporter,
+):
+    """Test framework instructions and chat-history system messages each log once."""
+    import json
+
+    from opentelemetry import trace
+
+    tracer = trace.get_tracer("test")
+    span_exporter.clear()
+
+    with (
+        patch("agent_framework.observability.logger.info") as mock_logger_info,
+        tracer.start_as_current_span("test_span") as span,
+    ):
+        _capture_messages(
+            span=span,
+            provider_name="test_provider",
+            messages=[
+                Message(role="system", contents=["Original system message"]),
+                Message(role="user", contents=["Test"]),
+            ],
+            system_instructions="Framework system instruction",
+        )
+
+    spans = span_exporter.get_finished_spans()
+    assert len(spans) == 1
+    input_messages = json.loads(spans[0].attributes[OtelAttr.INPUT_MESSAGES])
+    assert [msg.get("role") for msg in input_messages] == ["system", "user"]
+
+    assert mock_logger_info.call_count == 3, f"Expected 3 log calls, got {mock_logger_info.call_count}"
+    logged_messages = [call.args[0] for call in mock_logger_info.call_args_list]
+    assert [msg["role"] for msg in logged_messages] == ["system", "system", "user"]
+    assert logged_messages[0]["parts"][0]["content"] == "Framework system instruction"
+    assert logged_messages[1]["parts"][0]["content"] == "Original system message"
+    assert logged_messages[2]["parts"][0]["content"] == "Test"
+
+
 @pytest.mark.parametrize("enable_sensitive_data", [True], indirect=True)
 async def test_tool_arguments_preserves_non_ascii_characters(span_exporter: InMemorySpanExporter):
     """Test that non-ASCII characters are preserved in tool arguments span attribute."""