chore: fix tracing for text chat mode

This commit is contained in:
Abhishek Kumar 2026-05-21 12:30:56 +05:30
parent e23cce444f
commit 08a2435ba5
31 changed files with 1753 additions and 597 deletions

View file

@ -0,0 +1,53 @@
from api.services.pipecat.realtime_feedback_events import (
build_bot_text_event,
build_function_call_end_event,
build_node_transition_event,
realtime_feedback_event_sort_key,
stamp_realtime_feedback_event,
)
def test_build_function_call_end_event_serializes_results():
event = build_function_call_end_event(
function_name="lookup_contact",
tool_call_id="tool-1",
result={"contact_id": 42},
)
assert event == {
"type": "rtf-function-call-end",
"payload": {
"function_name": "lookup_contact",
"tool_call_id": "tool-1",
"result": "{'contact_id': 42}",
},
}
def test_stamp_and_sort_realtime_feedback_events():
node_transition = stamp_realtime_feedback_event(
build_node_transition_event(
node_id="node-1",
node_name="Greeting",
previous_node_id=None,
previous_node_name=None,
),
timestamp="2026-01-01T00:00:03+00:00",
turn=0,
node_id="node-1",
node_name="Greeting",
)
bot_text = stamp_realtime_feedback_event(
build_bot_text_event(
text="Hello there",
timestamp="2026-01-01T00:00:01+00:00",
),
timestamp="2026-01-01T00:00:02+00:00",
turn=0,
)
events = sorted([node_transition, bot_text], key=realtime_feedback_event_sort_key)
assert events == [bot_text, node_transition]
assert node_transition["node_id"] == "node-1"
assert node_transition["node_name"] == "Greeting"

View file

@ -0,0 +1,126 @@
from api.services.workflow.text_chat_logs import (
build_text_chat_realtime_feedback_events,
visible_text_chat_turns,
)
def test_visible_text_chat_turns_trims_to_cursor_branch():
session_data = {
"cursor_turn_id": "turn-2",
"turns": [
{"id": "turn-1"},
{"id": "turn-2"},
{"id": "turn-3"},
],
}
assert visible_text_chat_turns(session_data) == [
{"id": "turn-1"},
{"id": "turn-2"},
]
def test_build_text_chat_realtime_feedback_events_uses_visible_branch_and_dedupes_node_transitions():
session_data = {
"cursor_turn_id": "turn-2",
"turns": [
{
"id": "turn-1",
"created_at": "2026-01-01T00:00:00+00:00",
"events": [
{
"type": "node_transition",
"created_at": "2026-01-01T00:00:00+00:00",
"payload": {
"node_id": "node-start",
"node_name": "Start",
"previous_node_id": None,
"previous_node_name": None,
"allow_interrupt": False,
},
}
],
"user_message": None,
"assistant_message": {
"text": "Hello",
"created_at": "2026-01-01T00:00:01+00:00",
},
},
{
"id": "turn-2",
"created_at": "2026-01-01T00:00:02+00:00",
"events": [
{
"type": "node_transition",
"created_at": "2026-01-01T00:00:02+00:00",
"payload": {
"node_id": "node-start",
"node_name": "Start",
"previous_node_id": None,
"previous_node_name": None,
"allow_interrupt": False,
},
},
{
"type": "tool_call_started",
"created_at": "2026-01-01T00:00:03+00:00",
"payload": {
"function_name": "lookup_contact",
"tool_call_id": "tool-1",
},
},
{
"type": "tool_call_result",
"created_at": "2026-01-01T00:00:04+00:00",
"payload": {
"function_name": "lookup_contact",
"tool_call_id": "tool-1",
"result": {"contact_id": 42},
},
},
],
"user_message": {
"text": "Find Abhishek",
"created_at": "2026-01-01T00:00:02+00:00",
},
"assistant_message": {
"text": "I found one match.",
"created_at": "2026-01-01T00:00:05+00:00",
},
},
{
"id": "turn-3",
"created_at": "2026-01-01T00:00:06+00:00",
"events": [
{
"type": "execution_error",
"created_at": "2026-01-01T00:00:06+00:00",
"payload": {"message": "Should be hidden after rewind"},
}
],
"user_message": {
"text": "This turn is rewound away",
"created_at": "2026-01-01T00:00:06+00:00",
},
"assistant_message": None,
},
],
}
events = build_text_chat_realtime_feedback_events(session_data)
assert [event["type"] for event in events] == [
"rtf-node-transition",
"rtf-bot-text",
"rtf-user-transcription",
"rtf-function-call-start",
"rtf-function-call-end",
"rtf-bot-text",
]
assert events[0]["payload"]["node_name"] == "Start"
assert events[2]["payload"]["text"] == "Find Abhishek"
assert events[4]["payload"]["result"] == "{'contact_id': 42}"
assert all(
event.get("payload", {}).get("error") != "Should be hidden after rewind"
for event in events
)

View file

