Repository navigation
fix(bigtable): skip metrics export if previous write was too recent - #18630
abhishekacharya200 wants to merge 3 commits into
Conversation
Cloud Monitoring rejects points written more often than the metric's 60s sample period. The final export on shutdown often came within 30s of a periodic export, so it failed and logged a warning with a traceback on normal process exit. Fixes googleapis#18576
There was a problem hiding this comment.
Code Review
This pull request introduces a minimum export interval of 30 seconds for the Bigtable client metrics exporter to prevent Cloud Monitoring from rejecting points written too frequently. It tracks the last successful export time and skips subsequent exports if they occur too soon. The review feedback suggests moving the update of _last_export_time outside of the project loop to prevent incorrect state tracking if a batch write fails for one of multiple projects, and ensuring that failures return MetricExportResult.FAILURE.
parthea
left a comment
There was a problem hiding this comment.
LGTM, I added 2 minor observations
…tten A failed write for a later project left the time set by an earlier one, so an immediate retry was skipped. Also close the handler in a finally block in test_close_soon_after_export.
parthea
left a comment
There was a problem hiding this comment.
Thanks @abhishekacharya200!
|
Would the correct fix to add a shutdown hook? We had similar issue in java https://github.com/googleapis/google-cloud-java/blob/main/java-bigtable/google-cloud-bigtable/src/main/java/com/google/cloud/bigtable/data/v2/internal/csm/exporter/BigtableCloudMonitoringExporter.java And how we bypassed it is, mark the process as shutting down, and if export throw an error, catch it with a warning. This way partial success / per project metrics could still go through. |
| # Cloud Monitoring rejects points written more often than the metric's sample | ||
| # period (60s for Bigtable client metrics). Exports that come sooner than half of | ||
| # that after the previous write (e.g. the final export on shutdown) are skipped | ||
| _MIN_EXPORT_INTERVAL_SECONDS = 30 |
There was a problem hiding this comment.
30 seems like a magic number, why 30? should this be 60?
There was a problem hiding this comment.
Using 30 (half the 60s interval) gives plenty of headroom so normal 60s periodic ticks are never skipped due to latency/jitter
See analysis from Gemini below
Why we can't use
60on the client:_last_export_timeis recorded after thecreate_service_time_seriesRPC finishes. If periodic export 1 takes0.4sover the network (finishing att = 60.4s) and periodic export 2 fires on schedule att = 120.0s, the elapsed time between them is59.6s. If our threshold were60,59.6 < 60would be true and every second periodic export would be skipped.
There was a problem hiding this comment.
Following up on #18630 (comment) and #18630 (comment):
When a process exits shortly after a 60s periodic export, teardown triggers a final flush that Cloud Monitoring rejects with 400 (The same issue seen in #18576).
We have 2 potential solutions here:
- shutdown hook (marking the exporter as shutting down, still sending the final RPC, and catching the error with a warning)
or
- the
30stimer check inexport()(skipping the RPC if the last export was< 30sago)
-
Shutdown hook Lets partial writes and other projects go through on exit, since
create_service_time_seriesstill writes any new time series in the batch even when returning400for points exported too recently. However,export()already catches errors and logs a warning today, so we'd still make a rejected400RPC and log a warning on exit—or if we suppress warnings on shutdown, we'd hide real errors for short-lived scripts (< 60s) where teardown is the only export. Also, sinceMeterProvider's built-inatexithook callsexporter.export()beforeexporter.shutdown(), we'd have to passshutdown_on_exit=FalsetoMeterProviderand register our ownatexithook so the shutdown flag is set beforeMeterProvider.shutdown()runs. -
30stimer check inexport()Avoids the400RPC and warning log noise on normal exit, and works without the extra shutdown hook plumbing that is needed for1.. It skips the final< 30sof points on exit for a project that just exported, though if we change_last_export_timeto a per-project dict (dict[str, float]), other projects will still go through.
I'm leaning toward keeping the 30s timer check (updated to track _last_export_time per project) to avoid the warning noise, failed RPC on exit, and atexit plumbing, unless we think preserving the final < 30s of partial time series is worth those trade-offs. Thoughts?
There was a problem hiding this comment.
Thanks for the detailed write up, both of you. I went with the 30 second check and made it per project in 3209ffa: each project keeps its own last write time, so a project that just exported skips the final flush on exit while other projects still go through, and after a partial failure only the failed project is written again. Happy to switch to the shutdown hook instead if you'd rather keep the final partial series.
A recent write to one project no longer holds back exports to the others. Each project records its own last successful write, so a project that just exported skips the final flush while the rest still go through, and after a partial failure only the failed project is written again.
Fixes #18576
When a process exits,
MeterProvider.shutdown()runs one last export throughBigtableMetricsExporter. If a periodic export happened less than ~30 seconds before that, Cloud Monitoring rejects the write ("points were written more frequently than the maximum sampling period configured for the metric"), and the exporter logs it as a warning with a full traceback. With the 60 second export interval this hits about half of all normal exits, and on Cloud Run it shows up as recurring error logs.This follows the same approach as the Go fix for Spanner built-in metrics (googleapis/google-cloud-go#12266): the exporter remembers when it last wrote successfully and skips any export that comes less than 30 seconds (half the 60s sample period) after that write. Skipped exports return
SUCCESSand only log at debug level. The metrics are cumulative, so a skipped periodic export loses nothing. The next write still carries the totals. Failed writes don't update the timestamp, so a failed export is never followed by a skip.Tests:
TestGoogleCloudMetricsHandler::test_close_soon_after_exportruns a realMeterProviderandPeriodicExportingMetricReaderwith a mockedMetricServiceClient: one flush, thenclose(). Onmainthis sends a second write (assert 2 == 1). With this change it doesn't.TestBigtableMetricsExporter::test_export_skipped_if_previous_export_too_recentchecks the 30 second boundary with a patchedtime.monotonic(fails onmaintoo).TestBigtableMetricsExporter::test_export_not_skipped_after_failed_exportchecks that a failed write doesn't count as a recent export.tests/unitpasses locally on Python 3.14 (5497 passed) except two timing assertions intests/unit/data/_cross_sync/test_cross_sync.py(test_wait_async_timeoutand onetest_event_wait_timeout_exceededcase). They fail the same way on unmodifiedmainon my Windows machine and don't touch this code.ruff format,ruff check --select Iandflake8report nothing on the changed files.