Skip to content

Commit 71ecc64

Browse files
olexii4olexii4
committed
refactor(backend): poll only on watch failure
Remove parallel polling — polling now starts only when the WebSocket watch subscription fails. Remove the ENTRYPOINT_WINDOW_MS constant and its 12s warning. Assisted-by: Claude Opus 4.6 Signed-off-by: Oleksii Orel <oorel@redhat.com>
1 parent d3f66cb commit 71ecc64

2 files changed

Lines changed: 73 additions & 112 deletions

File tree

‎packages/dashboard-backend/src/services/PostStartInjector.ts‎

Lines changed: 48 additions & 53 deletions
Original file line numberDiff line numberDiff line change
@@ -18,14 +18,10 @@ import { logger } from '@/utils/logger';
1818

1919
// Safety net: if neither watch nor polling detected a terminal/running phase
2020
// within 10 min, something is stuck — tear down to avoid leaking resources.
21+
// The frontend shows a start-timeout error after 300 s (startTimeout in
22+
// ServerConfig/reducer.ts), so 600 s gives 2× that window before cleanup.
2123
const OVERALL_TIMEOUT_MS = 600000;
22-
// 2 s gives ~6 poll attempts within the ~12 s window that the UDI entrypoint.sh
23-
// waits for ~/.kube/config before giving up and falling back to the pod SA token.
2424
const POLL_INTERVAL_MS = 2000;
25-
// The UDI entrypoint.sh waits ~12 s for ~/.kube/config. If injection takes longer
26-
// than this from when the workspace reached Running, the terminal has already fallen
27-
// back to the pod service account identity.
28-
const ENTRYPOINT_WINDOW_MS = 12000;
2925

