Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
33 changes: 15 additions & 18 deletions platform/extension/messagequeue/mysql/subscriber.go
Original file line number Diff line number Diff line change
Expand Up @@ -49,12 +49,6 @@ const (
// so it converges over multiple calls even with large backlogs.
watermarkAdvancementLimit = 1000

// gcIdleTickInterval controls how often GC runs during idle poll ticks.
// GC runs every Nth idle tick instead of every tick to avoid excessive
// queries when many partitions are idle (e.g., 50 idle partitions at 100ms
// poll interval = 500 GC queries/sec without throttling).
gcIdleTickInterval = 100

// heartbeatPurgeAfterLeaseDurations sets the age threshold for purging
// abandoned heartbeat rows, as a multiple of LeaseDurationMs (10x = 5min
// at defaults). Well past every transient window in the protocol — a row
Expand All @@ -81,6 +75,13 @@ const (
leasePurgeAfterLeaseDurations = 10
)

// gcTickInterval is the number of poll ticks between garbage collection runs.
// GC runs every Nth tick regardless of delivery activity; without throttling,
// many partitions polling in lockstep would flood the store with queries
// (e.g., 50 partitions at 100ms poll interval = 500 GC queries/sec). A var so
// tests can shorten it; production always uses the default.
var gcTickInterval = 100

// HookSignal identifies the type of subscriber lifecycle event.
// Named after behavioral concerns (what happened) rather than implementation
// details (which loop ran), so signal names remain stable across refactors.
Expand Down Expand Up @@ -167,8 +168,7 @@ type partitionWorker struct {
// partition. Set once on the first successful poll, avoiding repeated
// initialization calls on every tick.
offsetInitialized bool
// gcCounter counts idle poll ticks. GC only runs every gcIdleTickInterval
// ticks to avoid excessive queries when many partitions are idle.
// gcCounter counts poll ticks since the last garbage collection run.
gcCounter int
}

Expand Down Expand Up @@ -1200,17 +1200,14 @@ func (w *partitionWorker) pollAndDeliver(ctx context.Context) (retErr error) {
)
}

