From afcce9da8541b9919798e7e8bb2315c66ee41c8e Mon Sep 17 00:00:00 2001 From: Monikon Date: Thu, 20 Aug 2026 22:38:10 +0300 Subject: [PATCH 1/4] fix(runner): check the polling deadline after the attempt, not instead of it MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Every polling helper was shaped `while (Date.now() < deadline) { attempt; sleep }`, so the loop could exit on the clock without ever looking at what arrived during the last sleep. The value is in the buffer, the wait reports a timeout, and the log reads "the confirmation arrived and it timed out anyway". The window is not the 50ms it looks like. A bot loading chunks blocks the event loop for seconds; the socket data flushes in one batch when it unblocks, and the sleep timer that was already pending resolves past the deadline. Under that stall the AuthMe preflight failed with `did not confirm registration in time` on a run whose log shows `Successfully registered!` five messages before the failure was printed. The loops now check the deadline after the attempt, so the last thing each does before giving up is look one more time. `poll`, `waitForAssertion` and `waitUntil` in utils, `pollAssertion` and `pollUntilPass` in matchers — the same omission in all five. `waitForStable` already had the right order and is untouched. One deliberate consequence: a helper called with a timeout of zero now makes one attempt rather than none, which is what "poll until the deadline" should have meant. --- runner-package/lib/matchers.ts | 9 +++++++-- runner-package/lib/utils.ts | 26 +++++++++++++++++++------- 2 files changed, 26 insertions(+), 9 deletions(-) diff --git a/runner-package/lib/matchers.ts b/runner-package/lib/matchers.ts index 55a5bd4..cfbc3f3 100644 --- a/runner-package/lib/matchers.ts +++ b/runner-package/lib/matchers.ts @@ -51,8 +51,11 @@ export class RunnerMatchers extends Matchers { const expected = !this.isNot; const deadline = Date.now() + timeout; - while (Date.now() < deadline) { + // Deadline last, as in `poll`: the condition is checked once more after the final + // wait, so a message that lands during it still counts. + for (;;) { if (condition() === expected) return; + if (Date.now() >= deadline) break; await new Promise(resolve => setTimeout(resolve, pollingRate)); } @@ -195,7 +198,8 @@ export class PollMatchers { const deadline = Date.now() + timeout; let lastError: unknown; - while (Date.now() < deadline) { + // Deadline last, as in `poll`: one more attempt after the final wait. + for (;;) { const value = await this.fn(); try { const m = new Matchers(value, this.isNot); @@ -204,6 +208,7 @@ export class PollMatchers { } catch (e) { lastError = e; } + if (Date.now() >= deadline) break; await sleep(Math.min(interval, Math.max(0, deadline - Date.now()))); } diff --git a/runner-package/lib/utils.ts b/runner-package/lib/utils.ts index b7e558c..d56c399 100644 --- a/runner-package/lib/utils.ts +++ b/runner-package/lib/utils.ts @@ -13,7 +13,14 @@ export const sleep = (ms: number, signal?: AbortSignal) => { /** * Polls `fn` until it returns a non-undefined value, or throws on timeout. - * Simple, race-condition-free, works with any state. + * + * The deadline is checked *after* `fn` runs, never instead of it: the last thing this does + * before giving up is look one more time. Checking the clock first discards whatever landed + * during the final sleep, and that window is not the 50ms it looks like — a bot loading + * chunks stalls the event loop for seconds, and when it comes back the value that would have + * passed the poll is already there while the clock is past the deadline. That failure reads + * as "the message arrived and the wait timed out anyway", which is exactly as confusing as + * it sounds. */ export async function poll( fn: () => T | undefined | Promise, @@ -27,10 +34,11 @@ export async function poll( const { timeout = 5000, interval = 50, message = 'poll() timed out', signal } = options; const deadline = Date.now() + timeout; - while (Date.now() < deadline) { + for (;;) { if (signal?.aborted) throw new Error('Aborted'); const result = await fn(); if (result !== undefined) return result; + if (Date.now() >= deadline) break; await sleep(interval, signal); } @@ -45,18 +53,20 @@ export async function waitForAssertion( fn: () => Promise, { timeout = 5000, interval = 250, signal }: { timeout?: number, interval?: number, signal?: AbortSignal } = {} ): Promise { - const start = Date.now(); + const deadline = Date.now() + timeout; let lastError: unknown; - while (Date.now() - start < timeout) { + // Deadline last, as in `poll`: the final attempt happens after the final sleep. + for (;;) { if (signal?.aborted) throw new Error('Aborted'); try { await fn(); return; // passed } catch (e) { lastError = e; - await sleep(interval, signal); } + if (Date.now() >= deadline) break; + await sleep(interval, signal); } throw lastError; } @@ -76,13 +86,15 @@ export async function waitUntil( signal }: { timeout?: number, interval?: number, message?: string, signal?: AbortSignal } = {} ): Promise { - const start = Date.now(); + const deadline = Date.now() + timeout; - while (Date.now() - start < timeout) { + // Deadline last, as in `poll`: the final check happens after the final sleep. + for (;;) { if (signal?.aborted) throw new Error('Aborted'); if (await predicate()) { return; // condition met } + if (Date.now() >= deadline) break; await sleep(interval, signal); } From 6e05611a81b71048879cb2c4dc06effdd10eba62 Mon Sep 17 00:00:00 2001 From: Monikon Date: Thu, 20 Aug 2026 22:39:09 +0300 Subject: [PATCH 2/4] fix(runner): read the bot's name when logging, not before it has one `_registerPersistentListeners` captured `username` into a local and printed that local on every chat line. `username` is `bot.username`, which mineflayer leaves undefined until the client is through the handshake, so the listeners could go up holding nothing and every message afterwards read "[Bot undefined]". Those are the lines worth reading when a login wall misbehaves, so it cost exactly where it hurt. `_captureSpawnPromise` already reads the name lazily for this reason; these three log calls now do the same. --- runner-package/lib/player.ts | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/runner-package/lib/player.ts b/runner-package/lib/player.ts index d474d48..9d4a7c5 100644 --- a/runner-package/lib/player.ts +++ b/runner-package/lib/player.ts @@ -115,25 +115,30 @@ export class PlayerWrapper { if (this._listenersBot === this.bot) return; this._listenersBot = this.bot; - const botUsername = this.username; + // Read on each line, not captured here: `username` is `bot.username`, which stays + // undefined until the client is through the handshake (see `_captureSpawnPromise`, + // which reads it the same way). A snapshot taken here is what put "[Bot undefined]" + // in front of chat lines — including every line a login wall produces, which are the + // ones worth reading when authentication goes wrong. + const botUsername = (): string | undefined => this.bot.username; const bot = this.bot; bot.on('message', (jsonMsg: unknown) => { const message = String(jsonMsg); - console.log(pc.dim(`[Bot ${botUsername}] Received message: "${message}"`)); + console.log(pc.dim(`[Bot ${botUsername()}] Received message: "${message}"`)); this.messageBuffer.push(message); }); bot.on('windowOpen', (window: unknown) => { if (process.env.PLUGWRIGHT_DEBUG !== '1') return; const win = window as { title?: string; type?: string | number; slots?: unknown[] }; - console.log(pc.gray(`[DEBUG] [Bot ${botUsername}] Global windowOpen event - Title: "${win.title}", Type: ${win.type}, SlotCount: ${win.slots?.length}`)); + console.log(pc.gray(`[DEBUG] [Bot ${botUsername()}] Global windowOpen event - Title: "${win.title}", Type: ${win.type}, SlotCount: ${win.slots?.length}`)); }); bot.on('windowClose', (window: unknown) => { if (process.env.PLUGWRIGHT_DEBUG !== '1') return; const win = window as { title?: string }; - console.log(pc.gray(`[DEBUG] [Bot ${botUsername}] windowClose event - Window: ${win?.title || 'unknown'}`)); + console.log(pc.gray(`[DEBUG] [Bot ${botUsername()}] windowClose event - Window: ${win?.title || 'unknown'}`)); }); } From 3e811fac149c6ec8e95513eb8943f03d057e2fe7 Mon Sep 17 00:00:00 2001 From: Drownek Date: Sat, 22 Aug 2026 14:49:09 +0200 Subject: [PATCH 3/4] fix(runner): apply the same loop logic to waitForStable and GuiItemLocator --- runner-package/lib/utils.ts | 7 ++++--- runner-package/lib/wrappers.ts | 3 ++- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/runner-package/lib/utils.ts b/runner-package/lib/utils.ts index d56c399..8aa3bac 100644 --- a/runner-package/lib/utils.ts +++ b/runner-package/lib/utils.ts @@ -127,20 +127,21 @@ export async function waitForStable( const deadline = Date.now() + timeout; // First, wait until the condition becomes true - while (Date.now() < deadline) { + for (;;) { if (signal?.aborted) throw new Error('Aborted'); if (await predicate()) break; - await sleep(interval, signal); if (Date.now() >= deadline) throw new Error(message); + await sleep(interval, signal); } // Then, verify it stays true for the entire `duration` const stableDeadline = Date.now() + duration; - while (Date.now() < stableDeadline) { + for (;;) { if (signal?.aborted) throw new Error('Aborted'); if (!(await predicate())) { throw new Error(message); } + if (Date.now() >= stableDeadline) break; await sleep(Math.min(interval, Math.max(0, stableDeadline - Date.now())), signal); } } \ No newline at end of file diff --git a/runner-package/lib/wrappers.ts b/runner-package/lib/wrappers.ts index 67996a9..31e5ae8 100644 --- a/runner-package/lib/wrappers.ts +++ b/runner-package/lib/wrappers.ts @@ -64,7 +64,7 @@ export class GuiItemLocator { const { timeout = 5000 } = options; const startTime = Date.now(); - while (Date.now() - startTime < timeout) { + for (;;) { const currentGui = this.gui._getCurrentGuiSnapshot(); if (currentGui) { const item = currentGui._findItemInternal(this.predicate); @@ -73,6 +73,7 @@ export class GuiItemLocator { return; } } + if (Date.now() - startTime >= timeout) break; await new Promise(resolve => setTimeout(resolve, 100)); } From fb136955d5b46ce01e1a6d02d481bbb9084454ac Mon Sep 17 00:00:00 2001 From: Drownek Date: Sat, 22 Aug 2026 14:54:34 +0200 Subject: [PATCH 4/4] fix(runner): apply the polling loop pattern to deprecated waitForGuiItem and clickGuiItem --- runner-package/lib/wrappers.ts | 68 ++++++++++------------------------ 1 file changed, 19 insertions(+), 49 deletions(-) diff --git a/runner-package/lib/wrappers.ts b/runner-package/lib/wrappers.ts index 31e5ae8..c33091a 100644 --- a/runner-package/lib/wrappers.ts +++ b/runner-package/lib/wrappers.ts @@ -441,21 +441,8 @@ export function createPlayerExtensions(bot: Bot) { const { timeout = 5000, pollingRate = 100 } = options; const startTime = Date.now(); - return new Promise((resolve, reject) => { - const checkForItem = () => { - const elapsed = Date.now() - startTime; - - if (elapsed >= timeout) { - clearInterval(pollInterval); - reject(new Error(`[Player] Timeout waiting for GUI item (${timeout}ms)`)); - return; - } - - // Check if there's a current window open - if (!bot.currentWindow) { - return; // Continue polling - } - + for (;;) { + if (bot.currentWindow) { const window = bot.currentWindow as Window; const items = window.slots .filter((item): item is RawItem => item != null) @@ -464,18 +451,17 @@ export function createPlayerExtensions(bot: Bot) { const matchedItem = items.find(itemMatcher); if (matchedItem) { - clearInterval(pollInterval); console.log(`[Player] Found GUI item: ${matchedItem.getDisplayName()} at slot ${matchedItem.slot}`); - resolve(matchedItem); + return matchedItem; } - }; + } - // Start polling - const pollInterval = setInterval(checkForItem, pollingRate); + if (Date.now() - startTime >= timeout) { + throw new Error(`[Player] Timeout waiting for GUI item (${timeout}ms)`); + } - // Initial check - checkForItem(); - }); + await new Promise(resolve => setTimeout(resolve, pollingRate)); + } }, async clickGuiItem( @@ -487,20 +473,8 @@ export function createPlayerExtensions(bot: Bot) { const { timeout = 5000, pollingRate = 100 } = options; const startTime = Date.now(); - return new Promise((resolve, reject) => { - const checkForItem = async () => { - const elapsed = Date.now() - startTime; - - if (elapsed >= timeout) { - clearInterval(pollInterval); - reject(new Error(`[Player] Timeout waiting for GUI item to click (${timeout}ms)`)); - return; - } - - if (!bot.currentWindow) { - return; - } - + for (;;) { + if (bot.currentWindow) { const window = bot.currentWindow as Window; const items = window.slots .filter((item): item is RawItem => item != null) @@ -509,8 +483,6 @@ export function createPlayerExtensions(bot: Bot) { const matchedItem = items.find(itemMatcher); if (matchedItem) { - clearInterval(pollInterval); - const lore = matchedItem.getLore(); console.log(`[Player] Clicking GUI item: ${matchedItem.getDisplayName()}`); console.log(` Material: ${matchedItem.name}`); @@ -519,19 +491,17 @@ export function createPlayerExtensions(bot: Bot) { console.log(` Lore: ${lore.join(' | ')}`); } - try { - await bot.clickWindow(matchedItem.slot, 0, 0); - resolve(); - } catch (error) { - reject(error); - } + await bot.clickWindow(matchedItem.slot, 0, 0); + return; } - }; + } - const pollInterval = setInterval(checkForItem, pollingRate); + if (Date.now() - startTime >= timeout) { + throw new Error(`[Player] Timeout waiting for GUI item to click (${timeout}ms)`); + } - checkForItem(); - }); + await new Promise(resolve => setTimeout(resolve, pollingRate)); + } }, async waitForGui(