Skip to content

Commit a1d38ef

Browse files
committed
fix(run-engine): advance the ck virtual-time floor from servable variants
The floor only tracked the lowest tag on record, so any registered variant that could not be served held it there: one sitting at its own concurrency ceiling, or one whose head is not ready yet. The keys actually being served advanced past it, and since new keys register at the floor, a later arrival started underneath the incumbents and took the fair pass until it caught up. The floor now also rises to the lowest tag that was servable on the call. Pass 1 walks candidates in ascending tag order, so that is a safe lower bound. The repair from the lowest tag on record stays, because both routes only ever raise it and it still recovers a floor that was lost while ckVtime survived. Also adds the fairness scenario the suite was missing. None of the six scenarios nacked or used future-scored messages, so a stalled variant never existed and this class of bug could not show up. In the window after it lands the latecomer now takes 5 of 20 serves, against 12 of 20 without the fix.
1 parent 32d976a commit a1d38ef

3 files changed

Lines changed: 175 additions & 14 deletions

File tree

internal-packages/run-engine/src/run-queue/index.ts

Lines changed: 14 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -5117,7 +5117,10 @@ end
51175117
51185118
local window = actualMaxCount * windowMultiplier
51195119
5120-
-- Monotonic floor, advanced to the minimum stored virtual-time tag
5120+
-- Floor only ever rises, by two independent routes: to the lowest tag on record (repairs
5121+
-- a floor that was lost while ckVtime survived), and to the lowest tag actually servable
5122+
-- this call (minServableTag). The second route matters because an unservable variant
5123+
-- keeps a stale low tag, which left the first route unable to advance at all.
51215124
local floor = tonumber(redis.call('GET', ckVtimeFloorKey) or '0')
51225125
local minEntry = redis.call('ZRANGE', ckVtimeKey, 0, 0, 'WITHSCORES')
51235126
if #minEntry > 0 then
@@ -5126,6 +5129,7 @@ if #minEntry > 0 then
51265129
floor = minTag
51275130
end
51285131
end
5132+
local minServableTag = nil
51295133
51305134
local results = {}
51315135
local dequeuedCount = 0
@@ -5180,6 +5184,10 @@ local function tryServe(ckQueueName)
51805184
local weight = 1
51815185
local tag = tonumber(redis.call('ZSCORE', ckVtimeKey, ckQueueName) or floor)
51825186
if tag < floor then tag = floor end
5187+
-- Pass 1 walks in ascending tag order, so anything unvisited is above this.
5188+
if minServableTag == nil or tag < minServableTag then
5189+
minServableTag = tag
5190+
end
51835191
redis.call('ZADD', ckVtimeKey, tostring(tag + (quantum / weight)), ckQueueName)
51845192
end
51855193
else
@@ -5202,12 +5210,8 @@ local function tryServe(ckQueueName)
52025210
redis.call('ZREM', ckVtimeKey, ckQueueName) -- NEW
52035211
else
52045212
redis.call('ZADD', ckIndexKey, any[2], ckQueueName)
5205-
-- The variant has work but none of it is ready yet (a nack backoff, say), so it
5206-
-- is not competing for service and must not hold the floor down. While it sat in
5207-
-- ckVtime its low tag pinned the floor, and new keys register at the floor, so a
5208-
-- key arriving later started far below the established ones and took every pass-1
5209-
-- slot until it caught up. It re-registers at the floor of the day on its next
5210-
-- enqueue/nack, or when pass 2 serves it after its head becomes ready.
5213+
-- Work but nothing ready (a nack backoff): not competing, so drop it from the fair
5214+
-- order rather than let it hoard credit. Rejoins at the floor when next served.
52115215
redis.call('ZREM', ckVtimeKey, ckQueueName)
52125216
end
52135217
end
@@ -5236,6 +5240,9 @@ if dequeuedCount < actualMaxCount then
52365240
end
52375241
52385242
-- NEW: persist floor and refresh TTLs
5243+
if minServableTag ~= nil and minServableTag > floor then
5244+
floor = minServableTag
5245+
end
52395246
redis.call('SET', ckVtimeFloorKey, tostring(floor), 'EX', stateTtl)
52405247
if redis.call('EXISTS', ckVtimeKey) == 1 then
52415248
redis.call('EXPIRE', ckVtimeKey, stateTtl)

internal-packages/run-engine/src/run-queue/tests/ckVtime.test.ts

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -709,6 +709,75 @@ describe("CK virtual-time (SFQ) dequeue", () => {
709709
}
710710
);
711711

