fix: track outstanding service log files on the rows themselves (#10894)

* fix: track outstanding service log files on the rows themselves

Adds `log_file.indexed_at` so the service log ingest can read outstanding rows
instead of walking a cursor over `log_ts`. A row registered after the pass had
gone by its minute was skipped for good, and no ordering fixes that — an arrival
sequence fails the same way, since a row can take a lower value and commit after
a higher one has moved the cursor past it.

The migration marks existing rows with a sentinel; the first pass returns the
ones the old cursor had not reached to the queue.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01EPAP96jJNYpPQ8bpxZcU1C

* [ee] refactor: drop the claim/confirm phase from the service log ingest queue

Two states are enough: a row is outstanding or it is marked. The migration no
longer creates the index for the claim sentinel, and the sqlx cache loses the
two queries the event-time cursor used.

* [ee] fix: make re-indexing a service log file idempotent

Corrects the `init_last_log_file_sent` note: a rewritten row keeps the
`indexed_at` it had, so one the indexers already took is not offered again.

* [ee] fix: let a rebuild take the rows it covered out of the ingest queue

Adds the query that releases them; the index layout stays v4.

* [ee] fix: index the lookup a rebuild releases rows by

A rebuild takes rows out of the queue by the file it read out of the store, which
is the one lookup that arrives without a `log_ts`. The primary key is
`(hostname, log_ts)`, so nothing covered it and each batch scanned every
outstanding row — worst in exactly the state a rebuild follows. Verified at 50k
outstanding rows: sequential scan becomes an index scan.

Also records `log_file.indexed_at` in the schema reference.

* [ee] fix: treat a state handed back without its line count as behind

* [ee] fix: give the converted state a line count

* [ee] fix: keep the converted cursor from being rewound by the rebuild

* [ee] fix: inherit the legacy cursor from one source, not field by field

* [ee] fix: count a file's lines against the buffer before reading it

* [ee] fix: bound the row buffer on what it holds, not on reported counts

* [ee] fix: settle the upgrade from the store rather than from event time

* [ee] docs: describe the conversion's second half as it now works

* [ee] refactor: settle the upgrade with one rebuild instead of reconciling

The migration records existing rows as done rather than marking them with a
sentinel: the indexer puts back what the old cursor had not reached on its first
pass, which is the only place that cursor's position is known.

* [ee] fix: repair the rows the old cursor skipped instead of recording them as done

The migration marks pre-existing rows with a sentinel again, so the indexer can
tell them from rows registered since and put the window's worth back on the queue.

* [ee] fix: keep a source file whole in one partition

* [ee] revert the file-atomic partition change

* [ee] fix: dedupe the public reads, and repair an index without a cursor

* [ee] fix: repair an index whose cursor is gone, and keep what the repair found

* [ee] fix: seed a pass from both axes of what a rebuild recovered

* [ee] fix: settle the cursor on what the store holds, not on what was read

* [ee] fix: an empty rebuild must not claim ground it has not covered

* [ee] test: pin the cursor a rebuild settles on

* chore: update ee-repo-ref to bc0c7051585194474078b6c1941a3fb73893d9e5

This commit updates the EE repository reference after PR #755 was merged in windmill-ee-private.

Previous ee-repo-ref: 328f5a90afeae9c683bf3294f0d9eb293a3e1a92

New ee-repo-ref: bc0c7051585194474078b6c1941a3fb73893d9e5

Automated by sync-ee-ref workflow.

---------

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Co-authored-by: windmill-internal-app[bot] <windmill-internal-app[bot]@users.noreply.github.com>

AGENTS.md

@@ -165,6 +165,15 @@ $NAV --root backend callees "X"                           # what does X call?
 - Search for existing code to reuse before writing new code
 - Follow established patterns in the codebase
 - Keep changes focused — don't refactor beyond what's asked
+- **A simpler design found late is still the design.** Work already spent is not an argument
+  for a shape, and neither is a clean review round, a passing suite, or a long PR thread. The
+  signal to stop and re-derive rather than patch again is a change that keeps growing to defend
+  its own structure: each review finding fixing an assumption the previous fix broke, the same
+  class of bug reappearing somewhere new, or most of the diff being consequences of one early
+  choice rather than the thing you set out to do. When that happens, say plainly what the
+  simpler design is and what switching costs — a migration, a review cycle restarted from zero,
+  work discarded — and let the user decide. Do not keep paying down the harder one because it
+  is nearly finished, and do not present the accumulated cost as a reason to continue.
 - **Ship only the tests the PR needs.** A committed test must pin behavior a future change could plausibly break, and be the smallest setup that exercises the new logic. While developing, write as many exhaustive tests and do as much manual testing as you need to convince yourself the change works — then remove that scaffolding before marking the PR ready, keeping only the essential regression guard(s). A test that merely re-exercises pre-existing behavior, or needs elaborate fixtures to assert something trivial, is scaffolding: delete it. If nothing meaningful is left to guard, ship no test rather than a ceremonial one.
 - **Comments record constraints, not narration.** Write a comment only for what the code can't show: why a non-obvious approach is required, what breaks if it's "simplified" away. State each invariant once, at the place where someone would break it, in ≤4 lines. Don't describe what the next line does, don't repeat the same rationale at multiple sites, and don't address the PR reviewer (justifying a change belongs in the PR description, not the code). Reference nothing ephemeral — no numbered steps from your dev flow, no "the poller / the test does X" scaffolding, no transient state that won't exist for the next reader; keep only the essential, durable rationale. Describe the code as it is, never its drafting history: "we no longer do X", "unchanged behavior", "instead of the previous approach" are meaningless to a reader who never saw the earlier iteration — before finishing, reread your comments as if the current state is the only state that ever existed.
 - **Never attribute work to a specific customer, account, or "requested by a customer" in repo-tracked content** (PR descriptions, commit messages, code comments, docs). Describe changes by their technical motivation instead.

backend/.sqlx/query-624a7dbc6cc951a199b0e70d86c463a0e7b5248c226ee92d95df94c3099cc400.json

@@ -0,0 +1,15 @@
+{
+  "db_name": "PostgreSQL",
+  "query": "UPDATE log_file SET indexed_at = now()\n         FROM unnest($1::text[], $2::text[]) AS c(hostname, file_path)\n         WHERE log_file.indexed_at IS NULL\n           AND log_file.hostname = c.hostname\n           AND log_file.file_path = c.file_path",
+  "describe": {
+    "columns": [],
+    "parameters": {
+      "Left": [
+        "TextArray",
+        "TextArray"
+      ]
+    },
+    "nullable": []
+  },
+  "hash": "624a7dbc6cc951a199b0e70d86c463a0e7b5248c226ee92d95df94c3099cc400"
+}

backend/.sqlx/query-6bbcb27a3bb70302076c559c8394b14b842f595f68dd885248abaaeabd2d0bf1.json

@@ -1,6 +1,6 @@
 {
   "db_name": "PostgreSQL",
-  "query": "SELECT\n                        hostname,\n                        mode::text,\n                        worker_group,\n                        log_ts,\n                        file_path,\n                        ok_lines,\n                        err_lines,\n                        json_fmt\n                    FROM log_file\n                    WHERE log_ts > $1\n                    ORDER BY log_ts ASC LIMIT $2",
+  "query": "SELECT\n                        hostname,\n                        mode::text,\n                        worker_group,\n                        log_ts,\n                        file_path,\n                        ok_lines,\n                        err_lines,\n                        json_fmt\n                    FROM log_file\n                    WHERE indexed_at IS NULL\n                    ORDER BY log_ts ASC, hostname ASC LIMIT $1",
   "describe": {
     "columns": [
       {
@@ -46,7 +46,6 @@
     ],
     "parameters": {
       "Left": [
-        "Timestamp",
         "Int8"
       ]
     },
@@ -61,5 +60,5 @@
       true
     ]
   },
-  "hash": "b5c839baab25c4dcdd503d380cf7a886242277cd50555f20b2e22e13942d2a3a"
+  "hash": "6bbcb27a3bb70302076c559c8394b14b842f595f68dd885248abaaeabd2d0bf1"
 }

backend/.sqlx/query-8d207cc9ed101ff116b617d25a94633c1531170ded1fdf09114718b941f5e1db.json

@@ -1,65 +0,0 @@
-{
-  "db_name": "PostgreSQL",
-  "query": "SELECT\n                        hostname,\n                        mode::text,\n                        worker_group,\n                        log_ts,\n                        file_path,\n                        ok_lines,\n                        err_lines,\n                        json_fmt\n                    FROM log_file\n                    WHERE log_ts > NOW() - make_interval(secs => $1)\n                    ORDER BY log_ts ASC LIMIT $2",
-  "describe": {
-    "columns": [
-      {
-        "ordinal": 0,
-        "name": "hostname",
-        "type_info": "Varchar"
-      },
-      {
-        "ordinal": 1,
-        "name": "mode",
-        "type_info": "Text"
-      },
-      {
-        "ordinal": 2,
-        "name": "worker_group",
-        "type_info": "Varchar"
-      },
-      {
-        "ordinal": 3,
-        "name": "log_ts",
-        "type_info": "Timestamp"
-      },
-      {
-        "ordinal": 4,
-        "name": "file_path",
-        "type_info": "Varchar"
-      },
-      {
-        "ordinal": 5,
-        "name": "ok_lines",
-        "type_info": "Int8"
-      },
-      {
-        "ordinal": 6,
-        "name": "err_lines",
-        "type_info": "Int8"
-      },
-      {
-        "ordinal": 7,
-        "name": "json_fmt",
-        "type_info": "Bool"
-      }
-    ],
-    "parameters": {
-      "Left": [
-        "Float8",
-        "Int8"
-      ]
-    },
-    "nullable": [
-      false,
-      null,
-      true,
-      false,
-      false,
-      true,
-      true,
-      true
-    ]
-  },
-  "hash": "8d207cc9ed101ff116b617d25a94633c1531170ded1fdf09114718b941f5e1db"
-}

backend/.sqlx/query-8e0461855d05dc03919c8979d8acdc85389c0629847d8fabb2ad0aa043957b2f.json

@@ -0,0 +1,22 @@
+{
+  "db_name": "PostgreSQL",
+  "query": "WITH moved AS (\n                     UPDATE log_file SET indexed_at = CASE\n                         WHEN log_ts > NOW() - make_interval(secs => $1) THEN NULL\n                         ELSE now() END\n                     WHERE indexed_at = 'epoch' RETURNING 1)\n                 SELECT count(*) AS \"n!\" FROM moved",
+  "describe": {
+    "columns": [
+      {
+        "ordinal": 0,
+        "name": "n!",
+        "type_info": "Int8"
+      }
+    ],
+    "parameters": {
+      "Left": [
+        "Float8"
+      ]
+    },
+    "nullable": [
+      null
+    ]
+  },
+  "hash": "8e0461855d05dc03919c8979d8acdc85389c0629847d8fabb2ad0aa043957b2f"
+}

backend/.sqlx/query-947f7ca06f6f9a3fd50f817bc9b0c06924719189bec8e5c19866db8d0b87df5e.json

@@ -0,0 +1,15 @@
+{
+  "db_name": "PostgreSQL",
+  "query": "UPDATE log_file SET indexed_at = now()\n                 FROM unnest($1::text[], $2::timestamp[]) AS c(hostname, log_ts)\n                 WHERE log_file.hostname = c.hostname AND log_file.log_ts = c.log_ts",
+  "describe": {
+    "columns": [],
+    "parameters": {
+      "Left": [
+        "TextArray",
+        "TimestampArray"
+      ]
+    },
+    "nullable": []
+  },
+  "hash": "947f7ca06f6f9a3fd50f817bc9b0c06924719189bec8e5c19866db8d0b87df5e"
+}

backend/.sqlx/query-a7d450e34084d561f69e588bd76fd56e616ee79d895b7dcc37ad9442789e1574.json

@@ -0,0 +1,22 @@
+{
+  "db_name": "PostgreSQL",
+  "query": "WITH retired AS (\n                     UPDATE log_file SET indexed_at = now()\n                     WHERE indexed_at IS NULL\n                       AND log_ts <= NOW() - make_interval(secs => $1) RETURNING 1)\n                 SELECT count(*) AS \"n!\" FROM retired",
+  "describe": {
+    "columns": [
+      {
+        "ordinal": 0,
+        "name": "n!",
+        "type_info": "Int8"
+      }
+    ],
+    "parameters": {
+      "Left": [
+        "Float8"
+      ]
+    },
+    "nullable": [
+      null
+    ]
+  },
+  "hash": "a7d450e34084d561f69e588bd76fd56e616ee79d895b7dcc37ad9442789e1574"
+}

backend/.sqlx/query-b8e732a03969666444f73397ac153d23ec2af084b2f93da24c920532c1916384.json

@@ -98,12 +98,12 @@
       null,
       null,
       null,
-      true,
+      false,
       null,
       null,
       null,
-      true,
-      true
+      false,
+      false
     ]
   },
   "hash": "b8e732a03969666444f73397ac153d23ec2af084b2f93da24c920532c1916384"