@ -0,0 +1,45 @@
import pytest
from api.services.workflow.text_chat_session_service import (
TextChatTurnNotFoundError,
build_pending_text_chat_turn,
truncate_text_chat_future_turns,
validate_text_chat_turn_cursor,
)
def test_build_pending_text_chat_turn_sets_pending_shape():
turn = build_pending_text_chat_turn(user_text="Hello")
assert turn["id"].startswith("turn_")
assert turn["status"] == "pending"
assert turn["user_message"]["text"] == "Hello"
assert turn["assistant_message"] is None
assert turn["events"] == []
assert turn["usage"] == {}
def test_truncate_text_chat_future_turns_moves_rewound_branch_to_discarded_future():
session_data = {
"cursor_turn_id": "turn-2",
"turns": [
{"id": "turn-1"},
{"id": "turn-2"},
{"id": "turn-3"},
],
"discarded_future": [],
}
active_turns, discarded_future = truncate_text_chat_future_turns(session_data)
assert active_turns == [{"id": "turn-1"}, {"id": "turn-2"}]
assert discarded_future[0]["rewound_from_turn_id"] == "turn-2"
assert discarded_future[0]["turns"] == [{"id": "turn-3"}]
def test_validate_text_chat_turn_cursor_raises_for_missing_turn():
with pytest.raises(TextChatTurnNotFoundError):
validate_text_chat_turn_cursor(
{"turns": [{"id": "turn-1"}]},
"turn-404",
)

View file

@ -0,0 +1,87 @@
from datetime import UTC, datetime
from types import SimpleNamespace
from unittest.mock import AsyncMock
import pytest
from api.services.pricing import workflow_run_cost as workflow_run_cost_mod
from api.services.pricing.workflow_run_cost import (
build_workflow_run_cost_info,
calculate_workflow_run_cost,
)
def _make_workflow_run():
return SimpleNamespace(
id=123,
workflow_id=456,
mode="textchat",
created_at=datetime.now(UTC),
usage_info={
"llm": {},
"tts": {},
"stt": {},
"call_duration_seconds": 7,
},
cost_info={},
workflow=SimpleNamespace(
organization_id=42,
user=SimpleNamespace(selected_organization_id=42),
),
)
@pytest.mark.asyncio
async def test_build_workflow_run_cost_info_does_not_update_org_usage(monkeypatch):
workflow_run = _make_workflow_run()
get_org = AsyncMock(return_value=SimpleNamespace(id=42, price_per_second_usd=1.5))
update_usage = AsyncMock()
monkeypatch.setattr(
workflow_run_cost_mod.db_client, "get_organization_by_id", get_org
)
monkeypatch.setattr(
workflow_run_cost_mod.db_client, "update_usage_after_run", update_usage
)
cost_info = await build_workflow_run_cost_info(workflow_run)
assert cost_info is not None
assert cost_info["call_duration_seconds"] == 7
assert "cost_breakdown" in cost_info
assert "dograh_token_usage" in cost_info
assert cost_info["charge_usd"] == 10.5
update_usage.assert_not_called()
@pytest.mark.asyncio
async def test_calculate_workflow_run_cost_keeps_org_usage_side_effect_in_wrapper(
monkeypatch,
):
workflow_run = _make_workflow_run()
get_org = AsyncMock(return_value=SimpleNamespace(id=42, price_per_second_usd=None))
update_run = AsyncMock()
update_usage = AsyncMock()
monkeypatch.setattr(
workflow_run_cost_mod.db_client,
"get_workflow_run_by_id",
AsyncMock(return_value=workflow_run),
)
monkeypatch.setattr(
workflow_run_cost_mod.db_client, "get_organization_by_id", get_org
)
monkeypatch.setattr(
workflow_run_cost_mod.db_client, "update_workflow_run", update_run
)
monkeypatch.setattr(
workflow_run_cost_mod.db_client, "update_usage_after_run", update_usage
)
await calculate_workflow_run_cost(workflow_run.id)
update_run.assert_awaited_once()
saved_kwargs = update_run.await_args.kwargs
assert saved_kwargs["run_id"] == workflow_run.id
assert "cost_breakdown" in saved_kwargs["cost_info"]
update_usage.assert_awaited_once()

View file

