Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
119 changes: 111 additions & 8 deletions crates/tinymemory-integrations/examples/memory_eval/agent.rs
Original file line number Diff line number Diff line change
Expand Up @@ -15,11 +15,17 @@
//! The extractive answer is a stand-in for a model reading the pack. It
//! scores what a model would see, not how well some model reasons.

use std::time::Instant;
use std::collections::HashSet;
use std::time::{Duration as StdDuration, Instant};

use chrono::{DateTime, Duration, Utc};
use tinymemory_api::ToolCallRef;
use tinymemory_tools::{AgentMemory, BackgroundJob, ContextPack, PostTurn, PreTurn};
use tinymemory_api::{Error, ToolCallRef};
use tinymemory_tools::{AgentMemory, BackgroundJob, PostTurn, PreTurn, TurnContext};

/// OpenHuman's default deadline for the pack before a model turn.
pub(crate) const PRE_TURN_TIMEOUT: StdDuration = StdDuration::from_millis(1_500);
/// OpenHuman's maximum length of one logged tool result.
const MAX_TOOL_LINE_CHARS: usize = 240;

/// A scripted tool call and the result the "tool" returns.
#[derive(Debug, Clone, Copy)]
Expand All @@ -39,6 +45,14 @@ pub(crate) struct TurnRecord {
pub(crate) post_ms: f64,
/// Whether the user turn was logged.
pub(crate) logged: bool,
/// Whether OpenHuman would have continued with an empty pack.
pub(crate) timed_out: bool,
/// Tokens in the pack injected into the simulated model prompt.
pub(crate) pack_tokens: usize,
/// Repeated bullet lines in the injected pack.
pub(crate) duplicate_lines: usize,
/// Bullet lines in the injected pack.
pub(crate) pack_lines: usize,
/// The jobs `post_turn` handed back.
pub(crate) jobs: Vec<BackgroundJob>,
/// How many tool calls the reply made.
Expand All @@ -53,6 +67,8 @@ pub(crate) struct ScriptedAgent {
/// How many of the thread's turns stay in the prompt.
window: u32,
clock: Option<DateTime<Utc>>,
openhuman: bool,
pending: Vec<tokio::task::JoinHandle<Result<TurnContext, Error>>>,
}

impl ScriptedAgent {
Expand All @@ -65,7 +81,28 @@ impl ScriptedAgent {
next: 0,
window,
clock: None,
openhuman: false,
pending: Vec::new(),
}
}

/// Mirror OpenHuman's dated hook, deadline, and reply logging.
pub(crate) fn openhuman(mut self) -> Self {
self.openhuman = true;
self
}

/// Wait for pre-turn tasks whose host deadline expired. OpenHuman leaves

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

priority medium tests likely

Test the pre-turn timeout and flush path, not only the on-time path

The docs (openhuman-host.md) and the code comments claim a timed-out task keeps running and can still log the user turn, and timed_out: context.is_none() plus flush() exist to model that. The new agent_tests.rs only covers the on-time path (assert!(!record.timed_out)); the timeout branch and flush are never executed by any test, so if the pending-task bookkeeping regressed (e.g. flush stopped counting logs, or timed-out turns were dropped instead of logged) nothing would fail. Add a test that forces the 1500 ms deadline to expire — e.g. by using an engine whose pre_turn_dated is delayed beyond PRE_TURN_TIMEOUT (the constant is pub(crate), so a test-shorter deadline is also possible) — and asserts record.timed_out is true and flush() returns the late-logged count.

[RULE] untested-invariant ·

/// those tasks running, so their accepted user turns may still land.
pub(crate) async fn flush(&mut self) -> Result<usize, Error> {
let mut logged = 0;
for task in self.pending.drain(..) {

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

priority medium critique confident

Retain pending tasks when flushing encounters an error

If any drained task returns a JoinError or an inner pre-turn error, ? exits the loop immediately. The remaining JoinHandles have already been removed from self.pending; dropping Tokio join handles detaches those tasks rather than cancelling them, so they can continue writing memory after flush has reported failure and can never be observed by a later flush. Await all tasks while retaining or aggregating errors, or restore unprocessed handles to self.pending before returning.

[RULE] unobserved-background-task ·

let context = task
.await
.map_err(|error| Error::Unavailable(format!("pre-turn task failed: {error}")))??;
logged += usize::from(context.logged.is_some());
}
Ok(logged)
}

/// Timestamps the thread's turns from `at`, a minute apart.
Expand Down Expand Up @@ -97,10 +134,46 @@ impl ScriptedAgent {
pre.in_prompt_from = self.in_prompt_from();
pre.at = self.tick();
let started = Instant::now();
let context = self.memory.pre_turn(pre).await?;
let context = if self.openhuman {
let memory = self.memory.clone();
let mut task =
tokio::spawn(
async move { memory.pre_turn_dated(pre, false, async { None }).await },
);
match tokio::time::timeout(PRE_TURN_TIMEOUT, &mut task).await {

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

priority medium critique confident

Reserve the turn index before allowing timed-out tasks to overlap

When this timeout branch stores the still-running task and returns, self.next is not advanced until the later post_turn completes. If the caller starts another user call before the pending task finishes, that call constructs another PreTurn with the same turn index and can log concurrently with the first task. The resulting conversation can contain duplicate user-turn indices and assistant logging in the wrong order. Reserve/increment the turn position before launching or accepting an overlapping turn, or serialize subsequent turns until the pending pre-turn has committed.

[RULE] concurrent-turn-ordering ·

Ok(result) => Some(result.map_err(|error| {
Error::Unavailable(format!("pre-turn task failed: {error}"))
})??),
Err(_) => {
self.pending.push(task);
None
}
}
} else {
Some(self.memory.pre_turn(pre).await?)
};
let pre_ms = ms(started);

let reply = reply(&context.pack, text, tools);
let markdown = context
.as_ref()
.map_or("", |value| value.pack.markdown.as_str());
let mut seen = HashSet::new();
let lines: Vec<&str> = markdown
.lines()
.filter(|line| line.starts_with("- "))
.collect();
let duplicate_lines = lines.iter().filter(|line| !seen.insert(**line)).count();
let prompt = if self.openhuman && !markdown.is_empty() {
format!("<memory-context>\n{markdown}\n</memory-context>\n\n{text}")
} else {
markdown.to_string()
};
let answer = reply(&prompt, text, if self.openhuman { &[] } else { tools });
let reply = if self.openhuman {
logged_reply(&answer, tools)
} else {
answer
};
let mut post = PostTurn::new(&self.thread, self.next + 1, reply);
post.tool_calls = tools
.iter()
Expand All @@ -118,7 +191,11 @@ impl ScriptedAgent {
Ok(TurnRecord {
pre_ms,
post_ms,
logged: context.logged.is_some(),
logged: context.as_ref().is_some_and(|value| value.logged.is_some()),
timed_out: context.is_none(),
pack_tokens: context.as_ref().map_or(0, |value| value.pack.tokens),
duplicate_lines,
pack_lines: lines.len(),
jobs: report.jobs,
tool_calls: tools.len(),
})
Expand All @@ -127,13 +204,13 @@ impl ScriptedAgent {

/// The agent's reply: tool results first, then an answer or an
/// acknowledgement.
fn reply(pack: &ContextPack, text: &str, tools: &[ToolStep]) -> String {
fn reply(markdown: &str, text: &str, tools: &[ToolStep]) -> String {
let mut lines: Vec<String> = tools
.iter()
.map(|step| format!("{} returned: {}", step.name, step.result))
.collect();
if text.trim_end().ends_with('?') {
lines.push(match answer(&pack.markdown, text) {
lines.push(match answer(markdown, text) {
Some(line) => format!("Going by memory: {line}"),
None => NOT_IN_MEMORY.to_string(),
});
Expand All @@ -143,6 +220,28 @@ fn reply(pack: &ContextPack, text: &str, tools: &[ToolStep]) -> String {
lines.join("\n")
}

/// The reply OpenHuman stores: the model's text and bounded tool-result lines.
fn logged_reply(text: &str, tools: &[ToolStep]) -> String {
let lines: Vec<String> = tools
.iter()
.filter_map(|step| {
let result = step.result.split_whitespace().collect::<Vec<_>>().join(" ");
(!result.is_empty()).then(|| {
format!(
"- {} → {}",
step.name,
result.chars().take(MAX_TOOL_LINE_CHARS).collect::<String>()
)
})
})
.collect();
if lines.is_empty() {
text.trim().to_string()
} else {
format!("{}\n\nTools:\n{}", text.trim(), lines.join("\n"))
}
}

/// The agent's reply when nothing in the pack answers.
const NOT_IN_MEMORY: &str = "I don't have that in memory.";

Expand Down Expand Up @@ -189,3 +288,7 @@ pub(crate) fn answer(markdown: &str, question: &str) -> Option<String> {
pub(crate) fn ms(started: Instant) -> f64 {
started.elapsed().as_secs_f64() * 1e3
}

#[cfg(test)]
#[path = "agent_tests.rs"]
mod tests;
87 changes: 87 additions & 0 deletions crates/tinymemory-integrations/examples/memory_eval/agent_tests.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,87 @@
//! Regression coverage for the OpenHuman turn mirror.

use super::*;
use std::sync::Arc;
use tinymemory_api::conformance::ReferenceEngine;
use tinymemory_api::{LearningKind, ListRequest, MemoryEngine, MemoryMeta, StoreItem};
use tinymemory_tools::MemoryLayout;

#[test]
fn logged_reply_keeps_bounded_tool_results() {
let long = "a".repeat(MAX_TOOL_LINE_CHARS + 20);
let result = logged_reply(
" Done. ",
&[
ToolStep {
name: "read",
result: "file contents\n changed",
},
ToolStep {
name: "empty",
result: " ",
},
],
);
assert_eq!(result, "Done.\n\nTools:\n- read → file contents changed");
assert_eq!(
logged_reply(
"Done.",
&[ToolStep {
name: "read",
result: Box::leak(long.into_boxed_str())
}]
)
.lines()
.last()
.unwrap()
.chars()
.count(),
"- read → ".chars().count() + MAX_TOOL_LINE_CHARS
);
}

#[tokio::test]
async fn openhuman_turn_logs_tool_result_without_echoing_the_pack() {
let engine = Arc::new(ReferenceEngine::new());
let layout = MemoryLayout::default();
engine
.store(StoreItem::learning(
"The release word is copper-lantern.",
LearningKind::Fact,
1.0,
MemoryMeta {
namespace: layout.learnings().clone(),
..MemoryMeta::default()
},
))
.await
.unwrap();
let memory = AgentMemory::new(engine.clone(), layout.clone(), "agent")
.unwrap()
.with_policy(crate::RecallPolicy {
team_limit: 0,
..crate::RecallPolicy::default()
});
let mut agent = ScriptedAgent::new(memory, "thread", 8).openhuman();
let record = agent
.user(
"What is the release word?",
&[ToolStep {
name: "read_file",
result: "retry logic is in src/retry.rs",
}],
)
.await
.unwrap();
assert!(!record.timed_out);
assert!(record.logged);
assert!(record.pack_tokens > 0);

let exported = engine
.export(ListRequest::new(layout.holistic_filter(), 100))
.await
.unwrap();
let stored = serde_json::to_string(&exported.items).unwrap();
assert!(stored.contains("read_file → retry logic is in src/retry.rs"));
assert!(!stored.contains("<memory-context>"));
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
{
"turns": 500,
"user_text": "Continue the coding session.",
"learning": "The project release word is copper-lantern."
}
25 changes: 25 additions & 0 deletions crates/tinymemory-integrations/examples/memory_eval/kpi.rs
Original file line number Diff line number Diff line change
Expand Up @@ -455,6 +455,17 @@ pub(crate) fn compute(
.collect()
};
let pre_turn = Latency::of(&samples(&|step| step.starts_with("pre_turn")));
let pre_turn_timeouts = reports.iter().map(|r| r.pre_turn_timeouts).sum::<usize>()
+ reports
.iter()
.flat_map(|r| &r.probes)
.filter(|probe| probe.timed_out)
.count();
Comment on lines +461 to +463

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

priority medium critique confident

Count timeouts only for pre-turn probes

The denominator below counts only probes whose via starts with pre_turn, but this numerator counts every timed-out probe. If a non-pre-turn probe times out, it increases the numerator without increasing the denominator, producing an incorrect rate or even a value above 100%. Apply the same via filter when counting timed-out probes.

Suggested change
.flat_map(|r| &r.probes)
.filter(|probe| probe.timed_out)
.count();
.flat_map(|r| &r.probes)
.filter(|probe| probe.via.starts_with("pre_turn") && probe.timed_out)
.count();

[RULE] inconsistent-filtering ·

let probe_pre_turns = reports
.iter()
.flat_map(|r| &r.probes)
.filter(|probe| probe.via.starts_with("pre_turn"))
.count();
let probe = Latency::of(&samples(&|step| step.starts_with("probe ")));
let total = |step: &str| {
timings
Expand All @@ -477,6 +488,20 @@ pub(crate) fn compute(
Unit::Ms,
Lower,
),
Kpi::new(
"latency",
"pre_turn p99",
(pre_turn.n > 0).then_some(pre_turn.p99),
Unit::Ms,
Lower,
),
Kpi::rate(
"latency",
"pre_turn timeout rate",
pre_turn_timeouts,
pre_turn.n + probe_pre_turns,
Lower,
),
Kpi::new(
"latency",
"probe p50",
Expand Down
15 changes: 15 additions & 0 deletions crates/tinymemory-integrations/examples/memory_eval/kpi_tests.rs
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ fn report(name: &'static str, probes: Vec<ProbeResult>, conflicts: &[&str]) -> S
about: "",
writes: 0,
tool_calls: 0,
pre_turn_timeouts: 0,
settle_ms: 0.0,
synthesis: Synthesis {
captured: Captured {
Expand Down Expand Up @@ -173,6 +174,20 @@ fn latency_reads_the_pre_turn_and_probe_samples() {
assert_eq!(value(&kpis, "pack hit"), None);
}

#[test]
fn timeout_rate_counts_scripted_turns_and_probe_turns() {
let mut timed_out = probed("brain_lookup", "recall", false);
timed_out.timed_out = true;
let on_time = probed("brain_lookup", "synthesis", true);
let mut report = report("brain_lookup", vec![timed_out, on_time], &[]);
report.pre_turn_timeouts = 1;
let mut timings = Timings::default();
timings.add("pre_turn (log + recall)", 1_500.0);
timings.add("pre_turn (log + recall)", 200.0);
let kpis = compute(&[report], None, &timings);
assert_eq!(value(&kpis, "pre_turn timeout rate"), Some(50.0));
}

#[test]
fn values_format_by_unit() {
assert_eq!(format(62.4, Unit::Pct), "62%");
Expand Down
Loading
Loading