3026
function isTerminalPhase(phase: string): boolean {
3127
return (
@@ -41,16 +37,13 @@ function isTerminalPhase(phase: string): boolean {
4137
* Watches a specific DevWorkspace after it is started and injects
4238
* kubeconfig + podman credentials once it reaches the Running phase.
4339
*
44-
* Detection strategy (belt-and-suspenders):
45-
* 1. K8s Watch — near-instant when the stream is healthy.
46-
* 2. Parallel polling (GET every 2 s) — reliable fallback when
47-
* the watch stream is silently dropped by a proxy or LB.
40+
* Detection strategy:
41+
* 1. K8s Watch — primary path, near-instant when healthy.
42+
* 2. Polling fallback (GET every 2 s) — starts only when the
43+
* watch subscription fails (ERROR event or rejection).
4844
* 3. Immediate initial GET — catches workspaces that reached
4945
* Running before the watch stream opened (LIST→STREAM race).
5046
*
51-
* All three paths race; whichever detects Running first injects
52-
* credentials and tears down the others.
53-
*
5447
* Guards:
5548
* - Only one session per workspace (keyed by namespace/name).
5649
* - Cleanup uses function identity (`isOwner`) to prevent a stale
@@ -76,7 +69,7 @@ export class PostStartInjector {
7669

7770
logger.info(
7871
`PostStartInjector: subscribing for ${key} — ` +
79-
`watch + poll every ${POLL_INTERVAL_MS / 1000}s, ` +
72+
`watch (poll fallback every ${POLL_INTERVAL_MS / 1000}s on failure), ` +
8073
`${OVERALL_TIMEOUT_MS / 1000}s overall timeout`,
8174
);
8275

@@ -145,12 +138,49 @@ export class PostStartInjector {
145138
cleanupAll(`terminal phase ${phase} via ${source}`);
146139
};
147140

141+
// ── polling fallback (starts only when the watch fails) ──────────────
142+
143+
const startPolling = (): void => {
144+
if (pollHandle !== undefined || !isOwner()) {
145+
return;
146+
}
147+
logger.info(
148+
`PostStartInjector: watch failed for ${key}, falling back to polling every ${POLL_INTERVAL_MS / 1000}s`,
149+
);
150+
pollHandle = setInterval(() => {
151+
if (!isOwner()) {
152+
if (pollHandle !== undefined) {
153+
clearInterval(pollHandle);
154+
pollHandle = undefined;
155+
}
156+
return;
157+
}
158+
159+
devworkspaceApi
160+
.getByName(namespace, workspaceName)
161+
.then(async dw => {
162+
const phase = dw.status?.phase;
163+
const devworkspaceId = dw.status?.devworkspaceId;
164+
165+
if (phase === DevWorkspaceStatus.RUNNING && devworkspaceId) {
166+
await handleRunning(devworkspaceId, 'poll');
167+
} else if (phase && isTerminalPhase(phase)) {
168+
handleTerminal(phase, 'poll');
169+
}
170+
})
171+
.catch((e: unknown) => {
172+
logger.warn(e, `PostStartInjector: poll GET failed for ${key}, will retry`);
173+
});
174+
}, POLL_INTERVAL_MS);
175+
};
176+
148177
// ── 1. K8s Watch (fast path) ───────────────────────────────────────────
149178

150179
const listener: MessageListener = async message => {
151180
if (message.eventPhase === api.webSocket.EventPhase.ERROR) {
152-
logger.warn(`PostStartInjector: watch ERROR for ${key} — polling continues`);
181+
logger.warn(`PostStartInjector: watch ERROR for ${key} — falling back to polling`);
153182
devworkspaceApi.stopWatching();
183+
startPolling();
154184
return;
155185
}
156186

@@ -181,39 +211,12 @@ export class PostStartInjector {
181211
.catch((error: unknown) => {
182212
logger.warn(
183213
error,
184-
`PostStartInjector: watchInNamespace rejected for ${key} — polling continues`,
214+
`PostStartInjector: watchInNamespace rejected for ${key} — falling back to polling`,
185215
);
216+
startPolling();
186217
});
187218

188-
// ── 2. Parallel polling (reliable path) ────────────────────────────────
189-
190-
pollHandle = setInterval(() => {
191-
if (!isOwner()) {
192-
if (pollHandle !== undefined) {
193-
clearInterval(pollHandle);
194-
pollHandle = undefined;
195-
}
196-
return;
197-
}
198-
199-
devworkspaceApi
200-
.getByName(namespace, workspaceName)
201-
.then(async dw => {
202-
const phase = dw.status?.phase;
203-
const devworkspaceId = dw.status?.devworkspaceId;
204-
205-
if (phase === DevWorkspaceStatus.RUNNING && devworkspaceId) {
206-
await handleRunning(devworkspaceId, 'poll');
207-
} else if (phase && isTerminalPhase(phase)) {
208-
handleTerminal(phase, 'poll');
209-
}
210-
})
211-
.catch((e: unknown) => {
212-
logger.warn(e, `PostStartInjector: poll GET failed for ${key}, will retry`);
213-
});
214-
}, POLL_INTERVAL_MS);
215-
216-
// ── 3. Immediate initial check (LIST→STREAM race) ──────────────────────
219+
// ── 2. Immediate initial check (LIST→STREAM race) ───────────────────────
217220

218221
devworkspaceApi
219222
.getByName(namespace, workspaceName)
@@ -248,14 +251,6 @@ export class PostStartInjector {
248251
`PostStartInjector: injecting kubeconfig for ${key} ` +
249252
`(via ${source}, ${elapsedSec}s after start request)`,
250253
);
251-
if (elapsedMs > ENTRYPOINT_WINDOW_MS) {
252-
logger.warn(
253-
`PostStartInjector: injection for ${key} is ${elapsedSec}s after start request — ` +
254-
`this exceeds the ~12s UDI entrypoint.sh window. ` +
255-
`The terminal may have already fallen back to the pod service account identity. ` +
256-
`Detection source: ${source}`,
257-
);
258-
}
259254
try {
260255
await kubeConfigApi.injectKubeConfig(namespace, devworkspaceId);
261256
logger.info(`PostStartInjector: kubeconfig injected successfully for ${key}`);

‎packages/dashboard-backend/src/services/__tests__/PostStartInjector.spec.ts‎

Lines changed: 25 additions & 59 deletions
Original file line numberDiff line numberDiff line change
@@ -245,58 +245,54 @@ describe('PostStartInjector', () => {
245245
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledTimes(1);
246246
});
247247

248-
// ── parallel polling ──────────────────────────────────────────────────────
248+
// ── polling fallback (only after watch failure) ───────────────────────────
249249

250-
describe('parallel polling', () => {
251-
test('polls every 2 s alongside the watch', () => {
250+
describe('polling fallback', () => {
251+
test('does not poll while watch is healthy', () => {
252252
invoke();
253253

254-
// Nothing before the first interval elapses
255-
jest.advanceTimersByTime(1999);
256-
expect(devworkspaceApi.getByName).toHaveBeenCalledTimes(1); // only initial check
257-
258-
jest.advanceTimersByTime(1);
259-
// Initial check + first poll
260-
expect(devworkspaceApi.getByName).toHaveBeenCalledTimes(2);
261-
262-
jest.advanceTimersByTime(2000);
263-
expect(devworkspaceApi.getByName).toHaveBeenCalledTimes(3);
254+
jest.advanceTimersByTime(10000);
255+
// Only the initial check, no polling
256+
expect(devworkspaceApi.getByName).toHaveBeenCalledTimes(1);
264257
});
265258

266-
test('injects via poll when watch is silent', async () => {
259+
test('starts polling after watch ERROR and injects via poll', async () => {
267260
(devworkspaceApi.getByName as jest.Mock)
268261
.mockResolvedValueOnce({ status: { phase: 'Starting' } }) // initial check
269262
.mockResolvedValueOnce({ status: { phase: 'Starting' } }) // poll #1
270-
.mockResolvedValue({ status: { phase: 'Running', devworkspaceId: 'ws-poll-id' } });
263+
.mockResolvedValue({ status: { phase: 'Running', devworkspaceId: 'ws-after-err' } });
271264

272265
invoke();
273266
await flushMicrotasks();
274267

268+
await capturedListener(errorMessage());
269+
expect(devworkspaceApi.stopWatching).toHaveBeenCalled();
270+
expect(logger.info).toHaveBeenCalledWith(expect.stringContaining('falling back to polling'));
271+
275272
jest.advanceTimersByTime(2000);
276273
await flushMicrotasks();
277274
expect(kubeConfigApi.injectKubeConfig).not.toHaveBeenCalled();
278275

279276
jest.advanceTimersByTime(2000);
280277
await flushMicrotasks();
281-
282-
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledWith(namespace, 'ws-poll-id');
283-
expect(podmanApi.podmanLogin).toHaveBeenCalledWith(namespace, 'ws-poll-id');
278+
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledWith(namespace, 'ws-after-err');
284279
expect((PostStartInjector as any).activeWatches.has(key)).toBe(false);
285280
});
286281

287-
test('does not double-inject when watch and poll both detect Running', async () => {
282+
test('starts polling after watchInNamespace rejection', async () => {
283+
(devworkspaceApi.watchInNamespace as jest.Mock).mockRejectedValue(
284+
new Error('watch rejected'),
285+
);
288286
(devworkspaceApi.getByName as jest.Mock)
289287
.mockResolvedValueOnce({ status: { phase: 'Starting' } }) // initial check
290-
.mockResolvedValue({ status: { phase: 'Running', devworkspaceId: 'ws-both' } });
288+
.mockResolvedValue({ status: { phase: 'Running', devworkspaceId: 'ws-reject-id' } });
291289

292290
invoke();
293291
await flushMicrotasks();
294292

295-
await capturedListener(dwMessage('Running', 'ws-both'));
296293
jest.advanceTimersByTime(2000);
297294
await flushMicrotasks();
298-
299-
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledTimes(1);
295+
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledWith(namespace, 'ws-reject-id');
300296
});
301297

302298
test.each(['Failed', 'Failing', 'Stopped', 'Stopping', 'Terminating'])(
@@ -309,6 +305,9 @@ describe('PostStartInjector', () => {
309305
invoke();
310306
await flushMicrotasks();
311307

308+
// Trigger watch failure to start polling
309+
await capturedListener(errorMessage());
310+
312311
jest.advanceTimersByTime(2000);
313312
await flushMicrotasks();
314313

@@ -326,59 +325,26 @@ describe('PostStartInjector', () => {
326325
invoke();
327326
await flushMicrotasks();
328327

329-
jest.advanceTimersByTime(2000);
330-
await flushMicrotasks();
331-
expect(kubeConfigApi.injectKubeConfig).not.toHaveBeenCalled();
332-
333-
jest.advanceTimersByTime(2000);
334-
await flushMicrotasks();
335-
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledWith(namespace, 'ws-retry-id');
336-
});
337-
338-
test('polling continues after watch ERROR', async () => {
339-
(devworkspaceApi.getByName as jest.Mock)
340-
.mockResolvedValueOnce({ status: { phase: 'Starting' } }) // initial check
341-
.mockResolvedValueOnce({ status: { phase: 'Starting' } }) // poll #1
342-
.mockResolvedValue({ status: { phase: 'Running', devworkspaceId: 'ws-after-err' } });
343-
344-
invoke();
345-
await flushMicrotasks();
346-
328+
// Trigger watch failure to start polling
347329
await capturedListener(errorMessage());
348-
expect(devworkspaceApi.stopWatching).toHaveBeenCalled();
349330

350331
jest.advanceTimersByTime(2000);
351332
await flushMicrotasks();
352333
expect(kubeConfigApi.injectKubeConfig).not.toHaveBeenCalled();
353334

354335
jest.advanceTimersByTime(2000);
355336
await flushMicrotasks();
356-
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledWith(namespace, 'ws-after-err');
337+
expect(kubeConfigApi.injectKubeConfig).toHaveBeenCalledWith(namespace, 'ws-retry-id');
357338
});
358339
});
359340

360341
// ── elapsed time logging ────────────────────────────────────────────────
361342

362-
test('logs elapsed time when injection succeeds quickly', async () => {
343+
test('logs elapsed time when injection succeeds', async () => {
363344
invoke();
364345
await capturedListener(dwMessage('Running', 'ws-123'));
365346

366347
expect(logger.info).toHaveBeenCalledWith(expect.stringContaining('0s after start request'));
367-
expect(logger.warn).not.toHaveBeenCalledWith(
368-
expect.stringContaining('exceeds the ~12s UDI entrypoint.sh window'),
369-
);
370-
});
371-
372-
test('warns when injection exceeds the 12 s UDI entrypoint window', async () => {
373-
invoke();
374-
375-
jest.advanceTimersByTime(15000);
376-
await capturedListener(dwMessage('Running', 'ws-slow'));
377-
378-
expect(logger.warn).toHaveBeenCalledWith(
379-
expect.stringContaining('exceeds the ~12s UDI entrypoint.sh window'),
380-
);
381-
expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Detection source: watch'));
382348
});
383349

384350
// ── ownership guard (stale callback safety) ───────────────────────────────

0 commit comments

Comments
 (0)