@ -8,6 +8,15 @@ from api.tests.integrations._run_pipeline_helpers import USER_CONFIGURATION
from pipecat.tests import MockLLMService
def _log_texts(logs: dict | None, event_type: str) -> list[str]:
events = (logs or {}).get("realtime_feedback_events") or []
return [
event.get("payload", {}).get("text", "")
for event in events
if event.get("type") == event_type
]
async def _create_user_and_workflow(
db_session,
async_session,
@ -115,6 +124,11 @@ async def test_text_chat_session_creation_executes_initial_assistant_turn(
)
assert create_response.status_code == 200
created = create_response.json()
run_response = await client.get(
f"/api/v1/workflow/{workflow.id}/runs/{created['workflow_run_id']}"
)
assert run_response.status_code == 200
run_payload = run_response.json()
turns = created["session_data"]["turns"]
assert created["revision"] == 2
@ -127,6 +141,16 @@ async def test_text_chat_session_creation_executes_initial_assistant_turn(
assert created["checkpoint"]["current_node_id"] == "start"
assert created["state"] == "running"
assert "Start" in (created["gathered_context"] or {}).get("nodes_visited", [])
workflow_run = await db_session.get_workflow_run_by_id(created["workflow_run_id"])
assert workflow_run is not None
assert workflow_run.cost_info[
"call_duration_seconds"
] == workflow_run.usage_info.get("call_duration_seconds", 0)
assert "cost_breakdown" in workflow_run.cost_info
assert "dograh_token_usage" in workflow_run.cost_info
assert _log_texts(run_payload["logs"], "rtf-bot-text") == [
"Hello from the workflow tester."
]
@pytest.mark.asyncio
@ -217,6 +241,11 @@ async def test_text_chat_message_executes_assistant_turn(
},
)
assert message_response.status_code == 200
run_response = await client.get(
f"/api/v1/workflow/{workflow.id}/runs/{created['workflow_run_id']}"
)
assert run_response.status_code == 200
run_payload = run_response.json()
payload = message_response.json()
turns = payload["session_data"]["turns"]
@ -232,6 +261,18 @@ async def test_text_chat_message_executes_assistant_turn(
assert payload["checkpoint"]["current_node_id"] == "start"
assert payload["state"] == "running"
assert "Start" in (payload["gathered_context"] or {}).get("nodes_visited", [])
workflow_run = await db_session.get_workflow_run_by_id(created["workflow_run_id"])
assert workflow_run is not None
assert workflow_run.cost_info[
"call_duration_seconds"
] == workflow_run.usage_info.get("call_duration_seconds", 0)
assert "cost_breakdown" in workflow_run.cost_info
assert "dograh_token_usage" in workflow_run.cost_info
assert _log_texts(run_payload["logs"], "rtf-user-transcription") == ["Hi there"]
assert _log_texts(run_payload["logs"], "rtf-bot-text") == [
"Welcome to the workflow tester.",
"Hello from the workflow tester.",
]
@pytest.mark.asyncio
@ -330,8 +371,13 @@ async def test_text_chat_executes_deferred_tool_calls_after_text_response(
},
)
assert message_response.status_code == 200
run_response = await client.get(
f"/api/v1/workflow/{workflow.id}/runs/{session['workflow_run_id']}"
)
assert run_response.status_code == 200
payload = message_response.json()
run_payload = run_response.json()
assistant_text = payload["session_data"]["turns"][1]["assistant_message"]["text"]
assert "Let me transfer you." in assistant_text
@ -342,6 +388,21 @@ async def test_text_chat_executes_deferred_tool_calls_after_text_response(
and event["payload"]["function_name"] == "go_to_agent_one"
for event in payload["session_data"]["turns"][1]["events"]
)
node_transition_names = [
event["payload"]["node_name"]
for event in run_payload["logs"]["realtime_feedback_events"]
if event["type"] == "rtf-node-transition"
]
assert node_transition_names == ["Start", "Agent One"]
function_call_event_names = [
event["type"]
for event in run_payload["logs"]["realtime_feedback_events"]
if event["type"] in {"rtf-function-call-start", "rtf-function-call-end"}
]
assert function_call_event_names == [
"rtf-function-call-start",
"rtf-function-call-end",
]
@pytest.mark.asyncio
@ -773,6 +834,11 @@ async def test_text_chat_rewind_reuses_checkpoint_snapshot(
assert rewind_response.status_code == 200
rewound = rewind_response.json()
assert rewound["session_data"]["cursor_turn_id"] == first_turn_id
rewound_run_response = await client.get(
f"/api/v1/workflow/{workflow.id}/runs/{session['workflow_run_id']}"
)
assert rewound_run_response.status_code == 200
rewound_run_payload = rewound_run_response.json()
third_message = await client.post(
f"/api/v1/workflow/{workflow.id}/text-chat/sessions/{session['workflow_run_id']}/messages",
@ -782,6 +848,11 @@ async def test_text_chat_rewind_reuses_checkpoint_snapshot(
},
)
assert third_message.status_code == 200
final_run_response = await client.get(
f"/api/v1/workflow/{workflow.id}/runs/{session['workflow_run_id']}"
)
assert final_run_response.status_code == 200
final_run_payload = final_run_response.json()
payload = third_message.json()
assert payload["checkpoint"]["current_node_id"] == "agent1"
@ -792,6 +863,24 @@ async def test_text_chat_rewind_reuses_checkpoint_snapshot(
payload["session_data"]["turns"][2]["assistant_message"]["text"]
== "Back in agent one."
)
assert _log_texts(rewound_run_payload["logs"], "rtf-user-transcription") == [
"First turn"
]
assert "Second turn" not in _log_texts(
rewound_run_payload["logs"], "rtf-user-transcription"
)
assert "Agent two here." not in _log_texts(
rewound_run_payload["logs"], "rtf-bot-text"
)
assert _log_texts(final_run_payload["logs"], "rtf-user-transcription") == [
"First turn",
"Third turn after rewind",
]
assert _log_texts(final_run_payload["logs"], "rtf-bot-text") == [
"Welcome to the rewind test.",
"Agent one here.",
"Back in agent one.",
]
@pytest.mark.asyncio