// Run GC periodically (throttled to every Nth idle tick)
if messageCount == 0 {
w.gcCounter++
if w.gcCounter >= gcIdleTickInterval {
w.gcCounter = 0
if err := w.garbageCollect(ctx); err != nil {
return fmt.Errorf("garbage collect: %w", err)
}
}
} else {
// GC runs every Nth tick regardless of delivery activity; an idle-only
// gate starved continuously busy partitions of garbage collection.
w.gcCounter++
if w.gcCounter >= gcTickInterval {
w.gcCounter = 0
if err := w.garbageCollect(ctx); err != nil {
return fmt.Errorf("garbage collect: %w", err)
Comment on lines +1205 to +1209

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

This early return now suppresses the messages_delivered counter on a busy tick.

Before this change GC could only run when messageCount == 0, so the garbage collect error path could never skip the if messageCount > 0 metrics block a few lines below. Now it can: the messages were already pushed to deliveryCh, but the counter is dropped — so throughput reads low exactly when the store is unhealthy and you most want the number.

Moving the metrics block above the GC block (or folding it into the existing defer) fixes it.

}
}

// Record poll metrics
Expand Down
58 changes: 58 additions & 0 deletions platform/extension/messagequeue/mysql/subscriber_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -710,6 +710,64 @@ func TestSubscriber_PartitionWorkerPollAndDeliver(t *testing.T) {
assert.True(t, foundFinish, "expected poll.finish histogram")
}

// TestSubscriber_PollAndDeliver_GCOnBusyTicks verifies that garbage collection
// runs on a partition that delivers a message on every poll tick. GC was gated
// on idle ticks, so a continuously busy partition never reclaimed acked rows.
func TestSubscriber_PollAndDeliver_GCOnBusyTicks(t *testing.T) {
old := gcTickInterval
gcTickInterval = 2
t.Cleanup(func() { gcTickInterval = old })

ctrl := gomock.NewController(t)

mockMessageStore := NewMockmessageStore(ctrl)
mockOffsetStore := NewMockoffsetStore(ctrl)
mockLeaseStore := NewMockpartitionLeaseStore(ctrl)

s := setupSubscriberTest(t, mockMessageStore, mockOffsetStore, mockLeaseStore).(*subscriber)

cfg := testSubscriptionConfig()
deliveryCh := make(chan extqueue.Delivery, 10)
sub := &subscription{
topic: "test_topic",
config: cfg,
deliveryCh: deliveryCh,
workers: make(map[string]*partitionWorker),
}
w := &partitionWorker{
partitionKey: "part-1",
sub: sub,
subscriber: s,
done: make(chan struct{}),
}

row := messageRow{
ID: "msg-1",
Offset: 1,
PartitionKey: "part-1",
Payload: []byte("payload"),
PublishedAt: time.Now().UnixMilli(),
}
// Every poll delivers one message, so the partition never idles.
mockMessageStore.EXPECT().FetchByOffset(gomock.Any(), "test_topic", "part-1", int64(0), cfg.BatchSize).
Return([]messageRow{row}, nil).Times(3)
mockOffsetStore.EXPECT().Initialize(gomock.Any(), "test_topic", "part-1", cfg.ConsumerGroup).Return(nil)

// The counter reaches gcTickInterval on the second busy tick.
mockOffsetStore.EXPECT().GetMinAckedOffset(gomock.Any(), "test_topic", "part-1").Return(int64(1), true, nil)
mockMessageStore.EXPECT().GarbageCollect(gomock.Any(), "test_topic", "part-1", int64(1)).Return(int64(1), nil)

ctx := context.Background()
for i := 0; i < 3; i++ {
require.NoError(t, w.pollAndDeliver(ctx))
select {
case <-deliveryCh:
default:
t.Fatal("expected a delivery on every busy tick")
}
}
}

// TestSubscriber_PollAndDeliver_PostponedBarrier verifies that a postponed
// message halts the partition scan (barrier), while a nacked message is
// skipped and later offsets keep flowing.
Expand Down
61 changes: 61 additions & 0 deletions test/integration/extension/messagequeue/mysql/queue_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -2268,6 +2268,67 @@ func (s *SQLQueueIntegrationSuite) TestIdleLeaseRelease() {
t.Logf("Idle lease released and partition resurrected on new traffic")
}

// TestGCReclaimsAckedRowsUnderContinuousTraffic verifies that garbage
// collection reclaims acked rows on a partition that never idles. GC was gated
// on idle poll ticks, so a continuously busy partition grew its message log
// without bound; it must now run on its own tick cadence regardless of traffic.
func (s *SQLQueueIntegrationSuite) TestGCReclaimsAckedRowsUnderContinuousTraffic() {
t := s.T()

topic := "gc_busy_topic"
partition := "gc-busy-part"
consumerGroup := "gc-busy-cg"

signalCh := make(chan queueMySQL.HookSignal, 100)
q, err := queueMySQL.NewQueue(queueMySQL.Params{
DB: s.db, Logger: zaptest.NewLogger(t), MetricsScope: tally.NoopScope,
OnSignal: signalCh,
})
require.NoError(t, err)
defer q.Close()

// Fast poll so the 100-tick GC cadence elapses quickly; at the 100ms
// default it would take 10s of continuous traffic before reclamation.
cfg := testSubConfig("worker-gc-busy", consumerGroup)
cfg.PollIntervalMs = 50
deliveryChan, err := q.Subscriber().Subscribe(s.ctx, topic, cfg)
require.NoError(t, err)

countMessages := func() int {
var n int
require.NoError(t, s.db.QueryRowContext(s.ctx,
"SELECT COUNT(*) FROM queue_messages WHERE topic = ? AND partition_key = ?",
topic, partition).Scan(&n))
return n
}

// Establish an acked backlog: 200 acked rows that survive consumption
// because only GC deletes message rows.
const initialBatch = 200
for i := 0; i < initialBatch; i++ {
require.NoError(t, q.Publisher().Publish(s.ctx, topic,
entityqueue.NewMessage(fmt.Sprintf("gc-%d", i), []byte("x"), partition, nil)))
}
receiveN(t, deliveryChan, initialBatch, func(d extqueue.Delivery, _ int) {
require.NoError(t, d.Ack(s.ctx))
})
require.Equal(t, initialBatch, countMessages())
Comment on lines +2312 to +2315

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

This assertion assumes GC hasn't fired yet, but the change under test is what can invalidate that — the drain above is busy ticks, which now increment gcCounter.

The subscription is live before the publishes, so the counter accrues across both the publish phase and the drain. At PollIntervalMs = 50 that lands somewhere around 30–80 ticks on a fast box and passes; if the 200 inserts take more than ~3.5s on a loaded CI runner with Dockerized MySQL, the counter crosses the 100-tick threshold, GC reclaims acked rows mid-drain, and this require.Equal fails. Roughly 2x margin against a wall-clock threshold.

Asserting countMessages() > 0 here, or seeding the acked backlog before subscribing, removes the timing dependency without weakening what the test actually proves (the waitForCondition below is the real assertion).


// Continuous traffic keeps the partition busy for well over 100 poll ticks;
// GC must reclaim the acked backlog without ever observing an idle tick.
const continuousTrafficIterations = 150
for i := 0; i < continuousTrafficIterations; i++ {
require.NoError(t, q.Publisher().Publish(s.ctx, topic,
entityqueue.NewMessage(fmt.Sprintf("gc-busy-%d", i), []byte("y"), partition, nil)))
delivery := receive(t, deliveryChan)
require.NoError(t, delivery.Ack(s.ctx))
}

waitForCondition(t, signalCh, func() bool {
return countMessages() < initialBatch
}, "acked backlog should be garbage collected while the partition stays busy")
}

// TestNackDoesNotBlockOtherMessages verifies that nacking a message does not
// block delivery of subsequent messages in the same partition. The nacked
// message should be skipped (invisible) while later messages are delivered.
Expand Down