From 845a89a5dd82c481fc2c0b2922d17223c5520c07 Mon Sep 17 00:00:00 2001 From: "Jose I. Paris" Date: Mon, 14 Sep 2026 13:49:52 +0200 Subject: [PATCH 1/4] fix(trace): stop crediting finished sessions on unrelated commits MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The Chainloop-Trace-Sessions trailer was chosen by intersecting the staged files with every ai-lines ledger on disk, with no scoping in time, branch or session liveness. Those ledgers never expire — WipeTraceDir preserves them and GCOrphans only drops one when no surviving commit references it — so a session pinned itself into the repository after its first commit and kept being stamped onto every later commit that touched any file it had ever edited. The consequences compounded downstream: a session's evidence file set comes from the diffs of the commits credited to it, so a foreign commit contributed its whole diff, and every file the session had no ranges for was reported as human-written. A single session accumulated commits from unrelated branches and surfaced on pull requests it never touched. Attribution is now consumed when it lands. Each ai-lines entry carries a recorded_at, the post-commit hook appends a consumed_by marker for the files the commit contained, and matching runs against the pending set instead of the full history. Ranges are retained for push-time enrichment, and per-file consumption keeps credit intact for a session committing its work in chunks. Entries written before recorded_at existed are never pending, so ledgers already on disk stop matching immediately. Two supporting changes: session-end now persists active: false and session-start revives it on resume, which lets a push with no commits to go on skip sessions that have ended; and GCOrphans retires sessions older than a week once everything they produced has been attested, since reachability alone never expires them. Active remains unsuitable as an attribution signal — session-end is not installed for `trace run` and never fires on SIGKILL or a closed terminal. Signed-off-by: Jose I. Paris --- app/cli/internal/trace/state/ailines.go | 93 ++++++++++- app/cli/internal/trace/state/state.go | 52 +++++- app/cli/internal/trace/state/state_test.go | 154 +++++++++++++++++ app/cli/pkg/action/trace_agent_hook.go | 32 ++++ app/cli/pkg/action/trace_agent_hook_test.go | 52 ++++++ app/cli/pkg/action/trace_hook_handler.go | 51 +++++- app/cli/pkg/action/trace_hook_handler_test.go | 155 +++++++++++++++++- 7 files changed, 567 insertions(+), 22 deletions(-) diff --git a/app/cli/internal/trace/state/ailines.go b/app/cli/internal/trace/state/ailines.go index 6c192795d..b41c872a9 100644 --- a/app/cli/internal/trace/state/ailines.go +++ b/app/cli/internal/trace/state/ailines.go @@ -30,11 +30,21 @@ import ( type AILineAttribution struct { SessionID string `json:"session_id"` Files map[string][]aicodingsession.LineRange `json:"files"` + // Pending holds the files whose recorded ranges have not been committed + // yet, and is the only set a new commit may be matched against. Files + // keeps every range ever recorded because push-time enrichment needs the + // full history, but matching against it credits a finished session on + // every later commit that happens to touch a file it once edited. + Pending map[string]struct{} `json:"-"` } -// newAILineAttribution returns an AILineAttribution with an initialized Files map. +// newAILineAttribution returns an AILineAttribution with initialized maps. func newAILineAttribution(sessionID string) *AILineAttribution { - return &AILineAttribution{SessionID: sessionID, Files: make(map[string][]aicodingsession.LineRange)} + return &AILineAttribution{ + SessionID: sessionID, + Files: make(map[string][]aicodingsession.LineRange), + Pending: make(map[string]struct{}), + } } // aiLinesPath returns the path for a session's AI line attribution file (JSONL). @@ -49,6 +59,15 @@ type aiLineEntry struct { SessionID string `json:"session_id,omitempty"` File string `json:"file"` Ranges []aicodingsession.LineRange `json:"ranges"` + // RecordedAt is the RFC3339 timestamp of the edit. Entries written before + // this field existed have none, and are never treated as pending — those + // ledgers predate consumption tracking, so their files would otherwise + // keep crediting their session forever. + RecordedAt string `json:"recorded_at,omitempty"` + // ConsumedBy is the SHA of the commit that committed the file's pending + // ranges. Set only on marker entries appended by MarkConsumed, which + // clear the file from Pending instead of contributing ranges. + ConsumedBy string `json:"consumed_by,omitempty"` } // LoadAILineAttribution loads the AI line attribution for a session by @@ -63,6 +82,9 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { } defer func() { _ = f.Close() }() + // Entries are appended in order, so replaying them in order lets a file + // go pending -> consumed -> pending again across successive edits and + // commits. dec := json.NewDecoder(f) for dec.More() { var entry aiLineEntry @@ -72,7 +94,16 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { if entry.SessionID != "" { attr.SessionID = entry.SessionID } + + if entry.ConsumedBy != "" { + delete(attr.Pending, entry.File) + continue + } + attr.Files[entry.File] = append(attr.Files[entry.File], entry.Ranges...) + if entry.RecordedAt != "" { + attr.Pending[entry.File] = struct{}{} + } } return attr @@ -81,6 +112,52 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { // RecordLineRanges appends line ranges for a file to a session's attribution JSONL. // An empty or nil ranges slice still records the file as touched (e.g., deletion-only edits). func (s *Store) RecordLineRanges(sessionID, filePath string, ranges []aicodingsession.LineRange) error { + return s.appendAILineEntries(sessionID, []aiLineEntry{{ + SessionID: sessionID, + File: filePath, + Ranges: ranges, + RecordedAt: NowTimestamp(), + }}) +} + +// MarkConsumed records that the pending ranges of the given files landed in +// commit sha, so they stop crediting the session on later commits. Files the +// session has nothing pending for are ignored, which keeps the ledger from +// growing a marker per commit per file the session never touched. +func (s *Store) MarkConsumed(sessionID string, files []string, sha string) error { + if sha == "" || len(files) == 0 { + return nil + } + + pending := s.LoadAILineAttribution(sessionID).Pending + if len(pending) == 0 { + return nil + } + + now := NowTimestamp() + entries := make([]aiLineEntry, 0, len(files)) + for _, file := range files { + if _, ok := pending[file]; !ok { + continue + } + entries = append(entries, aiLineEntry{ + SessionID: sessionID, + File: file, + RecordedAt: now, + ConsumedBy: sha, + }) + } + + return s.appendAILineEntries(sessionID, entries) +} + +// appendAILineEntries appends entries to a session's attribution JSONL, +// creating the file and its directory on first write. +func (s *Store) appendAILineEntries(sessionID string, entries []aiLineEntry) error { + if len(entries) == 0 { + return nil + } + path := s.aiLinesPath(sessionID) if err := os.MkdirAll(filepath.Dir(path), 0755); err != nil { return fmt.Errorf("create ai-lines dir: %w", err) @@ -91,10 +168,15 @@ func (s *Store) RecordLineRanges(sessionID, filePath string, ranges []aicodingse return err } - if err := json.NewEncoder(f).Encode(aiLineEntry{SessionID: sessionID, File: filePath, Ranges: ranges}); err != nil { - _ = f.Close() - return err + enc := json.NewEncoder(f) + for i := range entries { + if err := enc.Encode(entries[i]); err != nil { + _ = f.Close() + + return err + } } + return f.Close() } @@ -106,6 +188,7 @@ func (s *Store) LoadAllAILineAttributions() ([]*AILineAttribution, error) { if errors.Is(err, os.ErrNotExist) { return nil, nil } + return nil, err } diff --git a/app/cli/internal/trace/state/state.go b/app/cli/internal/trace/state/state.go index 084c56751..1268e4d66 100644 --- a/app/cli/internal/trace/state/state.go +++ b/app/cli/internal/trace/state/state.go @@ -48,6 +48,12 @@ const ( commitRecordExt = ".json" sessionRecordExt = ".json" aiLinesExt = ".jsonl" + + // staleSessionRetention is how long a session's records are kept once + // everything it produced has been attested. Reachability alone never + // expires them: a session referenced by one surviving commit pins itself + // into the repository for good. + staleSessionRetention = 7 * 24 * time.Hour ) // InitTraceDir creates the /chainloop-trace/ directory structure. @@ -89,7 +95,8 @@ func (s *Store) WipeTraceDir() error { // 1. Walk commits/, drop any record whose SHA isn't in liveSHAs (post-rebase // orphan or commit on a deleted branch). // 2. Walk ai-lines/ and sessions/, drop any entry whose session ID is no -// longer referenced by a surviving CommitRecord. +// longer referenced by a surviving CommitRecord, or which is older than +// staleSessionRetention and has nothing left to attest. // // An empty liveSHAs is treated as a pathological signal (no local branches // readable, or the caller fed us garbage) and the GC short-circuits — wiping @@ -107,6 +114,9 @@ func (s *Store) GCOrphans(liveSHAs map[string]bool) error { } liveSessions := make(map[string]struct{}) + // Sessions with a surviving commit that has not been attested yet. Their + // state must survive the age check — the next push still needs it. + unattestedSessions := make(map[string]struct{}) for _, entry := range commitEntries { if entry.IsDir() || !strings.HasSuffix(entry.Name(), commitRecordExt) { continue @@ -124,9 +134,14 @@ func (s *Store) GCOrphans(liveSHAs map[string]bool) error { } for _, sid := range rec.SessionIDs { liveSessions[sanitizeID(sid)] = struct{}{} + if !rec.Tracked { + unattestedSessions[sanitizeID(sid)] = struct{}{} + } } } + stale := s.staleSessionIDs(unattestedSessions) + for _, child := range []struct { sub string ext string @@ -148,7 +163,8 @@ func (s *Store) GCOrphans(liveSHAs map[string]bool) error { continue } id := strings.TrimSuffix(entry.Name(), child.ext) - if _, alive := liveSessions[id]; !alive { + _, alive := liveSessions[id] + if _, expired := stale[id]; !alive || expired { _ = os.Remove(filepath.Join(dir, entry.Name())) } } @@ -157,6 +173,38 @@ func (s *Store) GCOrphans(liveSHAs map[string]bool) error { return nil } +// staleSessionIDs returns the sanitized IDs of session records older than +// staleSessionRetention whose work has all been attested. Records with an +// unparseable or missing StartedAt are never reported stale, so a bad +// timestamp cannot cause data loss. +// +// Liveness is deliberately not consulted: session-end does not always run, so +// a leaked record stays Active forever and would never expire. +func (s *Store) staleSessionIDs(unattested map[string]struct{}) map[string]struct{} { + records, err := s.LoadAllSessionRecords() + if err != nil { + return nil + } + + cutoff := time.Now().UTC().Add(-staleSessionRetention) + stale := make(map[string]struct{}) + for _, rec := range records { + id := sanitizeID(rec.SessionID) + if _, ok := unattested[id]; ok { + continue + } + startedAt, err := time.Parse(time.RFC3339, rec.StartedAt) + if err != nil { + continue + } + if startedAt.Before(cutoff) { + stale[id] = struct{}{} + } + } + + return stale +} + // RemoveTraceDir removes the entire /chainloop-trace/ directory. func (s *Store) RemoveTraceDir() error { return os.RemoveAll(s.traceDirPath()) diff --git a/app/cli/internal/trace/state/state_test.go b/app/cli/internal/trace/state/state_test.go index 93b4c848b..4bc14a3a9 100644 --- a/app/cli/internal/trace/state/state_test.go +++ b/app/cli/internal/trace/state/state_test.go @@ -19,12 +19,19 @@ import ( "os" "path/filepath" "testing" + "time" "github.com/chainloop-dev/chainloop/pkg/attestation/crafter/materials/aicodingsession" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) +// Fixture names reused across the pending-tracking and stale-GC tests. +const ( + fileA = "a.go" + sessOld = "sess-old" +) + func TestLogFilePath(t *testing.T) { assert.Equal(t, filepath.Join("/fake/.git", "chainloop-trace", "log.txt"), NewGitStore("/fake/.git").LogFilePath()) } @@ -359,3 +366,150 @@ func TestAILineAttribution(t *testing.T) { assert.Equal(t, rawID, attrs[0].SessionID, "consumers key off the agent-assigned ID, not the filename") }) } + +func TestAILinePendingTracking(t *testing.T) { + t.Run("a recorded file is pending", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + + assert.Contains(t, store.LoadAILineAttribution("sess-1").Pending, fileA) + }) + + t.Run("consuming clears pending but keeps the ranges", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + require.NoError(t, store.MarkConsumed("sess-1", []string{fileA}, "sha-1")) + + attr := store.LoadAILineAttribution("sess-1") + assert.Empty(t, attr.Pending, "a committed file must stop crediting the session") + assert.Len(t, attr.Files[fileA], 1, "push-time enrichment still needs the ranges") + }) + + t.Run("only the committed files are consumed", func(t *testing.T) { + // Staging one file of two must not retire the other: a session that + // commits its work in logical chunks has to keep credit for the rest. + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + require.NoError(t, store.RecordLineRanges("sess-1", "b.go", []aicodingsession.LineRange{{Start: 1, End: 5}})) + require.NoError(t, store.MarkConsumed("sess-1", []string{fileA}, "sha-1")) + + pending := store.LoadAILineAttribution("sess-1").Pending + assert.NotContains(t, pending, fileA) + assert.Contains(t, pending, "b.go") + }) + + t.Run("editing a file again re-arms it", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + require.NoError(t, store.MarkConsumed("sess-1", []string{fileA}, "sha-1")) + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}})) + + assert.Contains(t, store.LoadAILineAttribution("sess-1").Pending, fileA) + }) + + t.Run("consuming a file the session never touched is a no-op", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + require.NoError(t, store.MarkConsumed("sess-1", []string{"untouched.go"}, "sha-1")) + + attr := store.LoadAILineAttribution("sess-1") + assert.Contains(t, attr.Pending, fileA) + assert.NotContains(t, attr.Files, "untouched.go") + }) + + t.Run("a ledger written before consumption tracking is never pending", func(t *testing.T) { + // Ledgers already on disk have no recorded_at, and their sessions are + // long gone. Treating them as pending would keep stamping those + // sessions onto new commits until the GC catches up. + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + path := store.aiLinesPath("sess-legacy") + require.NoError(t, os.MkdirAll(filepath.Dir(path), 0755)) + legacy := `{"session_id":"sess-legacy","file":"legacy.go","ranges":[{"start":1,"end":5}]}` + "\n" + require.NoError(t, os.WriteFile(path, []byte(legacy), 0600)) + + attr := store.LoadAILineAttribution("sess-legacy") + assert.Empty(t, attr.Pending) + assert.Len(t, attr.Files["legacy.go"], 1, "the ranges are still readable for enrichment") + }) +} + +func TestGCOrphans_StaleSessions(t *testing.T) { + t.Run("prunes an aged-out session whose commits are all attested", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + old := time.Now().UTC().Add(-30 * 24 * time.Hour).Format(time.RFC3339) + require.NoError(t, store.SaveCommitRecord(&CommitRecord{ + SHA: "sha-1", SessionIDs: []string{sessOld}, Timestamp: old, Tracked: true, + })) + require.NoError(t, store.SaveSessionRecord(&SessionRecord{SessionID: sessOld, Active: true, StartedAt: old})) + require.NoError(t, store.RecordLineRanges(sessOld, fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + + require.NoError(t, store.GCOrphans(map[string]bool{"sha-1": true})) + + // Still Active on disk, because session-end is unreliable — age plus + // "nothing left to attest" is what retires it. + assert.False(t, store.SessionRecordExists(sessOld)) + assert.Empty(t, store.LoadAILineAttribution(sessOld).Files) + }) + + t.Run("keeps an aged-out session with an unattested commit", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + old := time.Now().UTC().Add(-30 * 24 * time.Hour).Format(time.RFC3339) + require.NoError(t, store.SaveCommitRecord(&CommitRecord{ + SHA: "sha-1", SessionIDs: []string{sessOld}, Timestamp: old, Tracked: false, + })) + require.NoError(t, store.SaveSessionRecord(&SessionRecord{SessionID: sessOld, Active: false, StartedAt: old})) + require.NoError(t, store.RecordLineRanges(sessOld, fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + + require.NoError(t, store.GCOrphans(map[string]bool{"sha-1": true})) + + assert.True(t, store.SessionRecordExists(sessOld), "the next push still has to attest this commit") + assert.NotEmpty(t, store.LoadAILineAttribution(sessOld).Files) + }) + + t.Run("keeps a recent session", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + recent := time.Now().UTC().Add(-1 * time.Hour).Format(time.RFC3339) + require.NoError(t, store.SaveCommitRecord(&CommitRecord{ + SHA: "sha-1", SessionIDs: []string{"sess-new"}, Timestamp: recent, Tracked: true, + })) + require.NoError(t, store.SaveSessionRecord(&SessionRecord{SessionID: "sess-new", Active: true, StartedAt: recent})) + require.NoError(t, store.RecordLineRanges("sess-new", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + + require.NoError(t, store.GCOrphans(map[string]bool{"sha-1": true})) + + assert.True(t, store.SessionRecordExists("sess-new")) + assert.NotEmpty(t, store.LoadAILineAttribution("sess-new").Files) + }) + + t.Run("an unparseable StartedAt is never treated as stale", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.SaveCommitRecord(&CommitRecord{ + SHA: "sha-1", SessionIDs: []string{"sess-bad"}, Timestamp: "2026-03-28T00:00:00Z", Tracked: true, + })) + require.NoError(t, store.SaveSessionRecord(&SessionRecord{SessionID: "sess-bad", StartedAt: "not-a-timestamp"})) + + require.NoError(t, store.GCOrphans(map[string]bool{"sha-1": true})) + + assert.True(t, store.SessionRecordExists("sess-bad")) + }) +} diff --git a/app/cli/pkg/action/trace_agent_hook.go b/app/cli/pkg/action/trace_agent_hook.go index 6ed55a10b..f50d823b1 100644 --- a/app/cli/pkg/action/trace_agent_hook.go +++ b/app/cli/pkg/action/trace_agent_hook.go @@ -52,11 +52,38 @@ func HandleAgentSessionEnd(provider trace.Provider, log zerolog.Logger) error { log.Debug().Err(err).Msg("copy session data failed") } + setSessionActive(store, sessionID, false, log) + log.Debug().Str("session_id", sessionID).Msg("session ended") return nil } +// setSessionActive flips the Active flag on an existing session record. The +// record is otherwise written once and never upserted, so without this a +// session stays marked active for the life of the repository. +// +// Active is not a reliable liveness signal on its own and must not decide +// attribution: session-end is not installed for `trace run`, and never fires +// on SIGKILL or a closed terminal. It only narrows the set of sessions a push +// attests when there are no commits to go on. +func setSessionActive(store *state.Store, sessionID string, active bool, log zerolog.Logger) { + rec, err := store.LoadSessionRecord(sessionID) + if err != nil { + log.Debug().Err(err).Msg("load session record failed") + + return + } + if rec == nil || rec.Active == active { + return + } + + rec.Active = active + if err := store.SaveSessionRecord(rec); err != nil { + log.Debug().Err(err).Bool("active", active).Msg("update session record failed") + } +} + // sessionStartBanner is what the developer sees at the top of a traced // session. Its audience includes someone who cloned the repository and never // ran init, so it says what is happening in plain words and, when we know it, @@ -225,6 +252,11 @@ func ensureSessionTracked(provider trace.Provider, store *state.Store, repoRoot sessionID := input.SessionID if store.SessionRecordExists(sessionID) { + // A resumed session fires session-start again after its end hook ran. + // Reviving the flag keeps StartedAt and the agent metadata captured on + // the first call intact. + setSessionActive(store, sessionID, true, log) + return } diff --git a/app/cli/pkg/action/trace_agent_hook_test.go b/app/cli/pkg/action/trace_agent_hook_test.go index ea970e791..95c069efd 100644 --- a/app/cli/pkg/action/trace_agent_hook_test.go +++ b/app/cli/pkg/action/trace_agent_hook_test.go @@ -156,6 +156,58 @@ func TestHandleAgentSessionEnd(t *testing.T) { withStdin(t, `{"session_id":"abc-123"}`) require.NoError(t, HandleAgentSessionEnd(provider, zerolog.Nop())) }) + + t.Run("marks the session inactive", func(t *testing.T) { + repoDir := initTempGitRepo(t) + store := state.NewGitStore(filepath.Join(repoDir, ".git")) + require.NoError(t, store.InitTraceDir()) + + origDir, _ := os.Getwd() + require.NoError(t, os.Chdir(repoDir)) + t.Cleanup(func() { _ = os.Chdir(origDir) }) + + require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ + SessionID: "abc-123", Provider: "claude-code", Active: true, StartedAt: "2026-03-28T00:00:00Z", + })) + + withStdin(t, `{"session_id":"abc-123"}`) + require.NoError(t, HandleAgentSessionEnd(provider, zerolog.Nop())) + + rec, err := store.LoadSessionRecord("abc-123") + require.NoError(t, err) + require.NotNil(t, rec) + assert.False(t, rec.Active) + assert.Equal(t, "2026-03-28T00:00:00Z", rec.StartedAt, "ending a session must not rewrite when it began") + assert.Equal(t, "claude-code", rec.Provider) + }) + + t.Run("a resumed session goes back to active", func(t *testing.T) { + repoDir := initTempGitRepo(t) + store := state.NewGitStore(filepath.Join(repoDir, ".git")) + require.NoError(t, store.InitTraceDir()) + + origDir, _ := os.Getwd() + require.NoError(t, os.Chdir(repoDir)) + t.Cleanup(func() { _ = os.Chdir(origDir) }) + + require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ + SessionID: "abc-123", + Provider: "claude-code", + AgentVersion: "1.2.3", + Active: false, + StartedAt: "2026-03-28T00:00:00Z", + })) + + withStdin(t, `{"session_id":"abc-123","cwd":"/some/path"}`) + require.NoError(t, HandleAgentSessionStart(provider, zerolog.Nop())) + + rec, err := store.LoadSessionRecord("abc-123") + require.NoError(t, err) + require.NotNil(t, rec) + assert.True(t, rec.Active, "an agent can resume a session after its end hook ran") + assert.Equal(t, "2026-03-28T00:00:00Z", rec.StartedAt) + assert.Equal(t, "1.2.3", rec.AgentVersion, "metadata captured on the first hook must survive") + }) } func TestAutoInstallGitHooks(t *testing.T) { diff --git a/app/cli/pkg/action/trace_hook_handler.go b/app/cli/pkg/action/trace_hook_handler.go index b1d7a893b..7d9577f3c 100644 --- a/app/cli/pkg/action/trace_hook_handler.go +++ b/app/cli/pkg/action/trace_hook_handler.go @@ -84,8 +84,13 @@ func handleCommitMsg(msgFilePath string, log zerolog.Logger) error { return appendTrailer(msgFilePath, sessionIDs) } -// matchSessionsToFiles returns session IDs that have AI line attribution for -// any of the given files. The returned slice is sorted. +// matchSessionsToFiles returns session IDs with uncommitted AI line +// attribution for any of the given files. The returned slice is sorted. +// +// Matching is deliberately against Pending rather than Files: a session's full +// range history outlives its commits, so intersecting it would credit a +// long-finished session on every later commit that touches a file it once +// edited, and that commit's whole diff would then be attributed to it. func matchSessionsToFiles(attrs []*state.AILineAttribution, files []string) []string { fileSet := make(map[string]struct{}, len(files)) for _, f := range files { @@ -94,7 +99,7 @@ func matchSessionsToFiles(attrs []*state.AILineAttribution, files []string) []st var sessionIDs []string for _, attr := range attrs { - for filePath := range attr.Files { + for filePath := range attr.Pending { if _, ok := fileSet[filePath]; ok { sessionIDs = append(sessionIDs, attr.SessionID) @@ -191,20 +196,46 @@ func handlePostCommit(_ context.Context, log zerolog.Logger) error { return fmt.Errorf("save commit record: %w", err) } + // The credited sessions' pending ranges have now landed, so retire them. + // Skipping this is what makes a session accumulate foreign commits: its + // files stay pending and keep matching every later commit that touches + // them. Post-commit errors only ever get logged — the commit already + // exists — so returning here costs nothing but surfaces the failure. + if len(sessionIDs) > 0 { + committed := commitFiles(client, repoRoot, sha) + for _, sid := range sessionIDs { + if err := store.MarkConsumed(sid, committed, sha); err != nil { + return fmt.Errorf("mark attribution consumed for session %s: %w", sid, err) + } + } + } + log.Info().Str("sha", sha).Msg("commit record saved") return nil } // deriveSessionIDsForCommit scans ai-lines data and returns session IDs -// that have modified any file that appears in the given commit. +// that have uncommitted attribution for any file in the given commit. func deriveSessionIDsForCommit(client tracegit.Client, store *state.Store, repoRoot, headSHA string) []string { attrs, err := store.LoadAllAILineAttributions() if err != nil || len(attrs) == 0 { return nil } - changes, err := client.CodeChangesForRange(repoRoot, headSHA, headSHA) + files := commitFiles(client, repoRoot, headSHA) + if len(files) == 0 { + return nil + } + + return matchSessionsToFiles(attrs, files) +} + +// commitFiles returns the paths the commit at sha changed relative to its +// parent. Returns nil when the diff cannot be read, which leaves callers +// treating the commit as touching nothing rather than failing the hook. +func commitFiles(client tracegit.Client, repoRoot, sha string) []string { + changes, err := client.CodeChangesForRange(repoRoot, sha, sha) if err != nil || len(changes.Files) == 0 { return nil } @@ -214,7 +245,7 @@ func deriveSessionIDsForCommit(client tracegit.Client, store *state.Store, repoR files = append(files, f.Path) } - return matchSessionsToFiles(attrs, files) + return files } // filterCurrentBranchCommits returns the subset of records whose SHA is @@ -388,7 +419,13 @@ func RunTracePush(ctx context.Context, log zerolog.Logger, opts RunTracePushOpts } if len(aiCommits) == 0 { - for sid := range sessionRecords { + for sid, rec := range sessionRecords { + // A session that has ended without contributing a commit to this + // branch has nothing new to say; attesting it on every later push + // republishes the same stale evidence. + if !rec.Active { + continue + } sessionCommits[sid] = nil } if len(sessionCommits) == 0 { diff --git a/app/cli/pkg/action/trace_hook_handler_test.go b/app/cli/pkg/action/trace_hook_handler_test.go index 4e9482f52..1428af22c 100644 --- a/app/cli/pkg/action/trace_hook_handler_test.go +++ b/app/cli/pkg/action/trace_hook_handler_test.go @@ -34,6 +34,14 @@ import ( "github.com/stretchr/testify/require" ) +// Fixture names reused across the session-matching tests. +const ( + sessionA = "session-a" + srcFoo = "src/foo.go" + srcBar = "src/bar.go" + srcBaz = "src/baz.go" +) + func TestEvidenceName(t *testing.T) { t.Run("truncates long session ID", func(t *testing.T) { name := evidenceName("abcdefghijklmnop") @@ -48,14 +56,26 @@ func TestEvidenceName(t *testing.T) { func TestMatchSessionsToFiles(t *testing.T) { attrs := []*state.AILineAttribution{ - {SessionID: "session-a", Files: map[string][]aicodingsession.LineRange{"src/foo.go": {{Start: 1, End: 10}}}}, - {SessionID: "session-b", Files: map[string][]aicodingsession.LineRange{"src/bar.go": {{Start: 1, End: 5}}}}, - {SessionID: "session-c", Files: map[string][]aicodingsession.LineRange{"src/baz.go": {{Start: 1, End: 3}}}}, + { + SessionID: sessionA, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]struct{}{srcFoo: {}}, + }, + { + SessionID: "session-b", + Files: map[string][]aicodingsession.LineRange{srcBar: {{Start: 1, End: 5}}}, + Pending: map[string]struct{}{srcBar: {}}, + }, + { + SessionID: "session-c", + Files: map[string][]aicodingsession.LineRange{srcBaz: {{Start: 1, End: 3}}}, + Pending: map[string]struct{}{srcBaz: {}}, + }, } t.Run("matches sessions that touched staged files", func(t *testing.T) { - ids := matchSessionsToFiles(attrs, []string{"src/foo.go", "src/bar.go"}) - assert.Equal(t, []string{"session-a", "session-b"}, ids) + ids := matchSessionsToFiles(attrs, []string{srcFoo, srcBar}) + assert.Equal(t, []string{sessionA, "session-b"}, ids) }) t.Run("no match returns nil", func(t *testing.T) { @@ -69,13 +89,35 @@ func TestMatchSessionsToFiles(t *testing.T) { }) t.Run("empty attrs returns nil", func(t *testing.T) { - ids := matchSessionsToFiles(nil, []string{"src/foo.go"}) + ids := matchSessionsToFiles(nil, []string{srcFoo}) assert.Nil(t, ids) }) t.Run("result is sorted", func(t *testing.T) { - ids := matchSessionsToFiles(attrs, []string{"src/baz.go", "src/foo.go"}) - assert.Equal(t, []string{"session-a", "session-c"}, ids) + ids := matchSessionsToFiles(attrs, []string{srcBaz, srcFoo}) + assert.Equal(t, []string{sessionA, "session-c"}, ids) + }) + + t.Run("ignores a session whose ranges were already committed", func(t *testing.T) { + // The regression this guards: a finished session keeps its full range + // history in Files, so matching on that would credit it on every later + // commit touching src/foo.go — days or weeks after it ended. + committed := []*state.AILineAttribution{{ + SessionID: sessionA, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]struct{}{}, + }} + + assert.Nil(t, matchSessionsToFiles(committed, []string{srcFoo})) + }) + + t.Run("ignores a legacy attribution with no pending set", func(t *testing.T) { + legacy := []*state.AILineAttribution{{ + SessionID: sessionA, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + }} + + assert.Nil(t, matchSessionsToFiles(legacy, []string{srcFoo})) }) } @@ -373,6 +415,103 @@ func TestHandlePostCommit_UsesTrailerWhenPresent(t *testing.T) { assert.Equal(t, []string{"orig-1", "orig-2"}, commits[0].SessionIDs) } +// A session's attribution must only credit the commit that actually lands it. +// Before consumption tracking, the ai-lines ledger was matched in full on every +// commit, so a session that once edited a file kept being stamped onto later +// commits touching it — the whole foreign diff was then attributed to that +// session, with every file it had no ranges for reported as human-written. +func TestCommitLifecycle_SessionIsNotCreditedTwice(t *testing.T) { + dir, gitDir := initGitRepo(t) + store := state.NewGitStore(gitDir) + require.NoError(t, store.InitTraceDir()) + + shared := filepath.Join(dir, "shared.go") + require.NoError(t, os.WriteFile(shared, []byte("package main\n"), 0600)) + require.NoError(t, store.RecordLineRanges("sess-first", "shared.go", []aicodingsession.LineRange{{Start: 1, End: 1}})) + + // Commit 1: the session edited shared.go, so it earns the trailer. + msg := filepath.Join(dir, "msg1") + require.NoError(t, os.WriteFile(msg, []byte("feat: first\n"), 0600)) + runGit(t, dir, "add", "shared.go") + require.NoError(t, handleCommitMsg(msg, zerolog.Nop())) + + first, err := os.ReadFile(msg) + require.NoError(t, err) + require.Contains(t, string(first), "Chainloop-Trace-Sessions: sess-first") + + runGit(t, dir, "commit", "-F", msg) + require.NoError(t, handlePostCommit(t.Context(), zerolog.Nop())) + + // Commit 2: somebody else touches the same file. The finished session must + // not be credited, even though its ledger still lists shared.go. + require.NoError(t, os.WriteFile(shared, []byte("package main\n\nfunc main() {}\n"), 0600)) + msg2 := filepath.Join(dir, "msg2") + require.NoError(t, os.WriteFile(msg2, []byte("chore: unrelated\n"), 0600)) + runGit(t, dir, "add", "shared.go") + require.NoError(t, handleCommitMsg(msg2, zerolog.Nop())) + + second, err := os.ReadFile(msg2) + require.NoError(t, err) + assert.NotContains(t, string(second), "Chainloop-Trace-Sessions", + "a session whose ranges are already committed must not be credited again") + + runGit(t, dir, "commit", "-F", msg2) + require.NoError(t, handlePostCommit(t.Context(), zerolog.Nop())) + + commits, err := store.LoadAllCommitRecords() + require.NoError(t, err) + require.Len(t, commits, 2) + + credited := map[string][]string{} + for _, c := range commits { + subject := strings.SplitN(c.Message, "\n", 2)[0] + credited[subject] = c.SessionIDs + } + assert.Equal(t, []string{"sess-first"}, credited["feat: first"]) + assert.Empty(t, credited["chore: unrelated"], "the second commit belongs to no session") + + // The ranges themselves survive, because push-time enrichment needs them. + assert.NotEmpty(t, store.LoadAILineAttribution("sess-first").Files["shared.go"]) +} + +// A session committing its work in logical chunks has to keep credit for the +// files it has not staged yet. +func TestCommitLifecycle_PartialStagingKeepsCredit(t *testing.T) { + dir, gitDir := initGitRepo(t) + store := state.NewGitStore(gitDir) + require.NoError(t, store.InitTraceDir()) + + for _, name := range []string{"a.go", "b.go"} { + require.NoError(t, os.WriteFile(filepath.Join(dir, name), []byte("package main\n"), 0600)) + require.NoError(t, store.RecordLineRanges("sess-1", name, []aicodingsession.LineRange{{Start: 1, End: 1}})) + } + + commitOne := func(t *testing.T, file, subject string) string { + t.Helper() + msg := filepath.Join(dir, "msg-"+file) + require.NoError(t, os.WriteFile(msg, []byte(subject+"\n"), 0600)) + runGit(t, dir, "add", file) + require.NoError(t, handleCommitMsg(msg, zerolog.Nop())) + content, err := os.ReadFile(msg) + require.NoError(t, err) + runGit(t, dir, "commit", "-F", msg) + require.NoError(t, handlePostCommit(t.Context(), zerolog.Nop())) + + return string(content) + } + + assert.Contains(t, commitOne(t, "a.go", "feat: a"), "Chainloop-Trace-Sessions: sess-1") + assert.Contains(t, commitOne(t, "b.go", "feat: b"), "Chainloop-Trace-Sessions: sess-1", + "committing a.go must not retire the session's pending work on b.go") + + commits, err := store.LoadAllCommitRecords() + require.NoError(t, err) + require.Len(t, commits, 2) + for _, c := range commits { + assert.Equal(t, []string{"sess-1"}, c.SessionIDs) + } +} + func TestHandlePostCommit_SkipsMergeCommit(t *testing.T) { dir, gitDir := initGitRepo(t) store := state.NewGitStore(gitDir) From c40bca4578633de1773eaabf704eb8306022ea16 Mon Sep 17 00:00:00 2001 From: "Jose I. Paris" Date: Mon, 14 Sep 2026 15:16:38 +0200 Subject: [PATCH 2/4] fix(trace): credit only the session that edited a file last MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Consuming attribution on commit closed the case where a finished session had already committed its work, but not the one where it had not. Two sessions in a row over the same file, neither having committed, both stayed pending, so the commit carried both IDs — attaching a session that had moved on to that commit and to the pull request holding it, with the whole commit diff attributed to it. Each staged file is now owned by the session that edited it last: the earlier edit no longer describes the file, since the later session rewrote those lines. Ownership is per file, so a session still keeps credit for the other files it has pending. Ordering this needs better than the second resolution NowTimestamp provides — two sessions editing one file within the same second were indistinguishable, and the tie-break decided it. Attribution entries now record RFC3339Nano through a new NowTimestampPrecise, and Pending carries the parsed edit time per file. Timestamps are compared as times, never as strings: a fractional-second form does not sort lexicographically against a whole-second one. The tie-break stays for genuinely equal timestamps, falling to the lower session ID so the trailer does not follow map iteration order. Signed-off-by: Jose I. Paris --- app/cli/internal/trace/state/ailines.go | 39 ++++-- app/cli/internal/trace/state/state.go | 10 ++ app/cli/internal/trace/state/state_test.go | 28 ++++ app/cli/pkg/action/trace_agent_hook_test.go | 6 +- app/cli/pkg/action/trace_hook_handler.go | 51 ++++++- app/cli/pkg/action/trace_hook_handler_test.go | 130 ++++++++++++++++-- 6 files changed, 229 insertions(+), 35 deletions(-) diff --git a/app/cli/internal/trace/state/ailines.go b/app/cli/internal/trace/state/ailines.go index b41c872a9..ef66a00ba 100644 --- a/app/cli/internal/trace/state/ailines.go +++ b/app/cli/internal/trace/state/ailines.go @@ -22,6 +22,7 @@ import ( "os" "path/filepath" "strings" + "time" "github.com/chainloop-dev/chainloop/pkg/attestation/crafter/materials/aicodingsession" ) @@ -30,12 +31,16 @@ import ( type AILineAttribution struct { SessionID string `json:"session_id"` Files map[string][]aicodingsession.LineRange `json:"files"` - // Pending holds the files whose recorded ranges have not been committed - // yet, and is the only set a new commit may be matched against. Files - // keeps every range ever recorded because push-time enrichment needs the - // full history, but matching against it credits a finished session on - // every later commit that happens to touch a file it once edited. - Pending map[string]struct{} `json:"-"` + // Pending maps each file whose recorded ranges have not been committed yet + // to the time of its most recent edit, and is the only set a new commit may + // be matched against. Files keeps every range ever recorded because + // push-time enrichment needs the full history, but matching against it + // credits a finished session on every later commit that happens to touch a + // file it once edited. + // + // The timestamp resolves which session owns a file two of them both have + // pending: the later edit rewrote the earlier one's lines. + Pending map[string]time.Time `json:"-"` } // newAILineAttribution returns an AILineAttribution with initialized maps. @@ -43,7 +48,7 @@ func newAILineAttribution(sessionID string) *AILineAttribution { return &AILineAttribution{ SessionID: sessionID, Files: make(map[string][]aicodingsession.LineRange), - Pending: make(map[string]struct{}), + Pending: make(map[string]time.Time), } } @@ -59,10 +64,11 @@ type aiLineEntry struct { SessionID string `json:"session_id,omitempty"` File string `json:"file"` Ranges []aicodingsession.LineRange `json:"ranges"` - // RecordedAt is the RFC3339 timestamp of the edit. Entries written before - // this field existed have none, and are never treated as pending — those - // ledgers predate consumption tracking, so their files would otherwise - // keep crediting their session forever. + // RecordedAt is the RFC3339 timestamp of the edit, with sub-second + // precision so two sessions editing one file can be ordered. Entries + // written before this field existed have none, and are never treated as + // pending — those ledgers predate consumption tracking, so their files + // would otherwise keep crediting their session forever. RecordedAt string `json:"recorded_at,omitempty"` // ConsumedBy is the SHA of the commit that committed the file's pending // ranges. Set only on marker entries appended by MarkConsumed, which @@ -101,8 +107,11 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { } attr.Files[entry.File] = append(attr.Files[entry.File], entry.Ranges...) - if entry.RecordedAt != "" { - attr.Pending[entry.File] = struct{}{} + // An entry with no parseable timestamp is never pending: it either + // predates consumption tracking, in which case its session is long + // gone, or it cannot be ordered against a competing session's edit. + if recordedAt, err := time.Parse(time.RFC3339, entry.RecordedAt); err == nil { + attr.Pending[entry.File] = recordedAt } } @@ -116,7 +125,7 @@ func (s *Store) RecordLineRanges(sessionID, filePath string, ranges []aicodingse SessionID: sessionID, File: filePath, Ranges: ranges, - RecordedAt: NowTimestamp(), + RecordedAt: NowTimestampPrecise(), }}) } @@ -134,7 +143,7 @@ func (s *Store) MarkConsumed(sessionID string, files []string, sha string) error return nil } - now := NowTimestamp() + now := NowTimestampPrecise() entries := make([]aiLineEntry, 0, len(files)) for _, file := range files { if _, ok := pending[file]; !ok { diff --git a/app/cli/internal/trace/state/state.go b/app/cli/internal/trace/state/state.go index 1268e4d66..83e3c4da9 100644 --- a/app/cli/internal/trace/state/state.go +++ b/app/cli/internal/trace/state/state.go @@ -328,3 +328,13 @@ func removeIfExists(path string) error { func NowTimestamp() string { return time.Now().UTC().Format(time.RFC3339) } + +// NowTimestampPrecise returns the current UTC time in RFC3339 format with +// sub-second precision. Used where two events have to be ordered against each +// other — second resolution is too coarse to tell which of two edits to the +// same file came last. Callers must compare parsed times, not the strings: +// fractional-second forms do not sort lexicographically against whole-second +// ones. +func NowTimestampPrecise() string { + return time.Now().UTC().Format(time.RFC3339Nano) +} diff --git a/app/cli/internal/trace/state/state_test.go b/app/cli/internal/trace/state/state_test.go index 4bc14a3a9..7a9396815 100644 --- a/app/cli/internal/trace/state/state_test.go +++ b/app/cli/internal/trace/state/state_test.go @@ -427,6 +427,34 @@ func TestAILinePendingTracking(t *testing.T) { assert.NotContains(t, attr.Files, "untouched.go") }) + t.Run("pending carries the time of the most recent edit", func(t *testing.T) { + // Second resolution cannot order two sessions editing one file, so the + // recorded timestamps must be finer than that. + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + require.NoError(t, store.RecordLineRanges("sess-2", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}})) + + first := store.LoadAILineAttribution("sess-1").Pending[fileA] + second := store.LoadAILineAttribution("sess-2").Pending[fileA] + require.False(t, first.IsZero()) + require.False(t, second.IsZero()) + assert.True(t, second.After(first), "the later edit must be ordered after the earlier one") + }) + + t.Run("re-editing a file advances its pending time", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) + firstEdit := store.LoadAILineAttribution("sess-1").Pending[fileA] + + require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}})) + + assert.True(t, store.LoadAILineAttribution("sess-1").Pending[fileA].After(firstEdit)) + }) + t.Run("a ledger written before consumption tracking is never pending", func(t *testing.T) { // Ledgers already on disk have no recorded_at, and their sessions are // long gone. Treating them as pending would keep stamping those diff --git a/app/cli/pkg/action/trace_agent_hook_test.go b/app/cli/pkg/action/trace_agent_hook_test.go index 95c069efd..65961e572 100644 --- a/app/cli/pkg/action/trace_agent_hook_test.go +++ b/app/cli/pkg/action/trace_agent_hook_test.go @@ -167,7 +167,7 @@ func TestHandleAgentSessionEnd(t *testing.T) { t.Cleanup(func() { _ = os.Chdir(origDir) }) require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ - SessionID: "abc-123", Provider: "claude-code", Active: true, StartedAt: "2026-03-28T00:00:00Z", + SessionID: "abc-123", Provider: providerClaudeCode, Active: true, StartedAt: "2026-03-28T00:00:00Z", })) withStdin(t, `{"session_id":"abc-123"}`) @@ -178,7 +178,7 @@ func TestHandleAgentSessionEnd(t *testing.T) { require.NotNil(t, rec) assert.False(t, rec.Active) assert.Equal(t, "2026-03-28T00:00:00Z", rec.StartedAt, "ending a session must not rewrite when it began") - assert.Equal(t, "claude-code", rec.Provider) + assert.Equal(t, providerClaudeCode, rec.Provider) }) t.Run("a resumed session goes back to active", func(t *testing.T) { @@ -192,7 +192,7 @@ func TestHandleAgentSessionEnd(t *testing.T) { require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ SessionID: "abc-123", - Provider: "claude-code", + Provider: providerClaudeCode, AgentVersion: "1.2.3", Active: false, StartedAt: "2026-03-28T00:00:00Z", diff --git a/app/cli/pkg/action/trace_hook_handler.go b/app/cli/pkg/action/trace_hook_handler.go index 7d9577f3c..03adb2572 100644 --- a/app/cli/pkg/action/trace_hook_handler.go +++ b/app/cli/pkg/action/trace_hook_handler.go @@ -23,6 +23,7 @@ import ( "os" "sort" "strings" + "time" "github.com/chainloop-dev/chainloop/app/cli/internal/trace" "github.com/chainloop-dev/chainloop/app/cli/internal/trace/attribution" @@ -84,28 +85,64 @@ func handleCommitMsg(msgFilePath string, log zerolog.Logger) error { return appendTrailer(msgFilePath, sessionIDs) } -// matchSessionsToFiles returns session IDs with uncommitted AI line +// fileOwner is the session currently credited with a staged file's pending +// attribution, and when it made the edit. +type fileOwner struct { + sessionID string + editedAt time.Time +} + +// supersededBy reports whether an edit made at editedAt by sessionID takes the +// file over from this owner. Equal timestamps fall to the lower session ID, so +// the trailer stays stable instead of following map iteration order. +func (o fileOwner) supersededBy(sessionID string, editedAt time.Time) bool { + if editedAt.Equal(o.editedAt) { + return sessionID < o.sessionID + } + + return editedAt.After(o.editedAt) +} + +// matchSessionsToFiles returns the session IDs that own uncommitted AI line // attribution for any of the given files. The returned slice is sorted. // // Matching is deliberately against Pending rather than Files: a session's full // range history outlives its commits, so intersecting it would credit a // long-finished session on every later commit that touches a file it once // edited, and that commit's whole diff would then be attributed to it. +// +// Each file is owned by the session that edited it last. When two sessions both +// have it pending, the earlier edit no longer describes the file — the later +// session rewrote those lines — so crediting both would attach a session that +// has moved on to this commit and to the pull request carrying it. func matchSessionsToFiles(attrs []*state.AILineAttribution, files []string) []string { fileSet := make(map[string]struct{}, len(files)) for _, f := range files { fileSet[f] = struct{}{} } - var sessionIDs []string + owners := make(map[string]fileOwner, len(fileSet)) for _, attr := range attrs { - for filePath := range attr.Pending { - if _, ok := fileSet[filePath]; ok { - sessionIDs = append(sessionIDs, attr.SessionID) - - break + for filePath, editedAt := range attr.Pending { + if _, staged := fileSet[filePath]; !staged { + continue + } + if cur, claimed := owners[filePath]; claimed && !cur.supersededBy(attr.SessionID, editedAt) { + continue } + + owners[filePath] = fileOwner{sessionID: attr.SessionID, editedAt: editedAt} + } + } + + seen := make(map[string]struct{}, len(owners)) + var sessionIDs []string + for _, o := range owners { + if _, dup := seen[o.sessionID]; dup { + continue } + seen[o.sessionID] = struct{}{} + sessionIDs = append(sessionIDs, o.sessionID) } sort.Strings(sessionIDs) diff --git a/app/cli/pkg/action/trace_hook_handler_test.go b/app/cli/pkg/action/trace_hook_handler_test.go index 1428af22c..dbdab68b2 100644 --- a/app/cli/pkg/action/trace_hook_handler_test.go +++ b/app/cli/pkg/action/trace_hook_handler_test.go @@ -23,6 +23,7 @@ import ( "path/filepath" "strings" "testing" + "time" "github.com/chainloop-dev/chainloop/app/cli/internal/trace" "github.com/chainloop-dev/chainloop/app/cli/internal/trace/attribution" @@ -36,10 +37,12 @@ import ( // Fixture names reused across the session-matching tests. const ( - sessionA = "session-a" - srcFoo = "src/foo.go" - srcBar = "src/bar.go" - srcBaz = "src/baz.go" + sessionA = "session-a" + sessionB = "session-b" + srcFoo = "src/foo.go" + srcBar = "src/bar.go" + srcBaz = "src/baz.go" + providerClaudeCode = "claude-code" ) func TestEvidenceName(t *testing.T) { @@ -55,27 +58,28 @@ func TestEvidenceName(t *testing.T) { } func TestMatchSessionsToFiles(t *testing.T) { + edited := time.Date(2026, 4, 28, 10, 0, 0, 0, time.UTC) attrs := []*state.AILineAttribution{ { SessionID: sessionA, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]struct{}{srcFoo: {}}, + Pending: map[string]time.Time{srcFoo: edited}, }, { - SessionID: "session-b", + SessionID: sessionB, Files: map[string][]aicodingsession.LineRange{srcBar: {{Start: 1, End: 5}}}, - Pending: map[string]struct{}{srcBar: {}}, + Pending: map[string]time.Time{srcBar: edited}, }, { SessionID: "session-c", Files: map[string][]aicodingsession.LineRange{srcBaz: {{Start: 1, End: 3}}}, - Pending: map[string]struct{}{srcBaz: {}}, + Pending: map[string]time.Time{srcBaz: edited}, }, } t.Run("matches sessions that touched staged files", func(t *testing.T) { ids := matchSessionsToFiles(attrs, []string{srcFoo, srcBar}) - assert.Equal(t, []string{sessionA, "session-b"}, ids) + assert.Equal(t, []string{sessionA, sessionB}, ids) }) t.Run("no match returns nil", func(t *testing.T) { @@ -105,7 +109,7 @@ func TestMatchSessionsToFiles(t *testing.T) { committed := []*state.AILineAttribution{{ SessionID: sessionA, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]struct{}{}, + Pending: map[string]time.Time{}, }} assert.Nil(t, matchSessionsToFiles(committed, []string{srcFoo})) @@ -119,6 +123,65 @@ func TestMatchSessionsToFiles(t *testing.T) { assert.Nil(t, matchSessionsToFiles(legacy, []string{srcFoo})) }) + + t.Run("the session that edited a file last owns it", func(t *testing.T) { + contested := []*state.AILineAttribution{ + { + SessionID: sessionA, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]time.Time{srcFoo: edited}, + }, + { + SessionID: sessionB, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]time.Time{srcFoo: edited.Add(time.Minute)}, + }, + } + + assert.Equal(t, []string{sessionB}, matchSessionsToFiles(contested, []string{srcFoo})) + }) + + t.Run("ownership is per file, not per session", func(t *testing.T) { + // session-b won src/foo.go, but session-a still owns the bar.go edit + // it has pending, so both belong on a commit staging the two files. + split := []*state.AILineAttribution{ + { + SessionID: sessionA, + Files: map[string][]aicodingsession.LineRange{ + srcFoo: {{Start: 1, End: 10}}, + srcBar: {{Start: 1, End: 5}}, + }, + Pending: map[string]time.Time{srcFoo: edited, srcBar: edited}, + }, + { + SessionID: sessionB, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]time.Time{srcFoo: edited.Add(time.Minute)}, + }, + } + + assert.Equal(t, []string{sessionA, sessionB}, matchSessionsToFiles(split, []string{srcFoo, srcBar})) + }) + + t.Run("a tie breaks deterministically", func(t *testing.T) { + tied := []*state.AILineAttribution{ + { + SessionID: "session-z", + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]time.Time{srcFoo: edited}, + }, + { + SessionID: sessionA, + Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, + Pending: map[string]time.Time{srcFoo: edited}, + }, + } + + // Repeated because map iteration order varies between runs. + for range 20 { + assert.Equal(t, []string{sessionA}, matchSessionsToFiles(tied, []string{srcFoo})) + } + }) } func TestAppendTrailer(t *testing.T) { @@ -474,6 +537,53 @@ func TestCommitLifecycle_SessionIsNotCreditedTwice(t *testing.T) { assert.NotEmpty(t, store.LoadAILineAttribution("sess-first").Files["shared.go"]) } +// Two sessions in a row over the same file, neither having committed yet: the +// first one records its ranges and ends, then a second one edits the same file. +// Only the session that edited last may be credited — its edit rewrote the +// lines the first one wrote, and crediting both would attach a finished session +// to a commit, and to the pull request holding it, on the strength of work that +// no longer exists. +func TestCommitLifecycle_LaterSessionSupersedesFinishedOne(t *testing.T) { + dir, gitDir := initGitRepo(t) + store := state.NewGitStore(gitDir) + require.NoError(t, store.InitTraceDir()) + + shared := filepath.Join(dir, "shared.go") + + // Session one edits the file, then ends without committing. + require.NoError(t, os.WriteFile(shared, []byte("package main\n"), 0600)) + require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ + SessionID: "sess-first", Provider: providerClaudeCode, Active: true, StartedAt: state.NowTimestamp(), + })) + require.NoError(t, store.RecordLineRanges("sess-first", "shared.go", []aicodingsession.LineRange{{Start: 1, End: 1}})) + setSessionActive(store, "sess-first", false, zerolog.Nop()) + + // Session two edits the same file afterwards. + require.NoError(t, os.WriteFile(shared, []byte("package main\n\nfunc main() {}\n"), 0600)) + require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ + SessionID: "sess-second", Provider: providerClaudeCode, Active: true, StartedAt: state.NowTimestamp(), + })) + require.NoError(t, store.RecordLineRanges("sess-second", "shared.go", []aicodingsession.LineRange{{Start: 3, End: 3}})) + + msg := filepath.Join(dir, "msg") + require.NoError(t, os.WriteFile(msg, []byte("feat: shared\n"), 0600)) + runGit(t, dir, "add", "shared.go") + require.NoError(t, handleCommitMsg(msg, zerolog.Nop())) + + trailer, err := os.ReadFile(msg) + require.NoError(t, err) + assert.Contains(t, string(trailer), "Chainloop-Trace-Sessions: sess-second") + assert.NotContains(t, string(trailer), "sess-first", "the finished session's edit was overwritten") + + runGit(t, dir, "commit", "-F", msg) + require.NoError(t, handlePostCommit(t.Context(), zerolog.Nop())) + + commits, err := store.LoadAllCommitRecords() + require.NoError(t, err) + require.Len(t, commits, 1) + assert.Equal(t, []string{"sess-second"}, commits[0].SessionIDs) +} + // A session committing its work in logical chunks has to keep credit for the // files it has not staged yet. func TestCommitLifecycle_PartialStagingKeepsCredit(t *testing.T) { From 79a3764fdb4473a2e5e851661092cae24359e1dc Mon Sep 17 00:00:00 2001 From: "Jose I. Paris" Date: Mon, 14 Sep 2026 16:29:50 +0200 Subject: [PATCH 3/4] fix(trace): address review on session revival, consumption races and test clocks Only session-start revives an ended session. The revival was in ensureSessionTracked, which the pre- and post-tool-use hooks also call, so one of those arriving after session-end resurrected a session that really had finished and the next no-commit push would attest it. A consumption marker now names the edit it retires rather than the time it was written. MarkConsumed reads the pending set and then appends, so a concurrent RecordLineRanges could land in between and leave the marker behind an edit the commit never contained; replay then cleared that edit's pending state and the session lost credit for work still in the working tree. Replay compares the pending time against the marker's, so a later edit survives. The snapshot is now an explicit parameter, since it is the boundary this has to be correct across. Ordering tests no longer race the wall clock. They asserted strict ordering between two consecutive RecordLineRanges calls, which ties on a host whose clock advances in coarse ticks; the new RecordLineRangesAt lets them set the times instead, and the same seam makes the two-session lifecycle test deterministic. Left as is, with the reasoning recorded in staleSessionIDs: the GC does not spare a week-old session's uncommitted attribution. Keeping it means a session nothing has heard from in a week can still claim a file and pull the whole commit's diff into its evidence, and by then its transcript is usually gone, so the attestation it wins yields nothing. Attributing that edit to nobody is the safe direction. Signed-off-by: Jose I. Paris --- app/cli/internal/trace/state/ailines.go | 51 ++++++++++++++---- app/cli/internal/trace/state/state.go | 18 +++---- app/cli/internal/trace/state/state_test.go | 54 ++++++++++++++----- app/cli/pkg/action/trace_agent_hook.go | 13 +++-- app/cli/pkg/action/trace_agent_hook_test.go | 25 +++++++++ app/cli/pkg/action/trace_hook_handler_test.go | 9 +++- 6 files changed, 129 insertions(+), 41 deletions(-) diff --git a/app/cli/internal/trace/state/ailines.go b/app/cli/internal/trace/state/ailines.go index ef66a00ba..b2e270cc6 100644 --- a/app/cli/internal/trace/state/ailines.go +++ b/app/cli/internal/trace/state/ailines.go @@ -64,11 +64,13 @@ type aiLineEntry struct { SessionID string `json:"session_id,omitempty"` File string `json:"file"` Ranges []aicodingsession.LineRange `json:"ranges"` - // RecordedAt is the RFC3339 timestamp of the edit, with sub-second - // precision so two sessions editing one file can be ordered. Entries - // written before this field existed have none, and are never treated as - // pending — those ledgers predate consumption tracking, so their files - // would otherwise keep crediting their session forever. + // RecordedAt is the RFC3339 timestamp of the edit this entry describes, + // with sub-second precision so two sessions editing one file can be + // ordered. On a ConsumedBy marker it is the time of the edit being + // retired, not when the marker was written. Entries written before this + // field existed have none, and are never treated as pending — those + // ledgers predate consumption tracking, so their files would otherwise + // keep crediting their session forever. RecordedAt string `json:"recorded_at,omitempty"` // ConsumedBy is the SHA of the commit that committed the file's pending // ranges. Set only on marker entries appended by MarkConsumed, which @@ -102,7 +104,17 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { } if entry.ConsumedBy != "" { - delete(attr.Pending, entry.File) + // Retire only the edit the commit actually contained. A concurrent + // RecordLineRanges can land between MarkConsumed reading the + // pending set and appending its markers, leaving a marker behind an + // edit it never saw; that edit's later timestamp keeps it pending. + // A marker with no readable time predates this and retires the file + // outright. + consumedAt, err := time.Parse(time.RFC3339, entry.RecordedAt) + if err != nil || !attr.Pending[entry.File].After(consumedAt) { + delete(attr.Pending, entry.File) + } + continue } @@ -121,11 +133,19 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { // RecordLineRanges appends line ranges for a file to a session's attribution JSONL. // An empty or nil ranges slice still records the file as touched (e.g., deletion-only edits). func (s *Store) RecordLineRanges(sessionID, filePath string, ranges []aicodingsession.LineRange) error { + return s.RecordLineRangesAt(sessionID, filePath, ranges, time.Now().UTC()) +} + +// RecordLineRangesAt records an edit made at a given time. Ownership of a file +// two sessions both edited is decided by which edit came last, so tests that +// exercise that need to set the times rather than hope the wall clock advances +// between two calls — it does not on a host with a coarse clock. +func (s *Store) RecordLineRangesAt(sessionID, filePath string, ranges []aicodingsession.LineRange, at time.Time) error { return s.appendAILineEntries(sessionID, []aiLineEntry{{ SessionID: sessionID, File: filePath, Ranges: ranges, - RecordedAt: NowTimestampPrecise(), + RecordedAt: at.UTC().Format(time.RFC3339Nano), }}) } @@ -138,21 +158,30 @@ func (s *Store) MarkConsumed(sessionID string, files []string, sha string) error return nil } - pending := s.LoadAILineAttribution(sessionID).Pending + return s.markConsumedAt(s.LoadAILineAttribution(sessionID).Pending, sessionID, files, sha) +} + +// markConsumedAt writes the retirement markers for a pending snapshot. The +// snapshot is a parameter because it is the boundary this has to be correct +// across: an edit recorded after it was taken is not part of the commit, and +// naming each marker's edit time is what keeps that edit pending. +func (s *Store) markConsumedAt(pending map[string]time.Time, sessionID string, files []string, sha string) error { if len(pending) == 0 { return nil } - now := NowTimestampPrecise() entries := make([]aiLineEntry, 0, len(files)) for _, file := range files { - if _, ok := pending[file]; !ok { + editedAt, ok := pending[file] + if !ok { continue } + // The marker names the edit it retires, so an edit recorded after this + // snapshot is not swept up by a commit that never contained it. entries = append(entries, aiLineEntry{ SessionID: sessionID, File: file, - RecordedAt: now, + RecordedAt: editedAt.Format(time.RFC3339Nano), ConsumedBy: sha, }) } diff --git a/app/cli/internal/trace/state/state.go b/app/cli/internal/trace/state/state.go index 83e3c4da9..1cb46fdcf 100644 --- a/app/cli/internal/trace/state/state.go +++ b/app/cli/internal/trace/state/state.go @@ -180,6 +180,14 @@ func (s *Store) GCOrphans(liveSHAs map[string]bool) error { // // Liveness is deliberately not consulted: session-end does not always run, so // a leaked record stays Active forever and would never expire. +// +// Uncommitted attribution is deliberately not spared either, so a week-old +// edit that is committed later is attributed to nobody rather than to the +// session that made it. That is the safe direction: keeping the entry means a +// session nothing has heard from in a week can still claim a file and pull the +// whole commit's diff into its evidence, and by then its transcript is usually +// gone — raw/ is wiped on every push — so the attestation it wins yields +// nothing anyway. Under-crediting beats crediting the wrong session. func (s *Store) staleSessionIDs(unattested map[string]struct{}) map[string]struct{} { records, err := s.LoadAllSessionRecords() if err != nil { @@ -328,13 +336,3 @@ func removeIfExists(path string) error { func NowTimestamp() string { return time.Now().UTC().Format(time.RFC3339) } - -// NowTimestampPrecise returns the current UTC time in RFC3339 format with -// sub-second precision. Used where two events have to be ordered against each -// other — second resolution is too coarse to tell which of two edits to the -// same file came last. Callers must compare parsed times, not the strings: -// fractional-second forms do not sort lexicographically against whole-second -// ones. -func NowTimestampPrecise() string { - return time.Now().UTC().Format(time.RFC3339Nano) -} diff --git a/app/cli/internal/trace/state/state_test.go b/app/cli/internal/trace/state/state_test.go index 7a9396815..f47edb91e 100644 --- a/app/cli/internal/trace/state/state_test.go +++ b/app/cli/internal/trace/state/state_test.go @@ -427,32 +427,60 @@ func TestAILinePendingTracking(t *testing.T) { assert.NotContains(t, attr.Files, "untouched.go") }) - t.Run("pending carries the time of the most recent edit", func(t *testing.T) { - // Second resolution cannot order two sessions editing one file, so the - // recorded timestamps must be finer than that. + t.Run("pending records the edit time with sub-second precision", func(t *testing.T) { + // Second resolution cannot order two sessions editing one file, so what + // round-trips through the ledger has to keep the fraction. store := NewGitStore(t.TempDir()) require.NoError(t, store.InitTraceDir()) + at := time.Date(2026, 4, 28, 10, 0, 0, 123456789, time.UTC) + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, at)) + + assert.Equal(t, at, store.LoadAILineAttribution("sess-1").Pending[fileA]) + }) + + t.Run("the wall clock supplies a usable edit time", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + before := time.Now().UTC() require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) - require.NoError(t, store.RecordLineRanges("sess-2", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}})) - first := store.LoadAILineAttribution("sess-1").Pending[fileA] - second := store.LoadAILineAttribution("sess-2").Pending[fileA] - require.False(t, first.IsZero()) - require.False(t, second.IsZero()) - assert.True(t, second.After(first), "the later edit must be ordered after the earlier one") + got := store.LoadAILineAttribution("sess-1").Pending[fileA] + require.False(t, got.IsZero(), "an edit with no readable time is never pending") + assert.False(t, got.Before(before.Truncate(time.Second))) }) t.Run("re-editing a file advances its pending time", func(t *testing.T) { store := NewGitStore(t.TempDir()) require.NoError(t, store.InitTraceDir()) - require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) - firstEdit := store.LoadAILineAttribution("sess-1").Pending[fileA] + at := time.Date(2026, 4, 28, 10, 0, 0, 0, time.UTC) + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, at)) + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}}, at.Add(time.Minute))) - require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}})) + assert.Equal(t, at.Add(time.Minute), store.LoadAILineAttribution("sess-1").Pending[fileA]) + }) + + t.Run("a marker does not retire an edit recorded after it was built", func(t *testing.T) { + // MarkConsumed reads the pending set and then appends; an agent editing + // the same file in between leaves a marker sitting behind an edit the + // commit never contained. That edit must stay pending. + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + committed := time.Date(2026, 4, 28, 10, 0, 0, 0, time.UTC) + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, committed)) + + pendingBefore := store.LoadAILineAttribution("sess-1").Pending + require.Contains(t, pendingBefore, fileA) + + // The racing edit lands first, then the marker for the older one. + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}}, committed.Add(time.Second))) + require.NoError(t, store.markConsumedAt(pendingBefore, "sess-1", []string{fileA}, "sha-1")) - assert.True(t, store.LoadAILineAttribution("sess-1").Pending[fileA].After(firstEdit)) + assert.Contains(t, store.LoadAILineAttribution("sess-1").Pending, fileA, + "the edit made after the snapshot was not in the commit") }) t.Run("a ledger written before consumption tracking is never pending", func(t *testing.T) { diff --git a/app/cli/pkg/action/trace_agent_hook.go b/app/cli/pkg/action/trace_agent_hook.go index f50d823b1..9ae6a4fea 100644 --- a/app/cli/pkg/action/trace_agent_hook.go +++ b/app/cli/pkg/action/trace_agent_hook.go @@ -140,6 +140,14 @@ func HandleAgentSessionStart(provider trace.Provider, log zerolog.Logger) error ensureSessionTracked(provider, store, repoRoot, input, log) + // An agent can resume a session after its end hook ran, and the record is + // created once and never upserted, so revive the flag here. Only + // session-start may do this: the tool hooks share ensureSessionTracked, and + // one of those arriving late would resurrect a session that really has + // ended. Revival keeps StartedAt and the metadata captured on the first + // call intact. + setSessionActive(store, input.SessionID, true, log) + // Composing the banner costs a control-plane round trip, so it is only // worth doing for an agent that can put it in front of the user. Cursor // and opencode would discard it, and the developer would have paid the @@ -252,11 +260,6 @@ func ensureSessionTracked(provider trace.Provider, store *state.Store, repoRoot sessionID := input.SessionID if store.SessionRecordExists(sessionID) { - // A resumed session fires session-start again after its end hook ran. - // Reviving the flag keeps StartedAt and the agent metadata captured on - // the first call intact. - setSessionActive(store, sessionID, true, log) - return } diff --git a/app/cli/pkg/action/trace_agent_hook_test.go b/app/cli/pkg/action/trace_agent_hook_test.go index 65961e572..8c86c61e5 100644 --- a/app/cli/pkg/action/trace_agent_hook_test.go +++ b/app/cli/pkg/action/trace_agent_hook_test.go @@ -208,6 +208,31 @@ func TestHandleAgentSessionEnd(t *testing.T) { assert.Equal(t, "2026-03-28T00:00:00Z", rec.StartedAt) assert.Equal(t, "1.2.3", rec.AgentVersion, "metadata captured on the first hook must survive") }) + + t.Run("a late tool hook does not revive an ended session", func(t *testing.T) { + // Only session-start means "resumed". The tool hooks share + // ensureSessionTracked, so reviving there would let one arriving after + // session-end resurrect a session that really has finished, and the + // next no-commit push would attest it. + dir, gitDir := initGitRepo(t) + store := state.NewGitStore(gitDir) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ + SessionID: "abc-123", Provider: providerClaudeCode, Active: false, StartedAt: "2026-03-28T00:00:00Z", + })) + + target := filepath.Join(dir, "late.txt") + require.NoError(t, os.WriteFile(target, []byte("one\n"), 0600)) + + withStdin(t, `{"session_id":"abc-123","tool_name":"Write","tool_input":{"file_path":"`+target+`"}}`) + require.NoError(t, HandleAgentPostToolUse(provider, zerolog.Nop())) + + rec, err := store.LoadSessionRecord("abc-123") + require.NoError(t, err) + require.NotNil(t, rec) + assert.False(t, rec.Active) + }) } func TestAutoInstallGitHooks(t *testing.T) { diff --git a/app/cli/pkg/action/trace_hook_handler_test.go b/app/cli/pkg/action/trace_hook_handler_test.go index dbdab68b2..0beab3071 100644 --- a/app/cli/pkg/action/trace_hook_handler_test.go +++ b/app/cli/pkg/action/trace_hook_handler_test.go @@ -550,12 +550,17 @@ func TestCommitLifecycle_LaterSessionSupersedesFinishedOne(t *testing.T) { shared := filepath.Join(dir, "shared.go") + // Explicit edit times: the wall clock does not reliably advance between two + // calls on a host with a coarse clock, and which edit came last is the + // whole point here. + firstEdit := time.Now().UTC().Add(-time.Hour) + // Session one edits the file, then ends without committing. require.NoError(t, os.WriteFile(shared, []byte("package main\n"), 0600)) require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ SessionID: "sess-first", Provider: providerClaudeCode, Active: true, StartedAt: state.NowTimestamp(), })) - require.NoError(t, store.RecordLineRanges("sess-first", "shared.go", []aicodingsession.LineRange{{Start: 1, End: 1}})) + require.NoError(t, store.RecordLineRangesAt("sess-first", "shared.go", []aicodingsession.LineRange{{Start: 1, End: 1}}, firstEdit)) setSessionActive(store, "sess-first", false, zerolog.Nop()) // Session two edits the same file afterwards. @@ -563,7 +568,7 @@ func TestCommitLifecycle_LaterSessionSupersedesFinishedOne(t *testing.T) { require.NoError(t, store.SaveSessionRecord(&state.SessionRecord{ SessionID: "sess-second", Provider: providerClaudeCode, Active: true, StartedAt: state.NowTimestamp(), })) - require.NoError(t, store.RecordLineRanges("sess-second", "shared.go", []aicodingsession.LineRange{{Start: 3, End: 3}})) + require.NoError(t, store.RecordLineRangesAt("sess-second", "shared.go", []aicodingsession.LineRange{{Start: 3, End: 3}}, firstEdit.Add(time.Minute))) msg := filepath.Join(dir, "msg") require.NoError(t, os.WriteFile(msg, []byte("feat: shared\n"), 0600)) From 5f2d38dc3d014e81f69b0eda41feebc15578b626 Mon Sep 17 00:00:00 2001 From: "Jose I. Paris" Date: Mon, 14 Sep 2026 16:43:32 +0200 Subject: [PATCH 4/4] fix(trace): retire a consumed edit by ledger position, not timestamp MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Bounding a consumption marker with the retired edit's timestamp left the race it was meant to close open at the edges: a racing edit that landed in the same clock tick compared equal, so the marker swept it up and the session lost credit for work still in the working tree. Timestamps cannot settle this — that is the same coarse-clock tie the ordering tests had to stop relying on. Pending entries now carry their position in the ledger alongside the edit time, and a marker records the position it retires. Positions come from an append-only file, so they are unique and strictly increasing no matter what the clock does, and an edit appended after the snapshot sits past the marker's bound and stays pending. A marker without a position retires the file outright, matching the behaviour of the markers written before the field existed. Ownership between sessions still goes by edit time: positions from different ledgers are not comparable. Signed-off-by: Jose I. Paris --- app/cli/internal/trace/state/ailines.go | 81 +++++++++++-------- app/cli/internal/trace/state/state_test.go | 52 ++++++++++-- app/cli/pkg/action/trace_hook_handler.go | 6 +- app/cli/pkg/action/trace_hook_handler_test.go | 20 ++--- 4 files changed, 108 insertions(+), 51 deletions(-) diff --git a/app/cli/internal/trace/state/ailines.go b/app/cli/internal/trace/state/ailines.go index b2e270cc6..b976b7a7a 100644 --- a/app/cli/internal/trace/state/ailines.go +++ b/app/cli/internal/trace/state/ailines.go @@ -31,16 +31,26 @@ import ( type AILineAttribution struct { SessionID string `json:"session_id"` Files map[string][]aicodingsession.LineRange `json:"files"` - // Pending maps each file whose recorded ranges have not been committed yet - // to the time of its most recent edit, and is the only set a new commit may - // be matched against. Files keeps every range ever recorded because - // push-time enrichment needs the full history, but matching against it - // credits a finished session on every later commit that happens to touch a - // file it once edited. - // - // The timestamp resolves which session owns a file two of them both have - // pending: the later edit rewrote the earlier one's lines. - Pending map[string]time.Time `json:"-"` + // Pending holds each file whose recorded ranges have not been committed + // yet, and is the only set a new commit may be matched against. Files keeps + // every range ever recorded because push-time enrichment needs the full + // history, but matching against it credits a finished session on every + // later commit that happens to touch a file it once edited. + Pending map[string]PendingEdit `json:"-"` +} + +// PendingEdit is an uncommitted edit to one file. +type PendingEdit struct { + // At is when the edit was made. Ownership of a file that two sessions both + // have pending goes to the later edit, which rewrote the earlier one's + // lines. + At time.Time + // Seq is the edit's position in its ledger, counting from one. Retiring an + // edit is keyed off this rather than At because wall-clock times tie on a + // host with a coarse clock, whereas an append-only ledger's positions are + // unique and strictly increasing. Positions from different ledgers are not + // comparable, which is why ownership still goes by At. + Seq int } // newAILineAttribution returns an AILineAttribution with initialized maps. @@ -48,7 +58,7 @@ func newAILineAttribution(sessionID string) *AILineAttribution { return &AILineAttribution{ SessionID: sessionID, Files: make(map[string][]aicodingsession.LineRange), - Pending: make(map[string]time.Time), + Pending: make(map[string]PendingEdit), } } @@ -64,18 +74,22 @@ type aiLineEntry struct { SessionID string `json:"session_id,omitempty"` File string `json:"file"` Ranges []aicodingsession.LineRange `json:"ranges"` - // RecordedAt is the RFC3339 timestamp of the edit this entry describes, - // with sub-second precision so two sessions editing one file can be - // ordered. On a ConsumedBy marker it is the time of the edit being - // retired, not when the marker was written. Entries written before this - // field existed have none, and are never treated as pending — those - // ledgers predate consumption tracking, so their files would otherwise - // keep crediting their session forever. + // RecordedAt is the RFC3339 timestamp of the edit, with sub-second + // precision so two sessions editing one file can be ordered. Entries + // written before this field existed have none, and are never treated as + // pending — those ledgers predate consumption tracking, so their files + // would otherwise keep crediting their session forever. RecordedAt string `json:"recorded_at,omitempty"` // ConsumedBy is the SHA of the commit that committed the file's pending // ranges. Set only on marker entries appended by MarkConsumed, which // clear the file from Pending instead of contributing ranges. ConsumedBy string `json:"consumed_by,omitempty"` + // ConsumedSeq is the ledger position of the edit a marker retires. It + // bounds the marker to the snapshot MarkConsumed read, so an edit appended + // afterwards — which the commit cannot have contained — keeps its pending + // state. Zero on a marker written before this field existed, which retires + // the file outright. + ConsumedSeq int `json:"consumed_seq,omitempty"` } // LoadAILineAttribution loads the AI line attribution for a session by @@ -93,12 +107,14 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { // Entries are appended in order, so replaying them in order lets a file // go pending -> consumed -> pending again across successive edits and // commits. + seq := 0 dec := json.NewDecoder(f) for dec.More() { var entry aiLineEntry if err := dec.Decode(&entry); err != nil { break } + seq++ if entry.SessionID != "" { attr.SessionID = entry.SessionID } @@ -107,11 +123,10 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { // Retire only the edit the commit actually contained. A concurrent // RecordLineRanges can land between MarkConsumed reading the // pending set and appending its markers, leaving a marker behind an - // edit it never saw; that edit's later timestamp keeps it pending. - // A marker with no readable time predates this and retires the file - // outright. - consumedAt, err := time.Parse(time.RFC3339, entry.RecordedAt) - if err != nil || !attr.Pending[entry.File].After(consumedAt) { + // edit it never saw; that edit sits past the marker's snapshot, so + // it keeps its pending state. + cur, pending := attr.Pending[entry.File] + if pending && (entry.ConsumedSeq == 0 || cur.Seq <= entry.ConsumedSeq) { delete(attr.Pending, entry.File) } @@ -123,7 +138,7 @@ func (s *Store) LoadAILineAttribution(sessionID string) *AILineAttribution { // predates consumption tracking, in which case its session is long // gone, or it cannot be ordered against a competing session's edit. if recordedAt, err := time.Parse(time.RFC3339, entry.RecordedAt); err == nil { - attr.Pending[entry.File] = recordedAt + attr.Pending[entry.File] = PendingEdit{At: recordedAt, Seq: seq} } } @@ -164,25 +179,25 @@ func (s *Store) MarkConsumed(sessionID string, files []string, sha string) error // markConsumedAt writes the retirement markers for a pending snapshot. The // snapshot is a parameter because it is the boundary this has to be correct // across: an edit recorded after it was taken is not part of the commit, and -// naming each marker's edit time is what keeps that edit pending. -func (s *Store) markConsumedAt(pending map[string]time.Time, sessionID string, files []string, sha string) error { +// pinning each marker to the position of the edit it retires is what keeps that +// edit pending. +func (s *Store) markConsumedAt(pending map[string]PendingEdit, sessionID string, files []string, sha string) error { if len(pending) == 0 { return nil } entries := make([]aiLineEntry, 0, len(files)) for _, file := range files { - editedAt, ok := pending[file] + edit, ok := pending[file] if !ok { continue } - // The marker names the edit it retires, so an edit recorded after this - // snapshot is not swept up by a commit that never contained it. entries = append(entries, aiLineEntry{ - SessionID: sessionID, - File: file, - RecordedAt: editedAt.Format(time.RFC3339Nano), - ConsumedBy: sha, + SessionID: sessionID, + File: file, + RecordedAt: edit.At.Format(time.RFC3339Nano), + ConsumedBy: sha, + ConsumedSeq: edit.Seq, }) } diff --git a/app/cli/internal/trace/state/state_test.go b/app/cli/internal/trace/state/state_test.go index f47edb91e..eca33f226 100644 --- a/app/cli/internal/trace/state/state_test.go +++ b/app/cli/internal/trace/state/state_test.go @@ -436,7 +436,7 @@ func TestAILinePendingTracking(t *testing.T) { at := time.Date(2026, 4, 28, 10, 0, 0, 123456789, time.UTC) require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, at)) - assert.Equal(t, at, store.LoadAILineAttribution("sess-1").Pending[fileA]) + assert.Equal(t, at, store.LoadAILineAttribution("sess-1").Pending[fileA].At) }) t.Run("the wall clock supplies a usable edit time", func(t *testing.T) { @@ -447,19 +447,23 @@ func TestAILinePendingTracking(t *testing.T) { require.NoError(t, store.RecordLineRanges("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}})) got := store.LoadAILineAttribution("sess-1").Pending[fileA] - require.False(t, got.IsZero(), "an edit with no readable time is never pending") - assert.False(t, got.Before(before.Truncate(time.Second))) + require.False(t, got.At.IsZero(), "an edit with no readable time is never pending") + assert.False(t, got.At.Before(before.Truncate(time.Second))) }) - t.Run("re-editing a file advances its pending time", func(t *testing.T) { + t.Run("re-editing a file advances its pending edit", func(t *testing.T) { store := NewGitStore(t.TempDir()) require.NoError(t, store.InitTraceDir()) at := time.Date(2026, 4, 28, 10, 0, 0, 0, time.UTC) require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, at)) + first := store.LoadAILineAttribution("sess-1").Pending[fileA] + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}}, at.Add(time.Minute))) - assert.Equal(t, at.Add(time.Minute), store.LoadAILineAttribution("sess-1").Pending[fileA]) + second := store.LoadAILineAttribution("sess-1").Pending[fileA] + assert.Equal(t, at.Add(time.Minute), second.At) + assert.Greater(t, second.Seq, first.Seq, "ledger positions must advance with each append") }) t.Run("a marker does not retire an edit recorded after it was built", func(t *testing.T) { @@ -483,6 +487,44 @@ func TestAILinePendingTracking(t *testing.T) { "the edit made after the snapshot was not in the commit") }) + t.Run("a racing edit sharing the snapshot's timestamp still survives", func(t *testing.T) { + // Same as above, but the racing edit lands in the same clock tick as the + // one being retired. Retirement is keyed off the ledger position rather + // than the time precisely so a tie here cannot sweep it up. + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + tick := time.Date(2026, 4, 28, 10, 0, 0, 0, time.UTC) + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, tick)) + + pendingBefore := store.LoadAILineAttribution("sess-1").Pending + require.Contains(t, pendingBefore, fileA) + + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 8, End: 9}}, tick)) + require.NoError(t, store.markConsumedAt(pendingBefore, "sess-1", []string{fileA}, "sha-1")) + + assert.Contains(t, store.LoadAILineAttribution("sess-1").Pending, fileA, + "an identical timestamp must not make the later edit indistinguishable") + }) + + t.Run("a marker with no ledger position retires the file outright", func(t *testing.T) { + store := NewGitStore(t.TempDir()) + require.NoError(t, store.InitTraceDir()) + + require.NoError(t, store.RecordLineRangesAt("sess-1", fileA, []aicodingsession.LineRange{{Start: 1, End: 5}}, time.Now().UTC())) + + // A marker shaped like the ones written before consumed_seq existed. + path := store.aiLinesPath("sess-1") + legacy := `{"session_id":"sess-1","file":"` + fileA + `","ranges":null,"consumed_by":"sha-1"}` + "\n" + f, err := os.OpenFile(path, os.O_APPEND|os.O_WRONLY, 0600) + require.NoError(t, err) + _, err = f.WriteString(legacy) + require.NoError(t, err) + require.NoError(t, f.Close()) + + assert.NotContains(t, store.LoadAILineAttribution("sess-1").Pending, fileA) + }) + t.Run("a ledger written before consumption tracking is never pending", func(t *testing.T) { // Ledgers already on disk have no recorded_at, and their sessions are // long gone. Treating them as pending would keep stamping those diff --git a/app/cli/pkg/action/trace_hook_handler.go b/app/cli/pkg/action/trace_hook_handler.go index 03adb2572..ef29356fc 100644 --- a/app/cli/pkg/action/trace_hook_handler.go +++ b/app/cli/pkg/action/trace_hook_handler.go @@ -123,15 +123,15 @@ func matchSessionsToFiles(attrs []*state.AILineAttribution, files []string) []st owners := make(map[string]fileOwner, len(fileSet)) for _, attr := range attrs { - for filePath, editedAt := range attr.Pending { + for filePath, edit := range attr.Pending { if _, staged := fileSet[filePath]; !staged { continue } - if cur, claimed := owners[filePath]; claimed && !cur.supersededBy(attr.SessionID, editedAt) { + if cur, claimed := owners[filePath]; claimed && !cur.supersededBy(attr.SessionID, edit.At) { continue } - owners[filePath] = fileOwner{sessionID: attr.SessionID, editedAt: editedAt} + owners[filePath] = fileOwner{sessionID: attr.SessionID, editedAt: edit.At} } } diff --git a/app/cli/pkg/action/trace_hook_handler_test.go b/app/cli/pkg/action/trace_hook_handler_test.go index 0beab3071..157b009a3 100644 --- a/app/cli/pkg/action/trace_hook_handler_test.go +++ b/app/cli/pkg/action/trace_hook_handler_test.go @@ -63,17 +63,17 @@ func TestMatchSessionsToFiles(t *testing.T) { { SessionID: sessionA, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{srcFoo: edited}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited}}, }, { SessionID: sessionB, Files: map[string][]aicodingsession.LineRange{srcBar: {{Start: 1, End: 5}}}, - Pending: map[string]time.Time{srcBar: edited}, + Pending: map[string]state.PendingEdit{srcBar: {At: edited}}, }, { SessionID: "session-c", Files: map[string][]aicodingsession.LineRange{srcBaz: {{Start: 1, End: 3}}}, - Pending: map[string]time.Time{srcBaz: edited}, + Pending: map[string]state.PendingEdit{srcBaz: {At: edited}}, }, } @@ -109,7 +109,7 @@ func TestMatchSessionsToFiles(t *testing.T) { committed := []*state.AILineAttribution{{ SessionID: sessionA, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{}, + Pending: map[string]state.PendingEdit{}, }} assert.Nil(t, matchSessionsToFiles(committed, []string{srcFoo})) @@ -129,12 +129,12 @@ func TestMatchSessionsToFiles(t *testing.T) { { SessionID: sessionA, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{srcFoo: edited}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited}}, }, { SessionID: sessionB, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{srcFoo: edited.Add(time.Minute)}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited.Add(time.Minute)}}, }, } @@ -151,12 +151,12 @@ func TestMatchSessionsToFiles(t *testing.T) { srcFoo: {{Start: 1, End: 10}}, srcBar: {{Start: 1, End: 5}}, }, - Pending: map[string]time.Time{srcFoo: edited, srcBar: edited}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited}, srcBar: {At: edited}}, }, { SessionID: sessionB, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{srcFoo: edited.Add(time.Minute)}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited.Add(time.Minute)}}, }, } @@ -168,12 +168,12 @@ func TestMatchSessionsToFiles(t *testing.T) { { SessionID: "session-z", Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{srcFoo: edited}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited}}, }, { SessionID: sessionA, Files: map[string][]aicodingsession.LineRange{srcFoo: {{Start: 1, End: 10}}}, - Pending: map[string]time.Time{srcFoo: edited}, + Pending: map[string]state.PendingEdit{srcFoo: {At: edited}}, }, }