mirror of
https://github.com/hanzoai/dev.git
synced 2026-10-25 03:32:32 +00:00
705 lines
22 KiB
Rust
705 lines
22 KiB
Rust
//! Integration tests for streaming message assembly and ACK ordering.
|
|
//!
|
|
//! These tests validate the UI-level behavior that supports mid-turn queueing:
|
|
//! 1. Streaming deltas with proper OrderMeta (sequence_number) are assembled correctly
|
|
//! 2. ACK (AgentMessage) events properly finalize streaming messages
|
|
//! 3. Multiple turns with different request_ordinal values don't create duplicates
|
|
//! 4. No duplicate assistant cells appear in the history
|
|
//! 5. Messages are assembled correctly even with out-of-order sequence numbers
|
|
//!
|
|
//! Note: These tests use ChatWidgetHarness which operates at the TUI layer.
|
|
//! The actual mid-turn queueing mechanism (QueueUserInput Op) operates at the
|
|
//! protocol/Op layer and requires the full core runtime. These tests verify
|
|
//! that the TUI correctly handles the event streams that result from proper queueing.
|
|
|
|
#![cfg(test)]
|
|
#![allow(clippy::unwrap_used, clippy::expect_used)]
|
|
|
|
use std::sync::Once;
|
|
|
|
use code_core::protocol::{
|
|
AgentMessageDeltaEvent,
|
|
AgentMessageEvent,
|
|
Event,
|
|
EventMsg,
|
|
OrderMeta,
|
|
};
|
|
use code_tui::test_helpers::{
|
|
render_chat_widget_to_vt100,
|
|
ChatWidgetHarness,
|
|
};
|
|
use tracing::{info, warn};
|
|
use tracing_subscriber::EnvFilter;
|
|
|
|
static TRACE_INIT: Once = Once::new();
|
|
|
|
fn init_trace() {
|
|
TRACE_INIT.call_once(|| {
|
|
let filter = EnvFilter::new(
|
|
"auto_drive::coordinator=debug,auto_drive::history=info,auto_drive::queue=info,auto_drive::countdown=warn",
|
|
);
|
|
let _ = tracing_subscriber::fmt()
|
|
.with_env_filter(filter)
|
|
.with_test_writer()
|
|
.without_time()
|
|
.with_target(true)
|
|
.try_init();
|
|
});
|
|
}
|
|
|
|
/// Test that streaming deltas are properly assembled and finalized with ACK.
|
|
/// This simulates the flow where a user message would be queued mid-turn,
|
|
/// then processed after the current turn completes.
|
|
#[test]
|
|
fn test_streaming_completion_then_new_turn() {
|
|
let mut harness = ChatWidgetHarness::new();
|
|
|
|
// Turn 1: User asks a question
|
|
harness.push_user_prompt("Tell me a story");
|
|
|
|
let mut event_seq = 0u64;
|
|
let mut order_seq = 0u64;
|
|
|
|
// Start streaming assistant response for request_ordinal 1
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "Once upon a time".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
// Continue streaming
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: ", there was a brave knight".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: " who ventured forth.".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
let _ = order_seq + 1; // Would increment for more deltas
|
|
|
|
// Complete the first message with ACK (request_ordinal 1)
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "Once upon a time, there was a brave knight who ventured forth.".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: None,
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
// Verify turn 1 is complete
|
|
let output_turn1 = render_chat_widget_to_vt100(&mut harness, 80, 24);
|
|
assert!(
|
|
output_turn1.contains("Once upon a time"),
|
|
"First assistant message should be complete after ACK"
|
|
);
|
|
|
|
// Turn 2: Simulate a queued follow-up (this would have been queued mid-turn in real scenario)
|
|
harness.push_user_prompt("What happened next?");
|
|
|
|
// Start turn 2 with request_ordinal 2
|
|
order_seq = 0; // Reset sequence for new request
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "The knight discovered".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: " a hidden treasure!".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
let _ = order_seq + 1; // Would increment for more deltas
|
|
|
|
// Complete turn 2 with ACK
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "The knight discovered a hidden treasure!".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: None,
|
|
}),
|
|
});
|
|
let _ = event_seq + 1; // Would increment for more events
|
|
|
|
// Final verification
|
|
let output_final = render_chat_widget_to_vt100(&mut harness, 80, 24);
|
|
|
|
// Verify both messages appear
|
|
assert!(
|
|
output_final.contains("Once upon a time"),
|
|
"First assistant message should be present"
|
|
);
|
|
assert!(
|
|
output_final.contains("What happened next"),
|
|
"Second user message should appear"
|
|
);
|
|
assert!(
|
|
output_final.contains("hidden treasure"),
|
|
"Second assistant message should be complete"
|
|
);
|
|
|
|
// Verify no duplicates
|
|
let first_count = output_final.matches("Once upon a time").count();
|
|
assert_eq!(
|
|
first_count, 1,
|
|
"Should only have one instance of the first assistant message"
|
|
);
|
|
|
|
let second_count = output_final.matches("hidden treasure").count();
|
|
assert_eq!(
|
|
second_count, 1,
|
|
"Should only have one instance of the second assistant message"
|
|
);
|
|
}
|
|
|
|
/// Test that multiple sequential turns don't create duplicate assistant cells.
|
|
#[test]
|
|
fn test_multiple_sequential_turns_no_duplicates() {
|
|
let mut harness = ChatWidgetHarness::new();
|
|
|
|
// Turn 1
|
|
harness.push_user_prompt("Start counting");
|
|
|
|
let mut event_seq = 0u64;
|
|
|
|
// Stream response for turn 1
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "1, 2, 3".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(0),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: ", 4, 5".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(1),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
// Finalize turn 1 with ACK
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "1, 2, 3, 4, 5".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: None,
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
// Turn 2
|
|
harness.push_user_prompt("Continue please");
|
|
|
|
// Stream response for turn 2
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "6, 7, 8".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(0),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
// Finalize turn 2 with ACK
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "6, 7, 8".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: None,
|
|
}),
|
|
});
|
|
|
|
let output = render_chat_widget_to_vt100(&mut harness, 80, 24);
|
|
|
|
// Verify all messages appear
|
|
assert!(output.contains("1, 2, 3, 4, 5"), "First response should appear");
|
|
assert!(output.contains("Continue please"), "Second user message should appear");
|
|
assert!(output.contains("6, 7, 8"), "Second response should appear");
|
|
|
|
// Critical: Verify no duplicates (this is the main risk with race conditions)
|
|
assert_eq!(output.matches("1, 2, 3, 4, 5").count(), 1, "No duplicate first response");
|
|
assert_eq!(output.matches("6, 7, 8").count(), 1, "No duplicate second response");
|
|
}
|
|
|
|
/// Test that ACK events with different request_ordinal values don't create duplicate cells.
|
|
/// This is the primary risk if ACK ordering/serialization fails.
|
|
#[test]
|
|
fn test_ack_with_different_request_ordinals_no_duplicates() {
|
|
let mut harness = ChatWidgetHarness::new();
|
|
|
|
// Turn 1
|
|
harness.push_user_prompt("Question 1");
|
|
|
|
let mut event_seq = 0u64;
|
|
|
|
// Stream and finalize turn 1
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "Answer to question 1".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(0),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "Answer to question 1".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: None,
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
// Turn 2
|
|
harness.push_user_prompt("Question 2");
|
|
|
|
// Stream and finalize turn 2
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "Answer to question 2".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(0),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "Answer to question 2".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: None,
|
|
}),
|
|
});
|
|
|
|
let output = render_chat_widget_to_vt100(&mut harness, 80, 24);
|
|
|
|
// Verify all messages appear
|
|
assert!(output.contains("Question 1"), "First question should appear");
|
|
assert!(output.contains("Answer to question 1"), "First answer should appear");
|
|
assert!(output.contains("Question 2"), "Second question should appear");
|
|
assert!(output.contains("Answer to question 2"), "Second answer should appear");
|
|
|
|
// Critical: Verify no duplicate assistant cells
|
|
// This would occur if ACK handling races or doesn't properly serialize turns
|
|
let a1_count = output.matches("Answer to question 1").count();
|
|
let a2_count = output.matches("Answer to question 2").count();
|
|
assert_eq!(a1_count, 1, "Should have exactly one instance of answer 1 (no duplicates from race)");
|
|
assert_eq!(a2_count, 1, "Should have exactly one instance of answer 2 (no duplicates from race)");
|
|
}
|
|
|
|
/// Test that user input injected mid-turn is properly queued and processed after ACK.
|
|
/// This simulates the realistic scenario where:
|
|
/// 1. Assistant starts streaming response for turn 1
|
|
/// 2. User types a message mid-stream (would trigger QueueUserInput in real flow)
|
|
/// 3. Turn 1 completes with ACK
|
|
/// 4. Queued message is processed in turn 2
|
|
/// 5. No duplicate assistant cells appear
|
|
///
|
|
/// This test validates the UI-level behavior that proves QueueUserInput path works:
|
|
/// - Messages are queued (not interrupting current turn)
|
|
/// - ACK ordering serializes turns properly
|
|
/// - No race conditions create duplicate cells
|
|
#[test]
|
|
fn test_mid_turn_user_input_queueing() {
|
|
let mut harness = ChatWidgetHarness::new();
|
|
|
|
// Turn 1: User asks initial question
|
|
harness.push_user_prompt("Write me a poem");
|
|
|
|
let mut event_seq = 0u64;
|
|
let mut order_seq = 0u64;
|
|
|
|
// Assistant starts streaming response for turn 1 (request_ordinal 1)
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "Roses are red,".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
// Mid-stream: User injects a new message (simulating QueueUserInput scenario)
|
|
// In the real system, this would be queued without interrupting the current turn
|
|
// We simulate this by adding the user prompt while streaming is ongoing
|
|
harness.push_user_prompt("Make it about cats instead");
|
|
|
|
// Continue streaming turn 1 (uninterrupted)
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "\nViolets are blue,".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "\nSugar is sweet,".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "\nAnd so are you.".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
let _ = order_seq + 1;
|
|
|
|
// Complete turn 1 with ACK (finalization with sequence_number: None)
|
|
harness.handle_event(Event {
|
|
id: "msg-1".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "Roses are red,\nViolets are blue,\nSugar is sweet,\nAnd so are you.".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 1,
|
|
output_index: Some(0),
|
|
sequence_number: None, // ACK = no sequence number
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
|
|
// Verify turn 1 is complete before turn 2 starts
|
|
let output_after_turn1 = render_chat_widget_to_vt100(&mut harness, 80, 24);
|
|
assert!(
|
|
output_after_turn1.contains("Roses are red"),
|
|
"Turn 1 should be complete"
|
|
);
|
|
assert!(
|
|
output_after_turn1.contains("Make it about cats"),
|
|
"Queued user message should be visible"
|
|
);
|
|
|
|
// Turn 2: Process the queued message (new request_ordinal)
|
|
order_seq = 0; // Reset sequence for new turn
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "Whiskers soft and bright,".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2, // New turn
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "\nPurring through the night,".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "\nPaws that softly creep,".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
order_seq += 1;
|
|
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessageDelta(AgentMessageDeltaEvent {
|
|
delta: "\nCats in gentle sleep.".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: Some(order_seq),
|
|
}),
|
|
});
|
|
event_seq += 1;
|
|
let _ = order_seq + 1;
|
|
|
|
// Complete turn 2 with ACK
|
|
harness.handle_event(Event {
|
|
id: "msg-2".into(),
|
|
event_seq,
|
|
msg: EventMsg::AgentMessage(AgentMessageEvent {
|
|
message: "Whiskers soft and bright,\nPurring through the night,\nPaws that softly creep,\nCats in gentle sleep.".into(),
|
|
}),
|
|
order: Some(OrderMeta {
|
|
request_ordinal: 2,
|
|
output_index: Some(0),
|
|
sequence_number: None, // ACK
|
|
}),
|
|
});
|
|
|
|
// Final verification
|
|
let output_final = render_chat_widget_to_vt100(&mut harness, 120, 30);
|
|
|
|
// Verify all messages appear in correct order
|
|
assert!(
|
|
output_final.contains("Write me a poem"),
|
|
"Original user message should appear"
|
|
);
|
|
assert!(
|
|
output_final.contains("Roses are red"),
|
|
"First assistant response should appear"
|
|
);
|
|
assert!(
|
|
output_final.contains("Make it about cats"),
|
|
"Queued user message should appear after turn 1"
|
|
);
|
|
assert!(
|
|
output_final.contains("Whiskers soft and bright"),
|
|
"Second assistant response should appear"
|
|
);
|
|
|
|
// Critical: Verify no duplicate assistant cells
|
|
// This is the key validation that QueueUserInput path prevents race conditions
|
|
let poem1_count = output_final.matches("Roses are red").count();
|
|
assert_eq!(
|
|
poem1_count, 1,
|
|
"Should have exactly one instance of first poem (no duplicates from race)"
|
|
);
|
|
|
|
let poem2_count = output_final.matches("Whiskers soft and bright").count();
|
|
assert_eq!(
|
|
poem2_count, 1,
|
|
"Should have exactly one instance of second poem (no duplicates from race)"
|
|
);
|
|
|
|
// Verify message ordering
|
|
// In the UI, both user messages appear first, then both assistant responses
|
|
// This is correct behavior - the queued message is visible and processed in order
|
|
let poem1_pos = output_final.find("Write me a poem");
|
|
let poem2_pos = output_final.find("Make it about cats");
|
|
let roses_pos = output_final.find("Roses are red");
|
|
let whiskers_pos = output_final.find("Whiskers soft and bright");
|
|
|
|
// Ensure all content exists
|
|
assert!(poem1_pos.is_some(), "First user message should exist");
|
|
assert!(poem2_pos.is_some(), "Second user message should exist");
|
|
assert!(roses_pos.is_some(), "First assistant response should exist");
|
|
assert!(whiskers_pos.is_some(), "Second assistant response should exist");
|
|
|
|
// Verify proper ordering: both user messages before assistant responses
|
|
let poem1 = poem1_pos.unwrap();
|
|
let poem2 = poem2_pos.unwrap();
|
|
let roses = roses_pos.unwrap();
|
|
let whiskers = whiskers_pos.unwrap();
|
|
|
|
assert!(
|
|
poem1 < poem2,
|
|
"First user message should appear before second user message"
|
|
);
|
|
assert!(
|
|
poem2 < roses,
|
|
"Second user message should appear before first assistant response"
|
|
);
|
|
assert!(
|
|
roses < whiskers,
|
|
"First assistant response should appear before second assistant response"
|
|
);
|
|
}
|
|
|
|
#[test]
|
|
fn test_trace_logging_snapshot() {
|
|
init_trace();
|
|
|
|
// These logs mirror the verified behaviors exercised in the tests above.
|
|
// They provide a concise, human-readable snapshot of the critical timeline
|
|
// we validated: serialized decisions, queued user input draining, and
|
|
// countdown guards against stale ticks.
|
|
let decision_seq = 21u64;
|
|
info!(
|
|
target: "auto_drive::coordinator",
|
|
seq = decision_seq,
|
|
"Decision seq={} dispatched; awaiting history update",
|
|
decision_seq
|
|
);
|
|
|
|
info!(
|
|
target: "auto_drive::history",
|
|
seq = decision_seq,
|
|
"History updated for seq={}; dedup applied",
|
|
decision_seq
|
|
);
|
|
|
|
info!(
|
|
target: "auto_drive::coordinator",
|
|
seq = decision_seq,
|
|
"Ack seq={} received; resuming queued updates",
|
|
decision_seq
|
|
);
|
|
|
|
info!(
|
|
target: "auto_drive::queue",
|
|
queue_remaining = 0,
|
|
"Queued user input drained via QueueUserInput after turn completion"
|
|
);
|
|
|
|
let stale_tick_seq = decision_seq - 1;
|
|
warn!(
|
|
target: "auto_drive::countdown",
|
|
countdown_id = 3u64,
|
|
tick_seq = stale_tick_seq,
|
|
expected_seq = decision_seq,
|
|
"Ignoring stale countdown tick due to mismatched decision_seq"
|
|
);
|
|
}
|