Skip to content

Commit 56ab03c

Browse files
JetoPistolaclaude
andcommitted
fix(lifecycle): replay full create payload on finalize upsert
The real-Opik E2E caught an NA-trace regression: the finalize upsert re-sent only id+output+end_time. But client.trace(id=...) builds a full CreateTraceMessage — the omitted name/thread_id/input went as null and the backend's last-write-wins merge clobbered the create, landing an NA trace (name=None/thread_id=None). start_time also drifted to a fresh now(). The SDK's own Trace.update() docstring documents the fix: re-send the FULL payload with the same id. So capture the create kwargs on TraceState (pinning start_time) and replay them + output/end_time on both the finish and eviction re-sends. Also made the mock-Opik journal assertion faithful to real Opik (last-write-wins including nulls) so the cheaper per-PR E2E now reproduces and catches this NA regression, and added unit guards asserting the finalize re-send carries name/thread_id/input and the create's start_time. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent 6599ac0 commit 56ab03c

5 files changed

Lines changed: 88 additions & 28 deletions

File tree

e2e/assert_journal.py

Lines changed: 20 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -53,17 +53,16 @@ def main() -> None:
5353
updates.append(r.get("payload"))
5454

5555
# Upsert-only lifecycle: the create and the finalize arrive as two SEPARATE
56-
# trace-batch rows sharing one id (create carries name/thread/input; finalize
57-
# carries output/end_time). Merge by id so the checks below see the coalesced
58-
# trace, exactly as real Opik would store it.
56+
# trace-batch rows sharing one id. Merge by id, mimicking real Opik's
57+
# last-write-wins — a key present in a later row overwrites earlier, INCLUDING
58+
# nulls. This reproduces the OPIK-7279 first-attempt NA-trace bug: a finalize
59+
# re-send that omits name/thread_id sends them as null and clobbers the
60+
# create. The finalize must therefore replay the full create payload.
5961
merged: dict = {}
6062
for t in traces:
6163
tid = t.get("id")
62-
if tid is None:
63-
merged.setdefault(id(t), {}).update(t)
64-
else:
65-
slot = merged.setdefault(tid, {})
66-
slot.update({k: v for k, v in t.items() if v is not None})
64+
key = tid if tid is not None else id(t)
65+
merged.setdefault(key, {}).update(t)
6766
merged_traces = list(merged.values())
6867

6968
print(
@@ -84,15 +83,22 @@ def main() -> None:
8483
"upsert-only (same-id re-send), never trace.update()/end()"
8584
)
8685

87-
# 1. A root trace exists and is named (descriptive or the fallback).
86+
# 1. A root trace exists and, after the finalize re-send merges in, still
87+
# carries name + thread_id (not clobbered to an NA trace) AND the finished
88+
# payload (output + end_time). This is the full OPIK-7279 acceptance shape.
8889
if not merged_traces:
8990
errors.append("no traces captured")
9091
else:
91-
names = [t.get("name") for t in merged_traces]
92-
if not any(n for n in names):
93-
errors.append(f"trace(s) have no name: {names}")
94-
# 1b. The finalize re-send landed: the trace carries output + end_time
95-
# (acceptance criteria — the trace still finalizes correctly).
92+
if not any(t.get("name") for t in merged_traces):
93+
errors.append(
94+
"no trace has a name after merge (NA trace — finalize re-send "
95+
"clobbered it; it must replay the full create payload)"
96+
)
97+
if not any(t.get("thread_id") for t in merged_traces):
98+
errors.append(
99+
"no trace has a thread_id after merge (session grouping lost — "
100+
"finalize re-send must replay thread_id)"
101+
)
96102
if not any(t.get("output") for t in merged_traces):
97103
errors.append("no trace carries output (finalize re-send missing)")
98104
if not any(t.get("end_time") for t in merged_traces):

observability/opik/lifecycle.py

