From 62660b288d3c6bd130fee44331fa6e5855ce0e33 Mon Sep 17 00:00:00 2001 From: Mitch Lillie Date: Thu, 16 Apr 2026 14:43:55 -0700 Subject: [PATCH 1/2] Add build ID tracing and diagnostic levers for dev session pipeline MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Tracing: every file change gets a monotonic [build:N] ID that traces through the full pipeline in --verbose output. Logs at every stage: onChange → handleWatcherEvents → buildExtensions → generateExtensionTypes → emit('all') → DevSession.onEvent → validateAppEvent → processEvents → bundleExtensionsAndUpload → result Levers (env vars to isolate the permanent failure in #2417): DEV_SKIP_GENERATE_TYPES=1 Skip generateExtensionTypes() after build. Tests if this call hangs and permanently blocks emit('all'). DEV_SKIP_RESCAN_IMPORTS=1 Skip rescanImports() which can restart the file watcher. Tests if a watcher restart during vite mid-write permanently loses the admin extension's watched files. DEV_SERIALIZE_ONCHANGE=1 Serialize onChange handlers with a mutex. Tests if concurrent .then() chains corrupting shared state (this.app, bundle dir) cause the permanent break. DEV_UPLOAD_TIMEOUT_MS=15000 Add a timeout to bundleExtensionsAndUpload. Tests if a hung GCS upload or API call permanently blocks the SerialBatchProcessor. --- .../dev/app-events/app-event-watcher.ts | 79 ++++++++++++++----- .../app/src/cli/services/dev/extension.ts | 4 +- .../dev/processes/dev-session/dev-session.ts | 41 ++++++++-- 3 files changed, 99 insertions(+), 25 deletions(-) diff --git a/packages/app/src/cli/services/dev/app-events/app-event-watcher.ts b/packages/app/src/cli/services/dev/app-events/app-event-watcher.ts index 5bda637f46..a7df2ccc5c 100644 --- a/packages/app/src/cli/services/dev/app-events/app-event-watcher.ts +++ b/packages/app/src/cli/services/dev/app-events/app-event-watcher.ts @@ -81,6 +81,8 @@ export interface AppEvent { path: string startTime: [number, number] appWasReloaded?: boolean + /** Monotonic build ID for tracing an event through the pipeline */ + buildId?: number } type ExtensionBuildResult = {status: 'ok'; uid: string} | {status: 'error'; error: string; file?: string; uid: string} @@ -88,6 +90,8 @@ type ExtensionBuildResult = {status: 'ok'; uid: string} | {status: 'error'; erro /** * App event watcher will emit events when changes are detected in the file system. */ +let nextBuildId = 1 + export class AppEventWatcher extends EventEmitter { buildOutputPath: string private app: AppLinkedInterface @@ -125,35 +129,72 @@ export class AppEventWatcher extends EventEmitter { } this.fileWatcher = this.fileWatcher ?? new FileWatcher(this.app, this.options) + // Mutex for DEV_SERIALIZE_ONCHANGE lever + let onChangeLock: Promise = Promise.resolve() + this.fileWatcher.onChange((events) => { - handleWatcherEvents(events, this.app, this.options) - .then(async (appEvent) => { - if (appEvent?.extensionEvents.length === 0) outputDebug('Change detected, but no extensions were affected') - if (!appEvent) return + const buildId = nextBuildId++ + outputDebug(`[build:${buildId}] onChange: ${events.length} event(s): ${events.map((e) => `${e.type}:${e.path.split('/').pop()}`).join(', ')}\n`, this.options.stdout) + + const doWork = async () => { + const appEvent = await handleWatcherEvents(events, this.app, this.options) + if (appEvent?.extensionEvents.length === 0) { + outputDebug(`[build:${buildId}] no extensions affected, skipping`) + return + } + if (!appEvent) { + outputDebug(`[build:${buildId}] handleWatcherEvents returned undefined, skipping`) + return + } - this.app = appEvent.app - if (appEvent.appWasReloaded) this.fileWatcher?.updateApp(this.app) + appEvent.buildId = buildId + const extSummary = appEvent.extensionEvents.map((e) => `${e.type}:${e.extension.handle}`).join(', ') + outputDebug(`[build:${buildId}] processing ${appEvent.extensionEvents.length} extension event(s): ${extSummary}\n`, this.options.stdout) + + this.app = appEvent.app + if (appEvent.appWasReloaded) this.fileWatcher?.updateApp(this.app) + + // LEVER: DEV_SKIP_RESCAN_IMPORTS — skip rescanImports to test if watcher restart causes the break + if (!process.env.DEV_SKIP_RESCAN_IMPORTS) { await this.rescanImports(appEvent) + } else { + outputDebug(`[build:${buildId}] LEVER: skipping rescanImports\n`, this.options.stdout) + } - // Find affected created/updated extensions and build them - const buildableEvents = appEvent.extensionEvents.filter((extEvent) => extEvent.type !== EventType.Deleted) + // Find affected created/updated extensions and build them + const buildableEvents = appEvent.extensionEvents.filter((extEvent) => extEvent.type !== EventType.Deleted) - // Build the created/updated extensions and update the extension events with the build result - await this.buildExtensions(buildableEvents) + // Build the created/updated extensions and update the extension events with the build result + await this.buildExtensions(buildableEvents) + outputDebug(`[build:${buildId}] buildExtensions complete\n`, this.options.stdout) - // Generate the extension types after building the extensions so new imports are included - // Skip if the app was reloaded, as generateExtensionTypes was already called during reload - if (!appEvent.appWasReloaded) { - await this.app.generateExtensionTypes() - } + // LEVER: DEV_SKIP_GENERATE_TYPES — skip generateExtensionTypes to test if it hangs + if (!appEvent.appWasReloaded && !process.env.DEV_SKIP_GENERATE_TYPES) { + await this.app.generateExtensionTypes() + } else if (process.env.DEV_SKIP_GENERATE_TYPES) { + outputDebug(`[build:${buildId}] LEVER: skipping generateExtensionTypes\n`, this.options.stdout) + } + outputDebug(`[build:${buildId}] post-build steps complete\n`, this.options.stdout) + + // Find deleted extensions and delete their previous build output + await this.deleteExtensionsBuildOutput(appEvent) + outputDebug(`[build:${buildId}] emitting 'all'\n`, this.options.stdout) + this.emit('all', appEvent) + outputDebug(`[build:${buildId}] 'all' emitted, listeners returned\n`, this.options.stdout) + } - // Find deleted extensions and delete their previous build output - await this.deleteExtensionsBuildOutput(appEvent) - this.emit('all', appEvent) + // LEVER: DEV_SERIALIZE_ONCHANGE — serialize onChange handlers to test if concurrency causes the break + if (process.env.DEV_SERIALIZE_ONCHANGE) { + onChangeLock = onChangeLock.then(doWork).catch((error) => { + outputDebug(`[build:${buildId}] ERROR in onChange pipeline: ${error.message}\n`, this.options.stdout) + this.emit('error', error) }) - .catch((error) => { + } else { + doWork().catch((error) => { + outputDebug(`[build:${buildId}] ERROR in onChange pipeline: ${error.message}\n`, this.options.stdout) this.emit('error', error) }) + } }) await this.fileWatcher.start() diff --git a/packages/app/src/cli/services/dev/extension.ts b/packages/app/src/cli/services/dev/extension.ts index 91eab7eb2b..f3d4ef880c 100644 --- a/packages/app/src/cli/services/dev/extension.ts +++ b/packages/app/src/cli/services/dev/extension.ts @@ -146,7 +146,8 @@ export async function devUIExtensions(options: ExtensionDevOptions): Promise { + const eventHandler = async ({appWasReloaded, app, extensionEvents, buildId}: AppEvent) => { + outputDebug(`[build:${buildId}] devUIExtensions eventHandler received (${extensionEvents.length} events)`, payloadOptions.stdout) if (appWasReloaded) { extensions = app.allExtensions.filter((ext) => ext.isPreviewable) } @@ -155,6 +156,7 @@ export async function devUIExtensions(options: ExtensionDevOptions): Promise e.buildId).join(',') + await this.logger.debug(`[build:${buildIds}] processEvents: ${events.length} event(s), ${this.failedEvents.length} failed retries`) // Include any previously failed events to be processed again const allEvents = [...this.failedEvents, ...events] const event = this.consolidateAppEvents(allEvents) this.failedEvents = [] - if (!event) return + if (!event) { + await this.logger.debug(`[build:${buildIds}] processEvents: consolidate returned undefined, skipping`) + return + } this.statusManager.setMessage('CHANGE_DETECTED') this.updatePreviewURL(event) await this.logger.logExtensionEvents(event) const networkStartTime = startHRTime() - const result = await this.bundleExtensionsAndUpload(event) + await this.logger.debug(`[build:${event.buildId}] processEvents: starting bundleExtensionsAndUpload`) + + // LEVER: DEV_UPLOAD_TIMEOUT_MS — detect if bundleExtensionsAndUpload hangs forever + const timeoutMs = process.env.DEV_UPLOAD_TIMEOUT_MS ? parseInt(process.env.DEV_UPLOAD_TIMEOUT_MS, 10) : 0 + let result: DevSessionResult + if (timeoutMs > 0) { + const timeout = new Promise((_, reject) => + setTimeout(() => reject(new Error(`[build:${event.buildId}] bundleExtensionsAndUpload TIMED OUT after ${timeoutMs}ms`)), timeoutMs), + ) + try { + result = await Promise.race([this.bundleExtensionsAndUpload(event), timeout]) + } catch (error: any) { + await this.logger.debug(error.message) + result = {status: 'unknown-error', error} + } + } else { + result = await this.bundleExtensionsAndUpload(event) + } + await this.logger.debug(`[build:${event.buildId}] processEvents: result=${result.status}`) await this.handleDevSessionResult(result, event) await this.logger.debug( - `✅ Event handled [Network: ${endHRTimeInMs(networkStartTime)}ms - Total: ${endHRTimeInMs(event.startTime)}ms]`, + `[build:${event.buildId}] Event handled [Network: ${endHRTimeInMs(networkStartTime)}ms - Total: ${endHRTimeInMs(event.startTime)}ms]`, ) } @@ -184,6 +211,7 @@ export class DevSession { */ private async validateAppEvent(event: AppEvent): Promise { if (!this.statusManager.status.isReady) { + await this.logger.debug(`[build:${event.buildId}] validate: NOT READY`) await this.logger.warning('Change detected, but dev preview is not ready yet.') return false } @@ -191,18 +219,21 @@ export class DevSession { // If there are any build errors, don't update the dev session const errors = this.parseBuildErrors(event) if (errors.length) { + await this.logger.debug(`[build:${event.buildId}] validate: BUILD ERRORS (${errors.length})`) await this.logger.logMultipleErrors(errors) this.statusManager.setMessage('BUILD_ERROR') return false } if (event.extensionEvents.length === 0) { + await this.logger.debug(`[build:${event.buildId}] validate: NO EXTENSION EVENTS`) // The app was probably reloaded, but no extensions were affected, we are ready for new changes. // But we shouldn't trigger a new dev session update in this case. this.statusManager.setMessage('READY') return false } + await this.logger.debug(`[build:${event.buildId}] validate: VALID (${event.extensionEvents.length} events)`) return true } From f939694cb8332763d6ea85135b4e912c29851a61 Mon Sep 17 00:00:00 2001 From: Mitch Lillie Date: Thu, 16 Apr 2026 14:46:43 -0700 Subject: [PATCH 2/2] Add stress test script for dev session hot reload Toggles source code strings in a hosted app every N seconds to trigger repeated vite rebuilds. Used alongside the diagnostic levers to isolate the permanent failure in #2417. --- scripts/dev-session-stress-test.sh | 72 ++++++++++++++++++++++++++++++ 1 file changed, 72 insertions(+) create mode 100755 scripts/dev-session-stress-test.sh diff --git a/scripts/dev-session-stress-test.sh b/scripts/dev-session-stress-test.sh new file mode 100755 index 0000000000..339826a8ea --- /dev/null +++ b/scripts/dev-session-stress-test.sh @@ -0,0 +1,72 @@ +#!/bin/bash +# +# Stress test for dev session hot reloading (issue #2417). +# +# Makes small source code changes to a hosted app at a configurable interval +# to trigger repeated vite rebuilds → admin extension builds → dev session updates. +# Designed for apps generated from the Preact template with a home/ directory. +# +# Usage: +# ./dev-session-stress-test.sh [interval_seconds] [duration_minutes] +# +# Example: +# ./dev-session-stress-test.sh ~/src/apps/my-app 5 10 +# +# The script toggles strings back and forth so the app stays valid. +# Kill with: kill $(pgrep -f dev-session-stress-test) + +set -euo pipefail + +APP_PATH="${1:?Usage: $0 [interval_seconds] [duration_minutes]}" +INTERVAL="${2:-5}" +DURATION="${3:-10}" +ITERATIONS=$(( (DURATION * 60) / INTERVAL )) + +# Verify the app has the expected structure +if [ ! -f "$APP_PATH/home/pages/home.tsx" ]; then + echo "Error: $APP_PATH/home/pages/home.tsx not found." + echo "This script is designed for apps with a home/ directory (Preact template)." + exit 1 +fi + +cd "$APP_PATH" +echo "Stress test: $ITERATIONS changes every ${INTERVAL}s for ${DURATION}m in $APP_PATH" + +toggle() { + local file="$1" from="$2" to="$3" + if grep -q "$from" "$file" 2>/dev/null; then + sed -i '' "s|$from|$to|" "$file" + else + sed -i '' "s|$to|$from|" "$file" + fi +} + +for i in $(seq 1 $ITERATIONS); do + case $((i % 6)) in + 1) toggle home/pages/home.tsx \ + 'Create frequently asked questions to boost sales.' \ + 'Add FAQs to help customers find answers quickly.' + echo "[$(date '+%H:%M:%S')] $i/$ITERATIONS: home.tsx paragraph" ;; + 2) toggle home/pages/home.tsx \ + 'alt="Illustration of FAQ creation"' \ + 'alt="FAQ empty state illustration"' + echo "[$(date '+%H:%M:%S')] $i/$ITERATIONS: home.tsx alt text" ;; + 3) toggle home/pages/faq.tsx \ + 'e.g. What is your return policy?' \ + 'e.g. How long does shipping take?' + echo "[$(date '+%H:%M:%S')] $i/$ITERATIONS: faq.tsx placeholder" ;; + 4) toggle home/pages/faq.tsx \ + 'Provide a clear, helpful answer' \ + 'Write a concise and informative response' + echo "[$(date '+%H:%M:%S')] $i/$ITERATIONS: faq.tsx details" ;; + 5) toggle home/pages/_404.tsx \ + 'Go to home' 'Back to FAQs' + echo "[$(date '+%H:%M:%S')] $i/$ITERATIONS: _404.tsx button" ;; + 0) toggle home/index.html \ + 'Vite + Preact' 'FAQ Manager' + echo "[$(date '+%H:%M:%S')] $i/$ITERATIONS: index.html title" ;; + esac + [ "$i" -lt "$ITERATIONS" ] && sleep "$INTERVAL" +done + +echo "[$(date '+%H:%M:%S')] Done. $ITERATIONS changes over ${DURATION}m."