Skip to content

[#11736] improvement(core): id-cursor entity-change poller with per-listener failure retry; document commit-ordering limitation#11739

Open
yuqi1129 wants to merge 3 commits into
mainfrom
me/fix-entity-change-log-poller-11736
Open

[#11736] improvement(core): id-cursor entity-change poller with per-listener failure retry; document commit-ordering limitation#11739
yuqi1129 wants to merge 3 commits into
mainfrom
me/fix-entity-change-log-poller-11736

Conversation

@yuqi1129

@yuqi1129 yuqi1129 commented Jun 18, 2026

Copy link
Copy Markdown
Contributor

What changes were proposed in this pull request?

This PR keeps the EntityChangeLogPoller on its baseline id-cursor (WHERE id > lastConsumedId ORDER BY id, each row delivered exactly once) and makes two focused changes:

  1. Per-listener failure retry. The cursor advances only after every listener applies the batch. If a listener throws, the cursor pauses and the batch is retried only for the listeners that have not applied it yet (already-succeeded listeners are not re-invoked), until all succeed. A persistently stuck cursor is logged at ERROR.

  2. Document the commit-ordering gap as an accepted known limitation (class javadoc): its cause (ids are assigned at INSERT but visible only at COMMIT, so a smaller id can commit after the cursor passed a larger one, and id > cursor then skips it forever), the narrow conditions and low probability under which it occurs, and why no cheap/robust fix exists today.

Background — what was tried and dropped (kept in branch history):

  • An earlier revision switched to a created_at + overlap-window cursor to prevent the miss. The overlap re-delivers rows, which is only safe if every consumer is perfectly idempotent; CatalogManager's cache-invalidation consumer is not, and re-delivery made the poller invalidate and tear down an in-use catalog, closing its IsolatedClassLoader / connection pool → a permanently cached NoClassDefFoundError that failed the Ranger authorization IT suite. Reverted.
  • A follow-up added best-effort detection logging of the gap. It was also removed: it is best-effort only (state lost on restart, bounded lookback page), and the simpler "log on non-contiguous id" alternative is unusable because ids are legitimately non-contiguous (auto_increment_increment > 1, sequence caching, rollbacks) and would only produce noise.

So this PR deliberately ships the safe minimum and documents the rare miss rather than working around it.

Why are the changes needed?

The per-listener retry stops a transient listener failure from silently dropping a batch's invalidations, while avoiding duplicate re-delivery to listeners that already applied it. The commit-ordering miss is rare and, for the catalog cache, already bounded by TTL eviction; both preventing it and reliably detecting it introduce more risk/complexity than the miss warrants today.

Fix: #11736 (partial — listener-failure handling; commit-ordering gap documented as a known limitation, not fixed)

Does this PR introduce any user-facing change?

No new config or API.

How was this patch tested?

TestEntityChangeLogPoller: per-listener retry (no re-dispatch to already-succeeded listeners), cursor-advance-on-recovery, plus the existing dispatch / prune / batch-immutability tests. :core compile + Spotless clean.

Copilot AI review requested due to automatic review settings June 18, 2026 14:43

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR strengthens HA cache invalidation reliability by hardening the shared EntityChangeLogPoller against (a) commit-ordering gaps when using an auto-increment id cursor and (b) cursor advancement when one listener fails, plus it introduces and documents a new polling lag configuration.

Changes:

  • Add a DB-clock-based lag window (pollLagMs / gravitino.entityChangeLog.pollLagSecs) so poll consumption avoids commit-ordering gaps from out-of-order transaction commits.
  • Change cursor advancement semantics so the high-water mark only advances when all listeners successfully apply a batch; failures are retried next cycle.
  • Update mapper/provider signatures and tests to thread the lag through selectEntityChanges, and update config/docs versions to 1.4.0.

Reviewed changes

Copilot reviewed 13 out of 13 changed files in this pull request and generated 4 comments.

Show a summary per file
File Description
docs/gravitino-server-config.md Documents the new gravitino.entityChangeLog.pollLagSecs and updates “since version” for change-log configs.
core/src/main/java/org/apache/gravitino/storage/relational/EntityChangeLogPoller.java Adds poll lag support and changes cursor advancement to be conditional on listener success.
core/src/main/java/org/apache/gravitino/storage/relational/RelationalEntityStore.java Wires pollLagSecs from config into the poller.
core/src/main/java/org/apache/gravitino/storage/relational/mapper/EntityChangeLogMapper.java Extends selectEntityChanges to accept lagMs.
core/src/main/java/org/apache/gravitino/storage/relational/mapper/EntityChangeLogSQLProviderFactory.java Threads lagMs through to DB-specific SQL providers.
core/src/main/java/org/apache/gravitino/storage/relational/mapper/provider/base/EntityChangeLogBaseSQLProvider.java Adds lagging cutoff predicate to change selection SQL.
core/src/main/java/org/apache/gravitino/storage/relational/mapper/provider/postgresql/EntityChangeLogPostgreSQLProvider.java Overrides selection SQL to use PostgreSQL epoch-millis expression for the lag cutoff.
core/src/main/java/org/apache/gravitino/Configs.java Adds ENTITY_CHANGE_LOG_POLL_LAG_SECS config entry and updates versions to 1.4.0.
common/src/main/java/org/apache/gravitino/config/ConfigConstants.java Adds VERSION_1_4_0.
core/src/test/java/org/apache/gravitino/storage/relational/TestEntityChangeLogPoller.java Updates tests for new cursor semantics and mapper signature; adds negative lag validation and recovery tests.
core/src/test/java/org/apache/gravitino/storage/relational/mapper/provider/base/TestEntityChangeLogMapper.java Adds coverage for lag excluding “fresh” rows until they age past the lag window.
core/src/test/java/org/apache/gravitino/storage/relational/service/TestEntityChangeLogService.java Updates mapper call signature in service tests.
core/src/test/java/org/apache/gravitino/storage/relational/service/TestTableMetaService.java Updates mapper call signature in service tests.

Comment thread core/src/main/java/org/apache/gravitino/Configs.java Outdated
Comment thread docs/gravitino-server-config.md Outdated
@yuqi1129 yuqi1129 force-pushed the me/fix-entity-change-log-poller-11736 branch 2 times, most recently from 2bee41e to a1ffcff Compare June 18, 2026 15:20
@yuqi1129

Copy link
Copy Markdown
Contributor Author

Thanks for the review — addressed in e850679:

  1. Cross-field validation (EntityChangeLogPoller): the constructor now rejects retentionMs <= pollLagMs when cleanup is enabled (retentionMs > 0), so a row can never be pruned before it becomes eligible for polling. Added testRejectsRetentionNotGreaterThanLag.
  2. Config / Javadoc / docs wording (Configs, EntityChangeLogBaseSQLProvider, gravitino-server-config.md): dropped the inaccurate "all transactions that started before a consumed row have committed" claim. The wording now states the actual guarantee: a smaller-id row is inserted no later than a larger-id row, so waiting until a row is pollLagMs old gives that row's inserting transaction time to commit before the cursor advances past it — preventing the commit-ordering gap as long as the lag exceeds the longest write transaction.

@github-actions

github-actions Bot commented Jun 19, 2026

Copy link
Copy Markdown

Code Coverage Report

Overall Project 67.24% +0.03% 🟢
Files changed 85.94% 🟢

Module Coverage
aliyun 1.72% 🔴
api 46.82% 🟢
authorization-common 85.96% 🟢
aws 26.5% 🔴
azure 2.47% 🔴
catalog-common 10.4% 🔴
catalog-fileset 80.23% 🟢
catalog-glue 66.91% 🟢
catalog-hive 79.42% 🟢
catalog-jdbc-clickhouse 80.02% 🟢
catalog-jdbc-common 44.22% 🟢
catalog-jdbc-doris 80.28% 🟢
catalog-jdbc-hologres 54.03% 🟢
catalog-jdbc-mysql 79.23% 🟢
catalog-jdbc-oceanbase 80.91% 🟢
catalog-jdbc-postgresql 82.29% 🟢
catalog-jdbc-starrocks 78.51% 🟢
catalog-kafka 77.01% 🟢
catalog-lakehouse-generic 58.53% 🟢
catalog-lakehouse-hudi 79.1% 🟢
catalog-lakehouse-iceberg 85.86% 🟢
catalog-lakehouse-paimon 82.14% 🟢
catalog-model 77.72% 🟢
cli 44.51% 🟢
client-java 78.01% 🟢
common 50.17% 🟢
core 82.6% +0.02% 🟢
filesystem-hadoop3 77.27% 🟢
flink 0.0% 🔴
flink-common 47.12% 🟢
flink-runtime 0.0% 🔴
gcp 14.12% 🔴
hadoop-common 10.88% 🔴
hive-metastore-common 53.77% 🟢
iceberg-common 58.15% 🟢
iceberg-rest-server 73.9% 🟢
idp-basic 85.71% 🟢
integration-test-common 0.0% 🔴
jobs 66.17% 🟢
lance-common 20.83% 🔴
lance-rest-server 60.13% 🟢
lineage 53.02% 🟢
optimizer 82.95% 🟢
optimizer-api 21.95% 🔴
server 86.09% 🟢
server-common 74.18% 🟢
spark 28.57% 🔴
spark-common 41.66% 🟢
trino-connector 40.29% 🟢
Files
Module File Coverage
core EntityChangeLogPoller.java 85.94% 🟢

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 27 out of 27 changed files in this pull request and generated 1 comment.

@yuqi1129 yuqi1129 requested review from diqiu50 and roryqi June 23, 2026 11:34

@jerryshao jerryshao left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall the fix is sound and well-tested. Two bugs (commit-ordering gap and listener-failure cursor advance) are addressed correctly. Comments below are one functional concern, two style/usability nits, and one minor test coverage gap.

TimeUnit.DAYS.toMillis(1),
TimeUnit.HOURS.toMillis(1),
TimeUnit.SECONDS.toMillis(1),
System::currentTimeMillis);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Style: hardcoded 1 should reference DEFAULT_ENTITY_CHANGE_LOG_POLL_LAG_SECS.

This repeats the magic value that is also defined in Configs.DEFAULT_ENTITY_CHANGE_LOG_POLL_LAG_SECS. If the default is ever changed in Configs, this single-arg constructor is silently left inconsistent.

// Prefer
TimeUnit.SECONDS.toMillis(DEFAULT_ENTITY_CHANGE_LOG_POLL_LAG_SECS),

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK, it makes sense.

@diqiu50 diqiu50 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The lag is only applied on the regular polling path. start() still initializes entityPollHighWaterId from unlagged selectMaxChangeId(), so a restart can still skip a lower id that was inserted but uncommitted while a higher id was already committed. Once the cursor is initialized past that lower id, the lagged polling query cannot recover it. The startup cursor should be initialized using the same lagged/eligible boundary.

@yuqi1129

Copy link
Copy Markdown
Contributor Author

The lag is only applied on the regular polling path. start() still initializes entityPollHighWaterId from unlagged selectMaxChangeId(), so a restart can still skip a lower id that was inserted but uncommitted while a higher id was already committed. Once the cursor is initialized past that lower id, the lagged polling query cannot recover it. The startup cursor should be initialized using the same lagged/eligible boundary.

Changed selectMaxChangeId.

public static final String VERSION_1_3_0 = "1.3.0";

/** The version number for the 1.4.0 release. */
public static final String VERSION_1_4_0 = "1.4.0";

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Our next release will be 2.0.0, you probably need to update this.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

modified.

*
* <p>The {@code created_at <= dbNowMs - lagMs} predicate applies a lagging high-water mark.
* Auto-increment ids are assigned at INSERT time but become visible at COMMIT time, so a lower id
* can commit after a higher id; advancing the cursor purely by the largest committed id can step

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How could this be happened, is this a auto incremental id?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes — id is BIGINT AUTO_INCREMENT (MySQL) / BIGSERIAL (PG). The id is set when the INSERT runs, but the row is only visible after COMMIT. The change-log insert commits together with the rest of the metadata write (the soft-deletes etc.), so a lower id can become visible after a higher id that committed first. An id-only cursor can then jump over the lower id before it shows up and drop its invalidation for good. So the gap is real.

The following is an example:

Transaction A starts → INSERT gets id=10 (slow transaction, late commit)
Transaction B starts → INSERT gets id=11, fast COMMIT
Poller runs: sees id=11 (committed), cursor advances to 11
Transaction A finally COMMIT, id=10 becomes visible
Poller next check WHERE id > 11 → id=10 never seen ❌ Failure information permanently lost

* can commit after a higher id; advancing the cursor purely by the largest committed id can step
* over a not-yet-committed lower id and lose its invalidation forever. A smaller-id row was
* necessarily inserted no later than a larger-id row, so by only consuming rows whose {@code
* created_at} is at least {@code lagMs} in the past (measured by the database clock, so there is

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How do you know that 1 sec lag is enough? If for example, we hit minor or major gc in the Gravitino side, the id committed should be late. In this case, is it enough for just 1 second by default?

My feeling is that instead of adding a lag. We should make sure that the id we insert is incremental. And what the reader gets is always sequential.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The lag is just a best-effort guess, not a guarantee. It has to be bigger than the longest time between a row's INSERT and its COMMIT, and a GC pause, a lock wait, a slow disk write, or a long transaction can easily push that past 1s. When it does, the gap comes back and the invalidation is lost silently. So a fixed 1s default is fragile.

I will try to think about it again to gain a better solution.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I reworked it. The cursor is now created_at instead of id, and every cycle it re-reads a small window before the cursor:

  WHERE created_at > #{watermarkMs} - #{overlapMs} ORDER BY created_at, id

So if a row commits late (its created_at is behind the cursor), the next poll re-reads that window and picks it up, instead of skipping it forever. Re-reading a row we already handled is safe because invalidation is idempotent.

About your "make the ids the reader sees always in order" idea: I did not go that way because auto-increment ids are not reused after a rollback, so a rolled-back id never shows up and the reader would wait on it forever. The overlap window avoids that problem.

One thing I want to be clear about: the overlap does not add delay. A new change is still applied within one poll interval. The overlap only re-scans the past window to catch late commits, it does not hold back new rows
(this is the difference from the old lag).

Config renamed pollLagSecs -> pollOverlapSecs (default 30s, should be larger than the longest INSERT-to-COMMIT time). Done in the latest commit.

@yuqi1129 yuqi1129 closed this Jun 25, 2026
@yuqi1129 yuqi1129 reopened this Jun 25, 2026
yuqi1129 added a commit that referenced this pull request Jun 26, 2026
…ated_at

The base provider writes entity_change_log.created_at with the two-function
expression (UNIX_TIMESTAMP() * 1000) + EXTRACT(MICROSECOND FROM
CURRENT_TIMESTAMP(3)) / 1000. On MySQL both time functions are frozen to the
statement-start instant, so the value is consistent. H2 evaluates each time
function against the live wall clock, so the whole-second and sub-second reads
can straddle a one-second boundary and the combined created_at jumps up to one
second away from the true time.

The poller cursor is the created_at high-water mark and selectEntityChanges
re-reads created_at > watermark - overlap. A backward straddle on a freshly
inserted row writes a created_at below an already-consumed row's watermark, so
the new row drops out of the window. With the small overlap used in tests this
surfaced as the intermittent TestEntityChangeLogService failure (#11739).

Add an H2 provider that overrides only insertEntityChange to compute created_at
from a single CURRENT_TIMESTAMP(3) read via EXTRACT(EPOCH FROM
CURRENT_TIMESTAMP(3)) * 1000, the same atomic, true-UTC millisecond expression
the PostgreSQL provider uses. A single timestamp read cannot straddle a
boundary. Production MySQL and PostgreSQL are unaffected.
…re pause and missed-row logging

Revert the created_at watermark + overlap-window cursor (#11736/#11739). Its
overlap window re-delivered the same change row across poll cycles, which defeated
CatalogManager's single-shot consumeLocalMutation dedup and made the poller
invalidate the node's own in-use catalog. That invalidation synchronously closed
the catalog's IsolatedClassLoader (and connection pool) while a request was still
using it, producing a permanently cached NoClassDefFoundError that failed the whole
Ranger authz IT suite. The overlap cure was worse than the rare commit-ordering
miss it targeted, which for the catalog cache is also bounded by TTL eviction.

Keep the listener-failure handling: the cursor advances only after every listener
applies the batch; on failure it pauses and re-dispatches until all succeed
(ERROR-logged), so a transient listener failure cannot silently drop invalidations.

Instead of preventing the commit-ordering gap, make it observable: ids are assigned
at INSERT but visible at COMMIT, so a row can commit below the id>cursor cursor
after it advanced past it and be missed. The poller now records skipped ids (bounded:
narrow gaps only, capped count, stale entries dropped) and WARN-logs any that later
become visible, so the real-world frequency of the race is measurable.

Tests: listener-failure pause/retry, cursor-advance-on-recovery, and late-commit
missed-row detection.
@yuqi1129 yuqi1129 force-pushed the me/fix-entity-change-log-poller-11736 branch from 2e03ea6 to 8abb18f Compare June 26, 2026 14:02
@yuqi1129 yuqi1129 changed the title [#11736] improvement(core): Close EntityChangeLogPoller commit-ordering gap and listener-failure cursor advance [#11736] improvement(core): detect & log entity_change_log commit-ordering gaps; keep listener-failure cursor pause Jun 26, 2026
yuqi1129 added 2 commits June 26, 2026 23:38
…the commit-ordering limitation

The earlier missed-row detector (pendingGapIds / recordNewGaps / detectFilledGaps)
is removed. It carried real maintenance cost for little value: it is best-effort
only (no false positives but under-counts — lost on restart, bounded lookback page),
and any simpler "log on non-contiguous id" alternative is unusable because ids are
legitimately non-contiguous (auto_increment_increment > 1, sequence caching,
rollbacks).

What remains is the safe, minimal behavior: the baseline id-cursor poller
(WHERE id > lastConsumedId, each row delivered once) plus the per-listener
failure handling (retry only listeners that have not applied the batch; pause the
cursor until all succeed, ERROR-logged).

The commit-ordering miss is now documented as an accepted known limitation on the
class javadoc: its cause (id assigned at INSERT, visible at COMMIT), the conditions
and low probability under which it occurs, and why no cheap/robust fix is currently
available (overlap re-delivery is unsafe for non-idempotent consumers; reliable
detection needs fragile per-row bookkeeping). Revisit with a dedicated design if it
is shown to matter in production.
@yuqi1129 yuqi1129 changed the title [#11736] improvement(core): detect & log entity_change_log commit-ordering gaps; keep listener-failure cursor pause [#11736] improvement(core): id-cursor entity-change poller with per-listener failure retry; document commit-ordering limitation Jun 27, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Improvement] EntityChangeLogPoller can permanently miss cache invalidations in multi-node deployments

4 participants