PMM-15271 Keep collecting Enhanced Monitoring when one log stream is missing - #123
PMM-15271 Keep collecting Enhanced Monitoring when one log stream is missing#123marcuscruz-percona wants to merge 33 commits into
Conversation
|
@percona/platform-code-review-be, please review the current pull request |
There was a problem hiding this comment.
Pull request overview
Improves Enhanced Monitoring resilience when CloudWatch log streams are unavailable.
Changes:
- Filters disabled monitoring and isolates missing streams.
- Expires stale samples and adds health metrics.
- Adds extensive scraper, resolver, and collector tests.
Reviewed changes
Copilot reviewed 16 out of 16 changed files in this pull request and generated 2 comments.
Show a summary per file
| File | Description |
|---|---|
VERSION |
Bumps release to 0.7.5. |
sessions/sessions.go |
Resolves resource IDs and monitoring intervals. |
sessions/sessions_test.go |
Removes brittle resource-ID assertions. |
sessions/resolver_test.go |
Tests paginated state resolution. |
enhanced/window_test.go |
Tests request-window behavior. |
enhanced/streams.go |
Tracks and reprobes missing streams. |
enhanced/streams_test.go |
Tests batching, isolation, and probes. |
enhanced/scraper.go |
Implements resilient collection flow. |
enhanced/scraper_test.go |
Tests scraper refresh and collection. |
enhanced/fake_logs_test.go |
Adds a scriptable CloudWatch fake. |
enhanced/events_test.go |
Tests event handling and lifecycle. |
enhanced/errors.go |
Classifies collection errors. |
enhanced/errors_test.go |
Tests error classification. |
enhanced/collector.go |
Adds expiry and health metrics. |
enhanced/collector_test.go |
Tests caching, expiry, and concurrency. |
.golangci.yml |
Adjusts lint configuration. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
|
@copilot resolve the merge conflicts in this pull request |
Resolved. I merged |
Review findings and what happened to eachTwo passes over Fixed
Findings 1 and 2 were caught by tests written to fail first: Checked, deliberately not changed
Test gaps still openRecorded rather than closed, since none of them hides a defect I could demonstrate:
Verification after all of the aboveDoes the reported bug still get fixed: yes, and the same two layers as before. |
Test gaps closedThe four gaps I listed as still open in my earlier review summary now have tests, in
Each one was confirmed to fail first, by reverting the behaviour it covers and watching it go red:
One new helper: VerificationThe two The remaining local test failures are the pre-existing ones that need live AWS credentials: Not changedBudget exhaustion still reports The naming and structural smells I listed as deliberately deferred are still deferred. |
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 16 out of 16 changed files in this pull request and generated no new comments.
Suppressed comments (1)
enhanced/scraper.go:419
- A successful first page already proves that every requested stream exists, but
clearAcceptedruns only after the entire paginator finishes. If a recovered stream's probe returns one page and a later page is throttled or otherwise fails, this early return leaves the stream excluded for another five minutes; repeated pagination failures can prevent it from healing indefinitely. Clear the exclusions after the first successfulNextPage(the operation is idempotent), while still returning the later page error so the request window does not advance.
output, err := paginator.NextPage(ctx)
if err != nil {
return fmt.Errorf("failed to filter log events: %w", err)
}
Narrow the scraper's client field to the SDK's FilterLogEventsAPIClient interface, which the paginator already accepts, so enhanced metrics collection can be tested without AWS credentials.
The budget bounding how many extra requests a scrape may spend on finding missing log streams was reset once per scrape. A batch whose streams were all missing consumed it, leaving the batches after it unable to isolate their own missing stream, so healthy instances sharing those batches reported nothing until the first batch converged over several scrapes. The budget is now scoped to the batch that needs it, which keeps the per-batch bound that protects the CloudWatch request quota.
NewCollector filled the monitored instance set inside the loop that starts the scrapers, without holding the lock. From the second session on, the drain goroutine of an earlier session could already be in setMetrics, whose prune reads that set under the lock, which made the two race. The set is now complete before the first scraper starts, and nothing writes it afterwards.
The scrape interval and the metric TTL derived from it were computed once, from the instance states read at startup. A session whose instances all had Enhanced Monitoring disabled therefore kept scraping every 60s even after AWS started reporting a 1s interval, and the sample TTL stayed on the startup value too. The scraper now derives its interval from the instance states it refreshes, and resets its ticker when they change. The interval travels with the scrape result, so the collector's expiry follows it.
The probe deadline of an excluded stream was only ever set by the exclusion itself, which happens on ResourceNotFoundException. A stream that existed again but had published nothing inside the request window therefore kept a deadline in the past, stayed due on every scrape, and held one of the scrape's probe slots for good. With more such streams than slots, the streams that had genuinely come back were never probed again. Streams that CloudWatch accepted without returning an event now get another TTL, and an exclusion is dropped as soon as AWS reports Enhanced Monitoring off for the instance, since the stream is not requested at all from then on.
setMetrics refused any sample not newer than the stored one, and prune keeps the event timestamp of an instance whose payload it released. An instance whose replacement publishes timestamps older than the retired one's last event - a clock trailing by more than the retention - was therefore refused for good. A released payload has nothing left to protect, so the guard now applies only while one is held.
setMetrics read the wall clock twice while the functions it sits next to, collectSamples and prune, already take it as a parameter. Passing it in makes the retention boundary testable.
Nothing ever read it, and the assignment forced NewCollector to build the collector in two steps.
A missing log stream is counted once, when it is excluded, so that a permanently missing stream does not inflate the counter on every scrape. The help text promised one count per failed scrape.
Keep only the ones carrying a reason the code cannot state itself, and rename betterTimes to newestEventTimes, which is what it returns.
Matches the grouping the stream and window tests already use.
- a probe that finds the stream still missing keeps it excluded, waits another TTL and is not reported twice - probes stay staggered when every stream of a fleet is missing - a scrape that runs out of time during isolation leaves the batches behind it for the next one, without moving the request window - the self metrics carry the label sets PMM alerts on - a resolver failure leaves the missing set alone
The scraper gives every scrape of its loop the interval as a deadline, but the first one, run synchronously so the collector has all metric descriptions, ran on the collector's own context. Isolating missing log streams spends extra requests per batch, so a region where no log stream exists could hold NewCollector - and with it the metrics server - for as long as AWS kept answering. Sending a result now reports whether the scraper is stopping instead of selecting inline, which also gives the guard against blocking on an undrained channel a test of its own.
halves reads as a count of halves rather than the divisor it is, and due answered true for a log stream that was never excluded - a branch its only caller, which checks marked first, cannot reach.
…clock errorKind's not_found branch cannot be reached through a scrape, because isolation counts a missing log stream itself, and neither that branch nor a nil error was exercised. A table also pins the one ordering that matters: a refused credential must never be classified as a missing stream, since only not_found may exclude one. Stop, a session without instances, and a sample whose event is already older than its TTL had no test either. The last one is worth stating next to maxLookback: an instance whose clock lags further behind than the lookback is never even requested, so it reports a gap and nothing says why.
…dy follows This branch adds the first new files to enhanced and sessions, and reviewdog reports only issues on changed lines, so four checks that the existing code has always violated surfaced here for the first time: - depguard, configured with no allow list, rejects every import outside the standard library, including the AWS SDK the exporter is built on. gomodguard, which polices the same thing at module level, was already disabled for the same reason. - testpackage wants an external test package, but every test file here covers unexported identifiers and lives in the package it tests. - revive's package-comments fires on any new file, since no package in this repository has one. - exhaustruct rejects the empty promlog.Config that main.go and every other test uses to ask for the default logger. The first two accounted for 17 of the 18 issues reviewdog raised, and the remaining one is a test long enough for funlen, now marked as such. The other two came from reproducing reviewdog's diff-scoped view locally, which found three issues it had not reported.
TestSession talks to live AWS and asserted the DbiResourceId of four QA instances literally. AWS mints a new one whenever an instance is recreated, so pmm-qa-aurora3-mysql-instance-1 turned the test red the moment QA rebuilt it -- on this branch and on main alike, which is why main's own last run is red on exactly this test. Assert the shape of the resource ID and take the value from what AWS reported, so the test keeps checking everything it was written to check without failing on a value it does not control. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
A rejected request names no log stream, so answering one is the only positive evidence that every stream listed in it exists. Exclusion waited for an event instead, and a stream that answered without publishing was given another five minutes of exclusion. The request window is only as wide as the fastest instance's reporting interval, so on a fleet mixing intervals a recovered stream usually publishes nothing inside it, and healing took as many probe cycles as it took to catch one event -- hours rather than the five minutes intended. Clear the exclusion when CloudWatch answers the request. That also retires the probe re-arming, which existed to stop a silent stream from holding a probe slot: a stream no longer excluded needs no slot. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
Probe accounting walked the configured instances, so instances sharing a resource ID each listed their stream in the request and each spent a probe slot. Enough duplicates of one missing stream could take every slot of a scrape and keep a stream that had recovered from ever being probed. Count a stream once, and list it once. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
InstanceStates discarded the pages it had read when a later DescribeDBInstances page failed. An instance missing from the result is dropped, and a session left without instances is deleted with it, so one failed page could stop both basic and enhanced collection for a whole AWS key until the exporter restarted -- where the loop this replaced kept the pages that had succeeded. Return the states read so far alongside the error, and apply them. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
WaitGroup.Go replaces the Add/go/Done trio, and with it the constant that had to stay in agreement with the number of goroutines started. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
The comment claimed prune drops a retired resource ID, but the cache is keyed by region and instance, so what it drops is an entry for an instance the collector does not monitor. collectSamples named no subject. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
The two remaining scrape tests built their own background context, so they were the only ones that would not be cancelled with the test. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
Four paths through batch isolation and the state refresh had no test: a half rejected for a reason other than a missing stream, a scrape whose deadline is spent inside DescribeDBInstances, probe fairness across more missing streams than one scrape may probe, and the error an exhausted isolation budget reports. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
fa1fa20 to
f4ee234
Compare
clearAccepted ran only after the paginator drained, so a page failing after the first one left a recovered log stream excluded until its next probe came due, spending a probe slot it no longer needed. CloudWatch rejects the whole request when any single requested stream does not exist, so the first page it answers already proves every stream listed in it does. A request rejected on its first page still clears nothing, because it is no evidence either way. Signed-off-by: Marcus Cruz <marcus.cruz@percona.com>
|
Picking up the suppressed comment from the last review, on Fixed in b415805.
One correction to the reasoning, since it matters for anyone reading this later. The comment said the stream would be "excluded for another five minutes" and that repeated pagination failures "can prevent it from healing indefinitely". Neither holds. So the real cost was narrower than described: the stream kept its exclusion flag for one extra scrape and so kept consuming one of the eight |
PMM-15271 Keep collecting Enhanced Monitoring when one log stream is missing
https://perconadev.atlassian.net/browse/PMM-15271
Problem
After an RDS blue/green switchover, the exporter stopped collecting OS metrics (CPU, memory, disk,
load) for every RDS instance sharing a region and AWS key — not only the instance that switched
over. One monitored instance without an
RDSOSMetricslog stream (Enhanced Monitoring off in AWS, ora freshly promoted instance whose stream does not exist yet) was enough.
The outage was also invisible: the collector re-emitted its last cached sample forever, so graphs
showed flat lines instead of gaps, dashboards looked healthy, and CPU/memory alerts evaluated stale
numbers and could not fire. Recovery required a human to notice and enable Enhanced Monitoring in AWS
(37 minutes in the reported incident).
Root causes
MonitoringIntervalwas read from
DescribeDBInstancesand used only to pick the scrape interval; nothing filtered onit, so an instance that can never have a log stream went into every request.
FilterLogEventsper 100 log streams, and CloudWatch fails the wholerequest with
ResourceNotFoundExceptionwhen any single listed stream is absent. The old codelogged and
breaked, so up to 100 instances got nothing, every scrape, forever.Collectre-emitted every stored sample on every Prometheus scrape.nextStartTimemoved totime.Now()even when ascrape collected nothing, so events that landed late — the blue/green recovery case — were skipped
permanently.
instance's new
DbiResourceIdbefore CloudWatch had created its stream.What changed
The fix proper:
Allow the CloudWatch Logs client to be fakedscraper.svcnarrowed to the SDK's owncloudwatchlogs.FilterLogEventsAPIClient; scriptable fake, so everything below is tested without AWSSkip instances AWS has no Enhanced Monitoring forResourceIDResolverreturnsInstanceState{ResourceID, MonitoringInterval}; the interval is refreshed by the existing 5-minuteDescribeDBInstancescall, so enabling EM later re-admits an instance and disabling it later stops poisoning the batch — zero extra AWS calls (RC1)Split the enhanced scrape into batch, page and event stepsbatches/collectBatch/collectPages/handleEvent/eventSinkKeep collecting when a log stream is missingResourceNotFoundExceptionthe batch is halved until the missing streams are singled out, then excluded with a 5-minute TTL and staggered re-probes. Onlynot_foundmay exclude a stream — throttling and expired credentials never do. Also stops the window advancing on a failed scrape, and clamps it to a 3-minute lookback (RC2, RC4, RC5)Expire stale enhanced metrics and report collection healthmax(3 × interval, 3m); the cache is keyed by{region, instance}instead of resource ID, so a switchover overwrites instead of duplicating a label set; three self-metrics (RC3)Report collection health for every monitored instanceup 0instead of having no series at all, and a long outage keeps reportingup 0rather than resolving its own alert when the entry is prunedIgnore log events timestamped in the futureGive each batch its own log stream isolation budgetDefects found in the above while reviewing it, fixed in the same PR:
Build the monitored instance set before starting scrapersFollow the monitoring interval AWS reports while runningRe-arm the probe of a log stream that returned no eventsRestore an instance whose sample payload was releasedBound the first enhanced scrape by the scrape intervalNewCollector— and with it the metrics server — for as long as AWS kept answeringName the log stream bisect helpers for what they dohalvesread as a count rather than the divisor it is, anddueanswered true for a stream that was never excluded — a branch its only caller cannot reachRaised in review and fixed here:
Stop excluding a stream CloudWatch answeredSpend one probe slot per log streamLogStreamNamesare gone with itKeep the instance states already resolvedInstanceStatesdiscarded the pages it had read when a laterDescribeDBInstancespage failed. SinceNewdrops an instance with no resource ID and then deletes a session left without instances, one failed page could stop basic and enhanced collection for a whole AWS key until a restart — a regression against the loop it replaced, which kept the pages that succeededPlus no-behaviour-change commits: the clock passed into
setMetrics, the write-onlysessionsfielddropped, the error-counter help text corrected, comments that restated the code removed,
betterTimesrenamed tonewestEventTimes,WaitGroup.Goin place of theAdd/go/Donetrio,tests grouped under their subject, and three commits closing test gaps — the last of which covers
errorKind's classification (including the orderingthat keeps a refused credential out of
not_found),Stop, a session with no instances, and asample whose event timestamp is already older than its TTL.
Behaviour changes reviewers should know about
anything that relied on the last value always being present. Worth a release note.
rds_exporter_enhanced_upis0for an instance whose Enhanced Monitoring is offin AWS, for as long as it is monitored — so
up == 0alerts want to exclude those instances oraccept a permanent firing.
writer wins) instead of producing a duplicate label set that
promhttprejects.New metrics
rds_exporter_enhanced_upregion,instancerds_exporter_enhanced_last_event_timestamp_secondsregion,instancerds_exporter_enhanced_scrape_errors_totalregion,kindkindis a closed set:context,throttling,auth,not_found,future_event,other.not_foundcounts log streams as they are excluded, not once per scrape, so a permanently missingstream does not inflate it.
Local verification
One commit here is about that test rather than the bug.
sessions.TestSessionwas red onmaintoo,and for the same reason: it asserted a hardcoded
DbiResourceIdforpmm-qa-aurora3-mysql-instance-1, and that QA instance has been recreated since(
db-DFQSTXQUYKPPAFNHGTJ27P5PTU→db-XI52OXEYO3ANQECF54M7WS46EA).main's own last CI run is redon exactly that test and nothing else. Since AWS mints a new resource ID on every instance recreate,
the test now asserts the ID's shape and compares against what AWS reported — it still checks
everything it was written to check, without depending on a value it does not control. The other three
QA instances got the same treatment, so the next recreate does not turn CI red again.
One commit here is about the linter rather than the bug. This branch adds the first new files to
enhancedandsessions, and reviewdog only annotates changed lines, so four checks the existingcode has always violated surfaced for the first time:
depguardwith no allow list (it rejects theAWS SDK;
gomodguard, the same policy at module level, was already disabled),testpackageagainstin-package tests that cover unexported identifiers,
revive'spackage-commentson any new filesince no package here has one, and
exhaustructagainst the emptypromlog.Configthatmain.goitself uses. Configuring those rather than sprinkling 17
//nolintdirectives is why.golangci.ymlis in the diff.
Test functions in
enhancedandsessions: 11 → 49, 118 cases including subtests.Statement coverage of
enhanced: 67.3% → 94.5%, measured without AWS credentials in both cases.New tests cover: the reported scenario end to end, EM-state filtering and its refresh in both
directions, the scrape interval following AWS while running, missing-stream isolation, TTL re-probing
including a probe that finds the stream still missing and one that finds it silent, staggered probes,
resource-ID change invalidation, batch boundaries at 0/1/99/100/101/150 streams, partial results when
a page or an earlier batch fails, a scrape that runs out of time mid-isolation, throttling and expired
credentials never excluding a stream, context cancellation, window advance / non-advance / lookback
clamp, the future-timestamp boundary, sample expiry, the retention boundary, recovery after a payload
is released, redelivered events not extending expiry, the self-metric label sets, concurrent
Collectand
setMetricsunder-race, log injection through an AWS-controlled log stream name, and the rawevent message never reaching the log.
Not covered by this PR
EM off on one instance → the others keep reporting and the disabled one is never requested; enabling
EM without restarting the exporter → self-heal within ~5 minutes; switchover → a gap, not a flat
line, and no
-old1series left behind; a 1-second interval on a large fleet →scrape_errors_total{kind="throttling"}rises and no stream is marked missing.streams are missing at once, a scrape can run out of time while bisecting and leaves the batches
behind it for the next scrape. The request window does not advance, so those events are delayed
rather than lost, and the exclusions accumulated so far make each round cheaper until it converges.
Pinned by a test rather than papered over with another timeout constant.
collected, taken over the instances that reported in that scrape. An instance that reported nothing
in a given scrape therefore does not hold the window back, so an event of its own still inside
CloudWatch's ingestion lag (10–60 s) can fall before the new start time. Only reachable on a fleet
mixing Enhanced Monitoring intervals, unchanged from
main, and out of scope here — a per-instancewindow would be the fix.
key is
region + AWS access keyand role-based instances have no access key. Tracked separatelyunder PMM-13045.
Collector.Stop()is tested but still unreachable:mainregisters the collector and blocks inListenAndServewith no shutdown path. Not this bug.Delivery
VERSION
0.7.4→0.7.5. Tagv0.7.5after merge, then point thesources/rds_exportersubmodulein
Percona-Lab/pmm-submodules(v3) at the tag; the pmm docs version table is bumped in a companionpmm PR.
Backport: the exporter ships from tags with no release branches, so landing this on an earlier PMM 3.x
is a patch tag plus a submodule bump. PMM 2.x is not a cherry-pick — that line predates aws-sdk-go-v2
and
ResourceIDResolver.