backend/ee-repo-ref.txt

@@ -1 +1 @@
-58738c39ac41d57917bbd9400318704763d997f7
+bc0c7051585194474078b6c1941a3fb73893d9e5

backend/migrations/20260830085453_log_file_indexed_at.down.sql

@@ -0,0 +1,4 @@
+DROP INDEX IF EXISTS index_log_file_premigration;
+DROP INDEX IF EXISTS index_log_file_pending_path;
+DROP INDEX IF EXISTS index_log_file_pending;
+ALTER TABLE log_file DROP COLUMN IF EXISTS indexed_at;

backend/migrations/20260830085453_log_file_indexed_at.up.sql

@@ -0,0 +1,35 @@
+-- The service log ingest walked `log_file` with a cursor over `log_ts`, which is when a line
+-- was written rather than when its row appeared. Rows do not arrive in that order — an upload
+-- retried after a failure, a host that has just started, a batch the row limit cut mid-minute —
+-- and a row that becomes visible behind the cursor is never read: it stays in `log_file` and its
+-- lines stay out of search until retention drops them.
+--
+-- No ordering fixes this. A cursor over arrival order fails the same way, because `nextval` is
+-- allocated before its INSERT commits: a row can be assigned a lower value and commit after a
+-- higher one has already moved the cursor past it. Which rows are outstanding is a property of
+-- the rows, so it is recorded on them.
+ALTER TABLE log_file ADD COLUMN indexed_at TIMESTAMPTZ;
+
+-- Rows that already existed are marked, not queued: on a 14-day window most were ingested long
+-- ago and their raw files are gone. A sentinel rather than a timestamp, because the indexer has to
+-- tell them apart from rows registered since — those start NULL — and it puts the window's worth of
+-- them back on the queue on its first pass, keeping only what the columnar store can vouch for.
+--
+-- Not split here on the cursor the old ingest had reached. Below that cursor sits every row it
+-- skipped, which is the loss this migration exists to stop; recording those as done would carry the
+-- bug into its own fix.
+UPDATE log_file SET indexed_at = 'epoch' WHERE indexed_at IS NULL;
+
+-- The work queue, and the only index the ingest query needs: outstanding rows are a small
+-- fraction of the table, so this stays proportional to what is left to do rather than to the
+-- retention window.
+CREATE INDEX index_log_file_pending ON log_file (log_ts) WHERE indexed_at IS NULL;
+
+-- A rebuild takes rows out of the queue by the file it just read out of the store, which is
+-- the one lookup that arrives without a `log_ts`: the primary key is `(hostname, log_ts)`, so
+-- nothing else covers it and each batch would scan every outstanding row instead.
+CREATE INDEX index_log_file_pending_path ON log_file (hostname, file_path) WHERE indexed_at IS NULL;
+
+-- Reached once per pass while pre-migration rows survive, and never again after the first
+-- conversion clears them.
+CREATE INDEX index_log_file_premigration ON log_file (log_ts) WHERE indexed_at = 'epoch';

