Skip to content

fix(sync): let the stale-issue backfill settle #218

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
marcus merged 1 commit into from
Oct 16, 2026
+161 −14
Merged

fix(sync): let the stale-issue backfill settle #218

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
39 changes: 25 additions & 14 deletions internal/sync/backfill.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -72,6 +72,14 @@ func BackfillOrphanEntities(tx *sql.Tx, sessionID string) (int, error) {
return total, nil
}

// latestActionOrder orders action_log rows newest first by time. Ordering the
// text would put this function's own rows, which the driver writes as
// "2026-10-15 14:00:00-07:00", before "2026-10-15T21:00:00Z" rows from the
// same day. julianday parses both, and SQLite's CURRENT_TIMESTAMP, which are
// the formats left after migration 36 rewrote Go String() values. Ties go to
// the row logged last.
const latestActionOrder = `julianday(timestamp) DESC, rowid DESC`

// BackfillStaleIssues inserts synthetic update events for issues whose
// updated_at timestamp is newer than the latest action_log entry.
// This helps sync older data where status changes weren't logged.
Expand All @@ -96,10 +104,10 @@ func BackfillStaleIssues(tx *sql.Tx, sessionID string) (int, error) {
SELECT i.*,
(SELECT timestamp FROM action_log
WHERE entity_id = i.id AND entity_type IN ('issue', 'issues')
ORDER BY timestamp DESC, rowid DESC LIMIT 1) AS last_ts,
ORDER BY ` + latestActionOrder + ` LIMIT 1) AS last_ts,
(SELECT new_data FROM action_log
WHERE entity_id = i.id AND entity_type IN ('issue', 'issues')
ORDER BY timestamp DESC, rowid DESC LIMIT 1) AS last_data,
ORDER BY ` + latestActionOrder + ` LIMIT 1) AS last_data,
(SELECT COUNT(*) FROM action_log
WHERE entity_id = i.id AND entity_type IN ('issue', 'issues')
AND action_type = 'delete' AND undone = 0
Expand Down Expand Up @@ -187,14 +195,13 @@ func BackfillStaleIssues(tx *sql.Tx, sessionID string) (int, error) {
needsUpdate = true
}

updatedAt, haveUpdatedAt := parseAnyTime(updatedAtVal)
lastActionAt, haveLastAction := parseAnyTime(lastActionVal)

// Check updated_at staleness when we have timestamps
if !needsUpdate && updatedAtVal != nil && lastActionVal != nil {
if updatedAt, ok := parseAnyTime(updatedAtVal); ok {
if lastActionAt, ok := parseAnyTime(lastActionVal); ok {
if updatedAt.After(lastActionAt.Add(staleThreshold)) {
needsUpdate = true
}
}
if !needsUpdate && haveUpdatedAt && haveLastAction {
if updatedAt.After(lastActionAt.Add(staleThreshold)) {
needsUpdate = true
}
}

Expand Down Expand Up @@ -230,11 +237,14 @@ func BackfillStaleIssues(tx *sql.Tx, sessionID string) (int, error) {
return count, fmt.Errorf("generate action id: %w", err)
}

// Stamp the row no earlier than the latest action, so it becomes the
// latest action and the next run sees the status it records.
ts := time.Now()
if updatedAtVal != nil {
if parsed, ok := parseAnyTime(updatedAtVal); ok {
ts = parsed
}
if haveUpdatedAt {
ts = updatedAt
}
if haveLastAction && lastActionAt.After(ts) {
ts = lastActionAt
}

if _, err := stmt.Exec(actionID, sessionID, entityID, string(newData), ts); err != nil {
Expand Down Expand Up @@ -497,7 +507,8 @@ func statusMatches(lastData any, currentStatus string) bool {
if err := json.Unmarshal([]byte(raw), &fields); err != nil {
return false
}
val, ok := fields["status"]
// Review actions such as approve nest the issue under "issue".
val, ok := unwrapIssuePayload(fields)["status"]
if !ok || val == nil {
return false
}
Expand Down
136 changes: 136 additions & 0 deletions internal/sync/backfill_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -629,3 +629,139 @@ func TestAnyEventSetsStatusFalsePositive(t *testing.T) {
t.Error("anyEventSetsStatus returned true for 'open' when only 'reopened' exists")
}
}

func mustExec(t *testing.T, db *sql.DB, query string, args ...any) {
t.Helper()
if _, err := db.Exec(query, args...); err != nil {
t.Fatalf("exec %q: %v", query, err)
}
}

// runStaleBackfill runs BackfillStaleIssues in its own transaction.
func runStaleBackfill(t *testing.T, db *sql.DB) int {
t.Helper()
tx, err := db.Begin()
if err != nil {
t.Fatal(err)
}
n, err := BackfillStaleIssues(tx, "ses-test")
if err != nil {
t.Fatal(err)
}
if err := tx.Commit(); err != nil {
t.Fatal(err)
}
return n
}

func TestBackfillStaleIssues_SettlesAfterDelete(t *testing.T) {
db := setupBackfillDB(t)

// A delete logs no data. The backfilled row is stamped with updated_at,
// the same instant as the delete but written with a local offset, which
// sorts before the delete as text.
mustExec(t, db, `INSERT INTO issues (id, title, status, updated_at) VALUES ('td-703', 'Deleted', 'open', '2026-09-30 14:20:48.774338-07:00')`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-703a', 'ses-old', 'create', 'issue', 'td-703', '{"id":"td-703","status":"open"}', '2026-09-30T21:20:40.445832Z', 0)`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-703b', 'ses-old', 'delete', 'issue', 'td-703', '', '2026-09-30T21:20:48.774338Z', 0)`)

if n := runStaleBackfill(t, db); n != 1 {
t.Fatalf("run 1: expected 1 stale backfill, got %d", n)
}
if n := runStaleBackfill(t, db); n != 0 {
t.Fatalf("run 2: expected 0 stale backfills, got %d", n)
}
}

func TestBackfillStaleIssues_SettlesWhenLatestActionPostdatesUpdatedAt(t *testing.T) {
db := setupBackfillDB(t)

mustExec(t, db, `INSERT INTO issues (id, title, status, updated_at) VALUES ('td-704', 'Closed', 'closed', '2026-10-15 14:00:00-07:00')`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-704a', 'ses-old', 'create', 'issue', 'td-704', '{"id":"td-704","status":"open"}', '2026-10-15T20:00:00Z', 0)`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-704b', 'ses-old', 'update', 'issue', 'td-704', '{"id":"td-704"}', '2026-10-15T21:00:05Z', 0)`)

if n := runStaleBackfill(t, db); n != 1 {
t.Fatalf("run 1: expected 1 stale backfill, got %d", n)
}
if n := runStaleBackfill(t, db); n != 0 {
t.Fatalf("run 2: expected 0 stale backfills, got %d", n)
}
}

func TestBackfillStaleIssues_OrdersActionsByTimeAcrossFormats(t *testing.T) {
db := setupBackfillDB(t)

// "2026-10-15 15:00:00-07:00" is 22:00 UTC, an hour after the statusless
// action, although it sorts before it as text and was logged first.
mustExec(t, db, `INSERT INTO issues (id, title, status, updated_at) VALUES ('td-705', 'Closed', 'closed', '2026-10-15 15:00:00-07:00')`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, previous_data, new_data, timestamp, undone)
VALUES ('al-705a', 'ses-old', 'update', 'issue', 'td-705', '{"id":"td-705","status":"open"}', '{"id":"td-705","status":"closed"}', '2026-10-15 15:00:00-07:00', 0)`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-705b', 'ses-old', 'update', 'issue', 'td-705', '{"id":"td-705"}', '2026-10-15T21:00:00Z', 0)`)

if n := runStaleBackfill(t, db); n != 0 {
t.Fatalf("expected 0 stale backfills, got %d", n)
}
}

func TestBackfillStaleIssues_ReadsStatusFromApprovePayload(t *testing.T) {
db := setupBackfillDB(t)

// Approve logs the issue nested under "issue", which the sync engine unwraps.
mustExec(t, db, `INSERT INTO issues (id, title, status, updated_at) VALUES ('td-707', 'Approved', 'closed', '2026-10-15T21:00:00Z')`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-707', 'ses-old', 'approve', 'issue', 'td-707', '{"issue":{"id":"td-707","status":"closed"},"created_review_id":"rv-1"}', '2026-10-15T21:00:00Z', 0)`)

if n := runStaleBackfill(t, db); n != 0 {
t.Fatalf("expected 0 stale backfills, got %d", n)
}
}

func TestBackfillStaleIssues_IgnoresOrphanCreateFromSamePass(t *testing.T) {
db := setupBackfillDB(t)

// The issue has an update but no create, so the orphan backfill adds one,
// stamped with created_at. The update is still the latest action.
mustExec(t, db, `INSERT INTO issues (id, title, status, created_at, updated_at) VALUES ('td-708', 'Closed', 'closed', '2026-10-01T00:00:00Z', '2026-10-15T21:00:00Z')`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, previous_data, new_data, timestamp, undone)
VALUES ('al-708', 'ses-old', 'update', 'issue', 'td-708', '{"id":"td-708","status":"open"}', '{"id":"td-708","status":"closed"}', '2026-10-15T21:00:00Z', 0)`)

tx, err := db.Begin()
if err != nil {
t.Fatal(err)
}
orphans, err := BackfillOrphanEntities(tx, "ses-test")
if err != nil {
t.Fatal(err)
}
stale, err := BackfillStaleIssues(tx, "ses-test")
if err != nil {
t.Fatal(err)
}
if err := tx.Commit(); err != nil {
t.Fatal(err)
}
if orphans != 1 || stale != 0 {
t.Fatalf("expected 1 orphan and 0 stale backfills, got %d and %d", orphans, stale)
}
}

func TestBackfillStaleIssues_SettlesWithoutUpdatedAt(t *testing.T) {
db := setupBackfillDB(t)

// With no updated_at, the backfilled row must still be stamped no earlier
// than the latest action, even one stamped in the future.
mustExec(t, db, `INSERT INTO issues (id, title, status, updated_at) VALUES ('td-709', 'Closed', 'closed', NULL)`)
mustExec(t, db, `INSERT INTO action_log (id, session_id, action_type, entity_type, entity_id, new_data, timestamp, undone)
VALUES ('al-709', 'ses-old', 'delete', 'issue', 'td-709', '', '2999-01-01T00:00:00Z', 0)`)

if n := runStaleBackfill(t, db); n != 1 {
t.Fatalf("run 1: expected 1 stale backfill, got %d", n)
}
if n := runStaleBackfill(t, db); n != 0 {
t.Fatalf("run 2: expected 0 stale backfills, got %d", n)
}
}
Loading