RDS PostgreSQL log reads: finish rotated files in one cycle, keep positions across a restart, report skipped and missing files (#4708)

[erikdarlingdata]

Fixes #4708.

Why

RDS and Aurora PostgreSQL log reads (deadlocks, log events and plan capture, stderr and csvlog) opened only the newest log file. When RDS rotates the log, whatever the previous file received after the last read was never read, and a new stderr file was read from its last 10,000 lines instead of its first line. The read position also lived only in memory, so a restart re-read just the last 10,000 lines of the newest file. #4708 expects the old file to be finished, the new stderr file to be read from its start, and positions to survive a restart. The list of log files was also read as a single page, but RDS answers in pages once an instance holds more files than one page carries (three days of hourly stderr and csv files is about 144), so the newest file, or the file a saved position holds, could be missing from the list the read chose from.

What changes

RdsLogSource (the source all three RDS ingestors share):

• When the position it holds names a file that is no longer the newest, the read finishes that file from its marker first. That chunk is flagged ReadAgain. The position moves to the newest file only when the chunk that reaches the end of the old file is committed (ResumeMarker.NextKey), so a failed store write leaves the position on the old file.
• The newest file is then read from its first line (Marker "0"), stderr as well as csv, instead of its last 10,000 lines.
• Files that rotated between the held file and the newest are counted on the chunk (FilesSkipped). A held file RDS no longer lists is flagged (ResumeFileMissing) and the read falls back to the newest file's bounded tail.
• New: RestorePosition seeds a saved position (never over one the source already holds), CommittedPosition gives the position a commit leaves, MaxPassesPerCycle (4) and RunPassesAsync bound the reads per cycle.
• The list of log files is read in full. ListLogFilesAsync calls DescribeDBLogFiles again with the response's Marker (same instance and postgresql filter each time) until a page carries no Marker, and gathers every page into one list. Every choice after that works on the whole list: the stderr/csv filter, the newest file, the held file and the stale-csv check. A page with no files but a Marker is followed, and a Marker equal to the one the request carried ends the loop, so a bad answer cannot spin. The loop is capped at 20 pages (MaxLogListingPages); at the cap the read goes on with the files it has and logs one Warning that names the instance and the cap, at most once an hour for each instance (no new collection_log measurement). RdsLogSource takes an optional logger for that, and the three ingestors pass theirs to the source they create. ListLogFilesAsync sends no MaxRecords, so each page is the service's default size, which the API reference does not state. A listing that fits on one page was never affected; this guards the listings that page, such as csvlog files alongside stderr or a longer log retention.

Item 1, positions survive a restart (RdsResumeStore.cs, no schema change):

• Each ingestor saves its position to collect.collector_state after the chunk's rows are stored and the in-process position has moved. It loads once per server before that server's first read.
• Rows written, per server, under the collector that owns the ingestor: pg_plan_capture, pg_deadlocks or pg_log_events; state key log_resume (stderr file) or log_resume_csv (csv file), the keys those collectors already declare for the self-hosted tail; value rds|1|<instance>|<marker>|<file>. The file name is last so a | in it cannot break the parse.
• The value is self-describing. The self-hosted value is <offset>|<file> and starts with digits, so neither reader takes the other's value. An unrecognised value is ignored, which means a first read of the newest file.
• The stored file is checked against the RDS file listing by the read itself: not listed gives ResumeFileMissing and today's start rule; listed but older than the newest gives the finish-then-open sequence. A saved position for a different instance (a writer failover) is not used.
• Saving is at-least-once: a crash between the store write and the save re-reads a window, and the rows dedupe on their log hash key.

Item 2, one cycle: each ingestor loops while the chunk says ReadAgain, at most 4 reads, adding the outcomes. A rotation now finishes the old file and reads the new one in the same call (an hourly plan capture no longer lags a cycle). A file with more data than a call returns keeps the cycle reading it up to the bound, and the position stays on it for the next cycle.

Item 3, measurements and wording:

• RdsIngestOutcome carries FilesSkipped and ResumeFileMissing (summed over the passes). The runner records them on the collection_log row as log_files_skipped_by_rotation and log_resume_file_missing, the labels the self-hosted tail uses, through MeasurementsFor.
• WithLogResumeNotes takes a managedRoute flag, which the worker sets for Aurora and RDS targets. Those targets get their own two sentences (RdsLogResumeLostNote, RdsLogFilesSkippedNote) instead of the self-hosted wording about log_directory and a 4 MB window.
• The "in-memory by design" comments in the runner's _rdsPlans block and in RdsCpuIngestor, and the paragraph in the RdsLogSource header, now describe the saved position. The comments in the deadlock and log-event ingestors and the csv carry that say the source keeps an in-memory marker per (instance, file) are still true and are unchanged.

Test plan

• Red first: with the three behaviours switched off (positions not restored or saved, one read per cycle, outcome fields zeroed, measurements and RDS sentences off) 18 of the 26 new tests fail. The 8 that still pass are the ones that hold without the feature: a value that is not an RDS position is ignored (4 cases), the self-hosted tail ignores an RDS value, the value round-trips, a failed store write saves nothing, and the source pin. Green again with the feature restored.
• RdsResumePersistenceTests: restart resumes from the saved position (all three ingestors), csv position under log_resume_csv, a saved file RDS no longer lists is reported missing and the tail is read, non-RDS values ignored, the self-hosted tail ignores an RDS value, load once per server, nothing saved when the store write fails, rotation finished and newest read in one call (all three), at most 4 reads per cycle (all three), files skipped carried on the outcome (all three), measurements only when they happened, the RDS sentences, and a source pin that the runner passes the outcome fields and the worker passes the flag.
• RdsResumeStoreLiveTests against a local PostgreSQL 18.6 cluster (DARLING_TEST_PG): the runner's own state methods write exactly one row (pg_plan_capture, log_resume, rds|1|...), and a new ingestor over the same store resumes from its marker.
• Paging, 8 new tests in RdsLogSourceTests (a fake that answers in pages with a Marker): the newest file on page 2 is the one opened, a restored position whose file is on page 2 is finished and then the newest is opened, the newest .csv on page 2 is chosen, the stale-csv check compares the whole list, a page with no files but a Marker is followed, a repeated Marker ends the loop, a listing that never ends stops at 20 pages and logs the Warning once (again only an hour later, once for each instance, and not again from a second source over the same logger), and a listing with no Marker is requested once. Red first, with the list read as a single page (the source as it was, plus the new logger argument so the cap test compiles): 7 of the 39 tests in the class fail, the eighth new test holds either way. Green with the fix: 39 of 39. The cap test's fake returns a new Marker on every page, because a fixed Marker ends the loop on the second page.
• RdsLogEventIngestorCsvlogTests.ARotation_ReadsTheNewFileFromItsStart_AndWalksItForward and ARotationMidSkip_CountsTheDroppedRecordOnce updated: one call now finishes the old file and opens the next.
• Targeted: the Rds* classes, CollectorMeasurementSeamTests, DocCommentHygiene, LivePostgresCollectionHygieneTests, LiveCleanupConversionRatchetTests, PgLogEventsPipelineTests, RepoFileAdoptionTests: 298 run, 1 failed (LivePostgresCollectionHygieneTests.EveryClassUsingTheSharedStore_IsSerializedOrDocumentsWhyNot, because the new live class was not in the live-postgres collection); fixed, and that class plus the live class and LiveCleanupConversionRatchetTests re-ran clean (27 tests, 0 failed).
• Full Darling.Tests in CI at 7d74d8554: every test passed except PgServerLogTailRotationLiveTests.ALogThatGrewPastTheWindow_DisclosesTheBytesSkipped_AndCollectsTheLastWindow, the intermittent test tracked in Flaky live test: ALogThatGrewPastTheWindow times out with 0 rows read on unrelated PR runs #4719, which this change does not touch.
• Build: 0 warnings, 0 errors.
• Paging change, targeted: the Rds* classes plus DocCommentHygiene, RepoFileAdoption, LivePostgresCollectionHygieneTests, LiveCleanupConversionRatchetTests, CollectorMeasurementSeamTests and PgLogEventsPipelineTests: 456 run, 0 failed, 4 skipped (live).
• Paging change, full Darling.Tests run locally without DARLING_TEST_PG (live tests skip): 17087 total, 0 failed, 1112 skipped, 1 not run (the one [Fact(Explicit = true)] test).
• Full Darling.Tests in CI, live tests included, at the new head.

Worth double-checking

• A restart on the csvlog route can lose the one record that straddled the last read: the partial-record carry is in memory and the saved marker is past it. The next read resyncs and counts it in the csv-discarded measurement. Before this change a restart re-read the newest file's last 10,000 lines, which usually recovered it; the trade is that a restart now also picks up everything since the saved marker instead of only the last 10,000 lines.
• GetCollectorStateAsync and SaveCollectorStateAsync swallow failures by design (no state, keep the older value). A failed load reads as a first contact; a failed save leaves the older saved position. Both are the at-least-once direction.
• A big rotated file takes several cycles to finish (4 reads of up to one API call each per cycle). The position stays on it until it is done.
• The stale-csv check (newestStderr - newestCsv > 5 minutes) no longer tests HasValue on each side, because both sides are plain numbers over the gathered list. The old chains sat under a null-conditional, so on a listing that was present but had no .csv file the empty side already read as 0 (lifted to a nullable number with a value), and the HasValue test only ever held back an omitted list, which now arrives as an empty list and gives 0 minus 0. By reading the code the result is the same in every case, including a listing with stderr files and no .csv file, which reads as stale after 5 minutes as before; no test pins that case, and it was not run against the old code.
• Reading the whole list costs one DescribeDBLogFiles call for each page: an instance whose files fit on one page still costs one call, a larger one costs a few more on every read (at most 20). The three ingestors each own a source, so the once-an-hour Warning is kept for each logger and not for each source; otherwise an instance over the cap would be reported up to three times an hour.

CHANGELOG

SECTION: Fixed
ENTRY:

• RDS and Aurora PostgreSQL log reads now collect the lines a log file received before RDS rotated it, and resume where they stopped after a restart ([RDS PostgreSQL log reads: finish rotated files in one cycle, keep positions across a restart, report skipped and missing files (#4708) #4713]) - Deadlock, log-event and plan-capture reads opened only the newest RDS log file, so whatever the previous file received after the last read was never collected, a new stderr file was read from its last 10,000 lines instead of its first line, and the read position lived only in memory, so a restart re-read just the last 10,000 lines of the newest file. A read now finishes the file it was reading before it moves to the newest one, in the same cycle (at most four reads per cycle), and a new file is read from its first line. Each read saves its position to collect.collector_state once its rows are stored and loads it at start; a saved file RDS no longer lists falls back to the newest file's last 10,000 lines. Files that rotate away entirely between two reads are still not read, but the run now records how many in log_files_skipped_by_rotation, and a missing saved file in log_resume_file_missing, with a sentence on the collection_log row. The read also lists every log file even when the listing is paged (up to 20 pages), so a listing too long for one page can't hide the newest file or the file a saved position names; past 20 pages it uses the files it has and logs a warning, at most once an hour for each instance.
  REF:
  [RDS PostgreSQL log reads: finish rotated files in one cycle, keep positions across a restart, report skipped and missing files (#4708) #4713]: RDS PostgreSQL log reads: finish rotated files in one cycle, keep positions across a restart, report skipped and missing files (#4708) #4713