backend/src/monitor.rs

@@ -1358,9 +1358,9 @@ fn last_log_file_sent() -> Option<NaiveDateTime> {
 /// the file that was still open and the appender reopens that minute in append mode,
 /// so a restart inside it would otherwise strand everything written afterwards.
 ///
-/// A row rewritten this way restores the object and sums the counters, but whether the
-/// indexers read it again depends on their single `log_ts >` cursor, which is not
-/// per-hostname: a minute at or below it stays out of search until it is re-indexed.
+/// A row rewritten this way restores the object and sums the counters, but it keeps the
+/// `indexed_at` it already had, so one the indexers have taken is not offered again and
+/// the lines added by the rewrite stay out of search.
 async fn init_last_log_file_sent(conn: &Connection, hostname: &str) {
     let Some(db) = conn.as_sql() else {
         return;
@@ -1406,9 +1406,10 @@ async fn send_log_files_to_object_store(
         if ts < retention_cutoff {
             continue;
         }
-        // Stop at the first failure rather than moving on: both indexers walk
-        // `log_file` with a `log_ts > watermark` cursor, so a row that lands after
-        // a newer one is never picked up.
+        // Stop at the first failure rather than moving on, so a file is never
+        // registered before an older one that has not made it to the store yet.
+        // The indexers do not depend on that ordering — every row is offered until
+        // it is marked — but a gap here would still be visible while it lasts.
         if !send_log_file_to_object_store(hostname, mode, worker_group, conn, &file_name, ts).await
         {
             break;

backend/summarized_schema.txt

@@ -128,7 +128,7 @@ job_stats: workspace_id(char), job_id(uuid), metric_id(char), metric_name(char),
 kafka_pending_commits: id(bigint), workspace_id(char), kafka_trigger_path(char), topic(char), partition(int), offset(bigint), created_at(ts)
   FK: (workspace_id, kafka_trigger_path) -> kafka_trigger(workspace_id, path)
 kafka_trigger: path(char), kafka_resource_path(char), topics(char), group_id(char), script_path(char), is_flow(bool), workspace_id(char), edited_by(char), email(char), edited_at(ts), extra_perms(jsonb), server_id(char), last_server_ping(ts), error(text), error_handler_path(char), error_handler_args(jsonb), retry(jsonb), mode(trigger_mode), filters(jsonb[]), auto_commit(bool), labels(text[])
-log_file: hostname(char), log_ts(ts), ok_lines(bigint), err_lines(bigint), mode(log_mode), worker_group(char), file_path(char), json_fmt(bool)
+log_file: hostname(char), log_ts(ts), ok_lines(bigint), err_lines(bigint), mode(log_mode), worker_group(char), file_path(char), json_fmt(bool), indexed_at(ts)
 macro_definition: workspace_id(char), name(char), provider_path(char), params(text), body(text), is_table_macro(bool), created_at(ts)
   FK: (workspace_id) -> workspace(id)
 macro_usage: workspace_id(char), consumer_path(char), macro_name(char)