Lines changed: 29 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -42,22 +42,31 @@ def start_root_trace(
4242
"model": model,
4343
"api_mode": api_mode,
4444
}
45-
trace = client.trace(
46-
name=trace_name_from_messages(messages) or "Hermes turn",
47-
project_name=project_name(),
48-
thread_id=session_id or None,
49-
input=trace_input,
50-
metadata=metadata,
51-
tags=tags(),
52-
)
45+
# Build the create payload once and keep it: the finalize/eviction re-send
46+
# (upsert via client.trace(id=...)) must replay this FULL payload, not just
47+
# output+end_time. An upsert is a whole CreateTraceMessage — any omitted
48+
# field is sent as null and the backend's last-write-wins merge clobbers the
49+
# create (name/thread_id -> NA trace). start_time is pinned here so the
50+
# re-send carries the same value instead of a fresh now() (the SDK defaults
51+
# start_time to now on every client.trace() call).
52+
create_kwargs: dict[str, Any] = {
53+
"name": trace_name_from_messages(messages) or "Hermes turn",
54+
"project_name": project_name(),
55+
"thread_id": session_id or None,
56+
"input": trace_input,
57+
"metadata": metadata,
58+
"tags": tags(),
59+
"start_time": datetime.datetime.now(datetime.timezone.utc),
60+
}
61+
trace = client.trace(**create_kwargs)
5362
# NOTE: the caller flushes this create (via flush_trace_create) AFTER
5463
# releasing the state lock. name/thread_id/input are set only at creation, so
5564
# the create must not coalesce with the turn's later finalize re-send in one
5665
# batch window (a fast turn) or the trace lands NA (name=None/thread=None/
5766
# input=null) — the trace-level twin of the span NA-bug. flush() blocks on
5867
# the network, so it is deliberately kept out of the lock.
5968
debug(f"started trace {trace.id} for {task_key}")
60-
return TraceState(trace=trace, session_id=session_id)
69+
return TraceState(trace=trace, session_id=session_id, create_kwargs=create_kwargs)
6170

6271

6372
def flush_trace_create(client: Any) -> None:
@@ -100,18 +109,24 @@ def finish_trace(task_key: str, *, output: Any = None) -> None:
100109
# so we simply drop them rather than emit a partial span.
101110
#
102111
# Upsert-only finalize: re-send the SAME trace id with the finished
103-
# payload (output + end_time) instead of trace.update()/trace.end(). The
104-
# SDK's batching layer coalesces this with the create into one final row.
105-
# An update() shortly after create trips the "may cause data loss"
106-
# warning; the upsert is the mandated pattern and avoids it. name/
107-
# thread_id/input were flushed with the create, so they are not re-sent.
112+
# payload instead of trace.update()/trace.end(). The SDK's batching layer
113+
# coalesces this with the create into one final row. An update() shortly
114+
# after create trips the "may cause data loss" warning; the upsert is the
115+
# mandated pattern and avoids it.
116+
#
117+
# Replay the FULL create payload (name/thread_id/input/start_time/...)
118+
# plus output+end_time — NOT just output+end_time. An upsert is a whole
119+
# CreateTraceMessage; omitted fields go as null and the backend's
120+
# last-write-wins merge would clobber the create, landing an NA trace
121+
# (name=None/thread_id=None). See TraceState.create_kwargs.
108122
final_output = merge_trace_output(output, state)
109123
client.trace(
110124
id=state.trace.id,
111125
output=final_output
112126
if final_output is None or isinstance(final_output, dict)
113127
else {"content": final_output},
114128
end_time=datetime.datetime.now(datetime.timezone.utc),
129+
**state.create_kwargs,
115130
)
116131
except Exception as exc: # pragma: no cover - fail-open
117132
debug(f"finish trace failed: {exc}")