712+
redisTest(
713+
"a variant at its concurrency ceiling does not pin the floor",
714+
async ({ redisContainer }) => {
715+
// A saturated variant stops advancing but keeps its tag, which used to hold the
716+
// floor down for everyone arriving later.
717+
const queue = createQueue(redisContainer);
718+
try {
719+
const t0 = Date.now() - 100_000;
720+
721+
// Per-key ceiling of 1, well under the env limit, so hog gates on its own account
722+
// rather than by exhausting env capacity.
723+
await queue.updateQueueConcurrencyLimits(authenticatedEnvDev, QUEUE, 1);
724+
725+
for (let i = 0; i < 12; i++) {
726+
await queue.enqueueMessage({
727+
env: authenticatedEnvDev,
728+
message: makeMessage({ runId: `r-hog-${i}`, concurrencyKey: "hog", timestamp: t0 + i }),
729+
workerQueue: authenticatedEnvDev.id,
730+
skipDequeueProcessing: true,
731+
});
732+
}
733+
for (let i = 0; i < 12; i++) {
734+
await queue.enqueueMessage({
735+
env: authenticatedEnvDev,
736+
message: makeMessage({
737+
runId: `r-busy-${i}`,
738+
concurrencyKey: "busy",
739+
timestamp: t0 + 500 + i,
740+
}),
741+
workerQueue: authenticatedEnvDev.id,
742+
skipDequeueProcessing: true,
743+
});
744+
}
745+
746+
const shard = testOptions.keys.masterQueueShardForEnvironment(authenticatedEnvDev.id, 2);
747+
const hogVariant = variantName("hog");
748+
const busyVariant = variantName("busy");
749+
const ckVtimeKey = testOptions.keys.ckVtimeKeyFromQueue(busyVariant);
750+
const floorKey = testOptions.keys.ckVtimeFloorKeyFromQueue(busyVariant);
751+
752+
// Ack only busy, so hog accumulates in-flight messages until it is gated.
753+
for (let call = 0; call < 10; call++) {
754+
const messages = await queue.testDequeueFromMasterQueue(shard, authenticatedEnvDev.id, 2);
755+
for (const m of messages) {
756+
if (m.message.concurrencyKey === "busy") {
757+
await queue.acknowledgeMessage(authenticatedEnvDev.organization.id, m.messageId, {
758+
skipDequeueProcessing: true,
759+
});
760+
}
761+
}
762+
}
763+
764+
const hogTag = Number(await queue.redis.zscore(ckVtimeKey, hogVariant));
765+
const busyTag = Number(await queue.redis.zscore(ckVtimeKey, busyVariant));
766+
const floor = Number((await queue.redis.get(floorKey)) ?? "0");
767+
768+
// hog is still registered (it has ready work and will be served when a slot
769+
// frees), it has simply stopped advancing while saturated.
770+
expect(hogTag).not.toBeNaN();
771+
expect(busyTag).toBeGreaterThan(hogTag);
772+
773+
// The floor followed the key that was actually being served, not the stalled one.
774+
expect(floor).toBeGreaterThan(hogTag);
775+
} finally {
776+
await queue.quit();
777+
}
778+
}
779+
);
780+
712781
redisTest(
713782
"an unservable variant does not pin the floor for later arrivals",
714783
async ({ redisContainer }) => {

internal-packages/run-engine/src/run-queue/tests/ckVtimeFairness.test.ts

Lines changed: 92 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -93,7 +93,15 @@ function makeMessage(overrides: Partial<InputPayload> = {}): InputPayload {
9393
};
9494
}
9595

96-
type ScenarioMessage = { runId: string; ck: string; timestamp: number };
96+
type ScenarioMessage = {
97+
runId: string;
98+
ck: string;
99+
timestamp: number;
100+
// Enqueued at the top of this step instead of before step 0, for late arrivals.
101+
enqueueAtStep?: number;
102+
// Head never becomes ready during the run, so it is not expected to drain.
103+
neverReady?: boolean;
104+
};
97105

98106
type Scenario = {
99107
name: string;
@@ -138,7 +146,7 @@ async function runScenario(
138146
};
139147
await queue.updateEnvConcurrencyLimits(env);
140148

141-
for (const msg of scenario.messages) {
149+
const enqueue = async (msg: ScenarioMessage) => {
142150
await queue.enqueueMessage({
143151
env,
144152
message: makeMessage({
@@ -149,13 +157,18 @@ async function runScenario(
149157
workerQueue: env.id,
150158
skipDequeueProcessing: true,
151159
});
160+
};
161+
162+
for (const msg of scenario.messages) {
163+
if (msg.enqueueAtStep === undefined) await enqueue(msg);
152164
}
153165

154166
const shard = testOptions.keys.masterQueueShardForEnvironment(env.id, 2);
155-
const total = scenario.messages.length;
167+
const total = scenario.messages.filter((m) => !m.neverReady).length;
156168

157169
const remaining = new Map<string, number>();
158170
for (const m of scenario.messages) {
171+
if (m.neverReady) continue;
159172
remaining.set(m.ck, (remaining.get(m.ck) ?? 0) + 1);
160173
}
161174

@@ -165,6 +178,10 @@ async function runScenario(
165178
let drainStep = -1;
166179

167180
for (let step = 0; step < scenario.maxSteps && serves.length < total; step++) {
181+
for (const msg of scenario.messages) {
182+
if (msg.enqueueAtStep === step) await enqueue(msg);
183+
}
184+
168185
// evaluated before the dequeue: does this step have cross-key contention?
169186
let keysWithBacklog = 0;
170187
for (const count of remaining.values()) {
@@ -221,10 +238,11 @@ function firstServeStep(result: ScenarioResult, matches: (ck: string) => boolean
221238

222239
// No loss and no double-serve, in both runs.
223240
function assertConservation(scenario: Scenario, on: ScenarioResult, off: ScenarioResult) {
224-
expect(on.serves.length).toBe(scenario.messages.length);
225-
expect(off.serves.length).toBe(scenario.messages.length);
226-
expect(new Set(on.serves.map((s) => s.messageId)).size).toBe(scenario.messages.length);
227-
expect(new Set(off.serves.map((s) => s.messageId)).size).toBe(scenario.messages.length);
241+
const expected = scenario.messages.filter((m) => !m.neverReady).length;
242+
expect(on.serves.length).toBe(expected);
243+
expect(off.serves.length).toBe(expected);
244+
expect(new Set(on.serves.map((s) => s.messageId)).size).toBe(expected);
245+
expect(new Set(off.serves.map((s) => s.messageId)).size).toBe(expected);
228246
}
229247

230248
function debugLog(name: string, data: Record<string, unknown>) {
@@ -528,4 +546,71 @@ describe("CK virtual-time fairness on the real batched dequeue path", () => {
528546
expect(on.drainStep).toBe(off.drainStep);
529547
}
530548
);
549+
550+
redisTest(
551+
"ckStalledNewcomer: a stalled variant does not let a late arrival starve the incumbents",
552+
{ timeout: 120_000 },
553+
async ({ redisContainer }) => {
554+
// The case the other five scenarios cannot express: a variant that is registered but
555+
// never servable (its head stays in the future, which is what a nack backoff leaves
556+
// behind) used to freeze the virtual-time floor, so the late arrival registered far
557+
// below the incumbents and took every fair-pass slot until it caught up.
558+
const t0 = Date.now() - 100_000;
559+
const messages: ScenarioMessage[] = [];
560+
561+
messages.push({
562+
runId: "stalled-0",
563+
ck: "stalled",
564+
timestamp: Date.now() + 60 * 60 * 1000,
565+
neverReady: true,
566+
});
567+
568+
for (let k = 0; k < 3; k++) {
569+
for (let i = 0; i < 40; i++) {
570+
messages.push({ runId: `inc-${k}-${i}`, ck: `incumbent-${k}`, timestamp: t0 + i });
571+
}
572+
}
573+
574+
// Arrives once the incumbents have advanced well past the stalled variant's tag.
575+
for (let i = 0; i < 20; i++) {
576+
messages.push({
577+
runId: `late-${i}`,
578+
ck: "latecomer",
579+
timestamp: t0 + 5_000 + i,
580+
enqueueAtStep: 30,
581+
});
582+
}
583+
584+
const scenario: Scenario = {
585+
name: "ckStalledNewcomer",
586+
messages,
587+
envConcurrencyLimit: 1,
588+
holdSteps: 0,
589+
maxSteps: 600,
590+
};
591+
592+
const on = await runScenario(redisContainer, scenario, true);
593+
const off = await runScenario(redisContainer, scenario, false);
594+
595+
assertConservation(scenario, on, off);
596+
597+
// Over the 20 steps after it lands, the latecomer must not monopolise service.
598+
const windowServes = (r: ScenarioResult) =>
599+
r.serves.filter((s) => s.step >= 30 && s.step < 50);
600+
const onWindow = windowServes(on);
601+
const onLate = onWindow.filter((s) => s.ck === "latecomer").length;
602+
603+
debugLog("ckStalledNewcomer", {
604+
onWindowTotal: onWindow.length,
605+
onLate,
606+
offLate: windowServes(off).filter((s) => s.ck === "latecomer").length,
607+
});
608+
609+
// Four keys compete in that window, so a fair share is a quarter of it. Before the
610+
// floor fix the latecomer took 12 of 20 here; it now takes its 5.
611+
const fairShare = Math.ceil(onWindow.length / 4);
612+
expect(onWindow.length).toBeGreaterThan(0);
613+
expect(onLate).toBeLessThanOrEqual(fairShare + 2);
614+
}
615+
);
531616
});

0 commit comments

Comments
 (0)