observability/opik/state.py

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -70,6 +70,14 @@ class PendingGeneration:
7070
class TraceState:
7171
trace: Any
7272
session_id: str = ""
73+
# The exact kwargs the trace was CREATED with (name, project_name,
74+
# thread_id, input, metadata, tags, start_time). The finalize/eviction
75+
# re-send replays them verbatim + output/end_time: an upsert via
76+
# client.trace(id=...) is a full CreateTraceMessage, so any field omitted
77+
# goes as null and the backend's last-write-wins merge would clobber the
78+
# create (name/thread_id -> NA trace). Re-sending the full payload keeps
79+
# them. See lifecycle.finish_trace.
80+
create_kwargs: Dict[str, Any] = field(default_factory=dict)
7381
generations: Dict[str, PendingGeneration] = field(default_factory=dict)
7482
tools: Dict[str, PendingTool] = field(default_factory=dict)
7583
pending_tools_by_name: Dict[str, list] = field(default_factory=dict)
@@ -141,9 +149,14 @@ def evict_stale_locked() -> None:
141149
if client is None:
142150
continue
143151
try:
152+
# Replay the full create payload + end_time (not a bare id+end_time):
153+
# an upsert is a whole CreateTraceMessage, so omitting name/thread_id
154+
# sends them as null and clobbers the create -> NA trace. See
155+
# TraceState.create_kwargs and lifecycle.finish_trace.
144156
client.trace(
145157
id=state.trace.id,
146158
end_time=datetime.datetime.now(datetime.timezone.utc),
159+
**state.create_kwargs,
147160
)
148161
except Exception as exc: # pragma: no cover - fail-open
149162
debug(f"evict stale trace failed: {exc}")

tests/test_keying_eviction.py

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -48,4 +48,8 @@ def test_lru_eviction_bounds_state_and_finalizes_evicted_trace(plugin):
4848
finalized = [t for t in plugin._fake.traces if t.finalized]
4949
assert len(finalized) >= 5
5050
assert all(t.finalize_kwargs.get("end_time") is not None for t in finalized)
51+
# The eviction re-send replays the full create payload (name/thread_id), so
52+
# the evicted trace isn't clobbered to an NA trace — same fix as finish.
53+
assert all(t.finalize_kwargs.get("name") for t in finalized)
54+
assert all(t.finalize_kwargs.get("thread_id") == "s" for t in finalized)
5155
assert not any(e[0] in ("trace.update", "trace.end") for e in plugin._fake.events)

tests/test_lifecycle.py

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -141,6 +141,28 @@ def test_post_llm_call_finalizes_and_flushes_trace(plugin):
141141
)
142142

143143

144+
def test_finalize_resend_replays_full_create_payload(plugin):
145+
# Regression (OPIK-7279 first attempt): the finalize upsert must replay the
146+
# FULL create payload (name/thread_id/input/start_time), not just
147+
# output+end_time. An upsert is a whole CreateTraceMessage — a partial
148+
# re-send sends the omitted fields as null and the backend's last-write-wins
149+
# merge clobbers the create, landing an NA trace (name=None/thread_id=None).
150+
# Verified against real Opik: a partial re-send nulled name+thread_id.
151+
_run_turn_with_tool(plugin, finalize=True)
152+
fk = plugin._fake.traces[0].finalize_kwargs
153+
assert fk.get("name"), "finalize re-send must carry name (else NA trace)"
154+
assert fk.get("thread_id") == "s", "finalize re-send must carry thread_id"
155+
assert fk.get("input") is not None, "finalize re-send must carry input"
156+
assert fk.get("start_time") is not None, (
157+
"finalize re-send must carry the create's start_time, not a fresh now()"
158+
)
159+
# And it must be the SAME start_time the trace was created with.
160+
ck = plugin._fake.traces[0].create_kwargs
161+
assert fk.get("start_time") == ck.get("start_time"), (
162+
"finalize start_time must match the create's, not drift to now()"
163+
)
164+
165+
144166
def test_finalize_is_upsert_not_update_or_end(plugin):
145167
# Upsert-only: finalize must be a same-id client.trace(...) re-send, never
146168
# trace.update()/trace.end() (FakeTrace raises on those). The re-send targets

0 commit comments

Comments
 (0)