diff --git a/.project-docs/30-worklog/tasks/20260914-plugin-status-refresh-01a0858b.md b/.project-docs/30-worklog/tasks/20260914-plugin-status-refresh-01a0858b.md new file mode 100644 index 0000000..fe8b807 --- /dev/null +++ b/.project-docs/30-worklog/tasks/20260914-plugin-status-refresh-01a0858b.md @@ -0,0 +1,28 @@ +# Plugin connection status refresh after login + +## Scope and gate +- User reports that normal polling logs are quiet but plugin connection status only becomes connected after refreshing the page. Investigate status/heartbeat lifecycle and repair confirmed frontend defects; preserve quiet successful logs. +- Feature mode on main, /Users/andy/IdeaProjects/LWLT-AIBOT, base 9625110f44b0f1c2c6b10cdf58e5845512ff51c7. One worktree. Existing .idea and plugin 0.5.182 ZIP are known and untouched; tracked source clean. Overlap: Clear. +- Main-thread only. Own LianSyn-platform/app.js, a focused frontend regression test and this record. No .env reads, live ERP access, task mutations, extension reload, service restart, deployment or external send. No extension source or release changes planned. + +## Findings and plan +- Prior quiet-log fixes only gate request-start and successful completion logging; the POST heartbeat handler and browser timers were not changed. +- Automatic 30-second background refresh and focus/visibility listeners are registered only inside the initial initializeSession-success branch. Loading while logged out and then submitting the login form performs one ping but never registers the periodic refresh/listeners. A full reload with an existing session does register them. +- Reproduce using the actual page bootstrap and login handlers in an isolated fake browser. Make background refresh lifecycle available regardless of initial authentication, keep unauthenticated calls inert and avoid duplicate schedules. Preserve role gates and the 30-second interval. Verify recovery after transient disconnected status without a page reload and all existing checks. + +## User clarification and extended diagnosis +- User clarified this also happens while leaving the page open; initial-login scheduling alone is insufficient to explain all symptoms. +- Periodic bridge checks share backgroundRefreshInProgress with full task-list synchronization. A pending/continuously coalesced task refresh can prevent all subsequent bridge checks. Bridge PING also uses only a 1.2-second timeout despite awaiting worker wakeup, ERP identity inspection, extension update state and storage reads; a late response is dropped after timeout. Concurrent focus/manual/periodic probes can overwrite newer state. +- Verify these cases with fake time and isolated message/API handlers, then decouple bridge liveness from task-list progress, coalesce same-session probes, bound PING wait reasonably and reject stale session responses. BRIDGE_READY should trigger an account-bound fresh check rather than apply its unbound account snapshot. Actual user's browser timing remains unobserved; do not claim a unique runtime cause from source alone. + +## Implementation and verification +- Kept the prior quiet-success logging policy and extension 0.5.182 unchanged. Only platform app.js changed at runtime. +- Registered the existing 30-second interval and focus/visibility listeners once per page regardless of initial login; no requests while logged out. Moved bridge probing outside the shared task-sync in-progress gate; each account/session has one coalesced in-flight probe. Bounded PING timeout is now 10 seconds instead of 1.2 seconds, allowing worker wakeup/ERP inspection without discarding ordinary slower replies. Real timeouts still show disconnected and recover on later checks. +- BRIDGE_READY triggers a fresh check containing the expected ERP account, rather than applying its unbound account snapshot. Late success/failure from an old login cannot overwrite the new session or register its heartbeat. Server execution_ready=false remains a warning; administrator role still never probes or registers a browser worker. +- Full app bootstrap and real login/message/timer code run under fake DOM/time/API boundaries. Before-fix failures reproduced missing login scheduling, task-list blocking of heartbeat, two-second valid replies being discarded, overlapping probes and unbound readiness handling. Tests send only fake PING/heartbeat traffic; task dispatch and unrelated rendering are stubbed. +- Focused 10/10; control-plane 231/231; legacy 366/366; typecheck/build and git diff --check PASS. Preserved the async pingBridge API expected by the existing authorization regression. Source copy passed repository 10/10. Original repository 8/10 due to pre-existing IDE/OS residue and ignored prior archived logs, untouched. All 2682 copied files SHA-verified; non-example .env files, metadata, logs and generated build output excluded before reads. Final app.js synchronized and verified after the async-interface adjustment. +- Main-thread final read-only review PASS: no server logging changes, no extension/package changes, no new business execution path; scheduler remains 30 seconds with one probe per session, role and stale-session gates intact. Actual user browser timing is unobserved, so source reproductions establish failure modes rather than identify a unique live trigger. +- Temporary verification: /private/tmp/ltjt-bridge-status-*.log and /private/tmp/ltjt-bridge-status-source-manifest.json. No deployment, service restart, live ERP read/write, extension reload or external send performed. Deploy platform assets, then refresh once to load the fix; future connection recovery should update without reloading. + +## Promotion candidates +- Keep worker liveness independent of business-list refresh progress; coalesce concurrent checks, bound response wait and ignore stale session completions. UI readiness announcements require account-bound verification. Canonical promotion deferred to integration. diff --git a/LianSyn-platform/app-bridge-status.test.mjs b/LianSyn-platform/app-bridge-status.test.mjs new file mode 100644 index 0000000..9cea0f6 --- /dev/null +++ b/LianSyn-platform/app-bridge-status.test.mjs @@ -0,0 +1,232 @@ +import assert from 'node:assert/strict'; +import { readFileSync } from 'node:fs'; +import test from 'node:test'; +import vm from 'node:vm'; + +const source = readFileSync(new URL('./app.js', import.meta.url), 'utf8'); + +function browser({ authenticated = true, role = 'user', bridgeDelay = 0 } = {}) { + let time = 0, nextId = 0, sequence = 0; + const timers = new Map(), nodes = new Map(), listeners = new Map(); + const calls = { pings: 0, heartbeats: 0, ai: 0, tasks: 0 }; + const state = { authenticated, role, bridgeDelay, bridgeAvailable: true, executionReady: true, holdTasks: false }; + const storage = { getItem: () => null, setItem() {}, removeItem() {} }; + const addListener = (target, type, callback) => { + const key = `${target}:${type}`; + listeners.set(key, [...(listeners.get(key) || []), callback]); + }; + const node = selector => { + if (!nodes.has(selector)) nodes.set(selector, { + value: '', textContent: '', hidden: false, disabled: false, dataset: {}, + classList: { add() {}, remove() {}, toggle() {} }, + addEventListener: (type, callback) => addListener(selector, type, callback), + setAttribute() {}, querySelectorAll: () => [], querySelector: child => node(`${selector} ${child}`), + }); + return nodes.get(selector); + }; + const schedule = (callback, delay, interval = false) => { + const id = ++nextId; + timers.set(id, { callback, due: time + delay, interval: interval ? delay : 0 }); + return id; + }; + const document = { + visibilityState: 'visible', querySelector: node, querySelectorAll: () => [], + addEventListener: (type, callback) => addListener('document', type, callback), + }; + const window = { + location: { pathname: '/', origin: 'http://fixture.invalid', replace() {} }, + setTimeout: (callback, delay) => schedule(callback, delay), clearTimeout: id => timers.delete(id), + addEventListener: (type, callback) => addListener('window', type, callback), + postMessage(message) { + assert.equal(message.type, 'PING', 'status tests must never dispatch a task'); + calls.pings++; + if (!state.bridgeAvailable) return; + schedule(() => { + for (const callback of listeners.get('window:message') || []) callback({ source: window, data: { + source: 'LTJT_ORDER_ASSISTANT_EXTENSION', requestId: message.requestId, type: 'PONG', payload: { + ok: true, version: '99.0.0', bridge_installed_at: 'fixture', + erp_session: { account_matched: true, session_ready: true, host_permission_granted: true }, + }, + } }); + }, state.bridgeDelay); + }, + }; + const context = vm.createContext({ window, document, sessionStorage: storage, localStorage: storage, + setTimeout: window.setTimeout, clearTimeout: window.clearTimeout, + setInterval: (callback, delay) => schedule(callback, delay, true), clearInterval: id => timers.delete(id), + crypto: { randomUUID: () => `fixture-${++sequence}` }, Headers, AbortController, URL, URLSearchParams, + queueMicrotask, TextEncoder, Date, calls, fixtureState: state, + fetch: async resource => { + let status = 200, data = { ok: true }; + if (resource === '/api/auth/me') { + status = state.authenticated ? 200 : 401; + data = { user: { id: 'fixture-user', username: 'fixture', role: state.role, erp_account: 'fixture-erp' } }; + } else if (resource === '/api/auth/csrf') data.csrf_token = 'fixture-token'; + else if (resource === '/api/auth/login') { + state.authenticated = true; + data = { csrf_token: 'fixture-token', user: { id: 'fixture-user', username: 'fixture', role: state.role, erp_account: 'fixture-erp' } }; + } else if (resource === '/api/connections/heartbeat') { + calls.heartbeats++; + data.execution_ready = state.executionReady; + } else if (resource === '/api/status') { calls.ai++; data.ai_connected = true; } + else throw new Error(`unexpected status-test API: ${resource}`); + return { ok: status === 200, status, json: async () => data }; + }, + }); + // Execute real page bootstrap, auth, bridge messaging and scheduler code. + // Only unrelated rendering and business-list execution are stubbed. + vm.runInContext(source, context); + vm.runInContext(` + configurePageMode = () => {}; + renderTaskCards = renderTaskDetail = renderStatusDetails = setOutput = () => {}; + startRemoteEventStream = startPolling = stopPolling = () => {}; + autoDispatchReadyTasks = async () => {}; + syncAutomationSettings = async () => {}; + syncRemoteTasks = async () => { + calls.tasks++; + if (fixtureState.holdTasks) await new Promise(() => {}); + }; + `, context); + const flush = async () => { for (let i = 0; i < 30; i++) await Promise.resolve(); }; + async function advance(ms = 0) { + const end = time + ms; + await flush(); + while (true) { + const next = [...timers].filter(([, timer]) => timer.due <= end).sort((a, b) => a[1].due - b[1].due)[0]; + if (!next) break; + const [id, timer] = next; + time = timer.due; + if (timer.interval) timer.due += timer.interval; + else timers.delete(id); + timer.callback(); + await flush(); + } + time = end; + await flush(); + } + return { + state, calls, context, timers, listeners, node, advance, + status: () => node('#bridgeState .status-icon-value').textContent, + async boot() { await listeners.get('document:DOMContentLoaded')[0](); await advance(); }, + async login() { + const result = listeners.get('#loginForm:submit')[0]({ preventDefault() {} }); + await advance(state.bridgeDelay); + await result; + }, + emit(type, payload = {}) { + for (const callback of listeners.get(`window:${type}`) || []) callback(type === 'message' + ? { source: window, data: { source: 'LTJT_ORDER_ASSISTANT_EXTENSION', ...payload } } : payload); + }, + }; +} + +test('login after an unauthenticated page load starts ongoing status recovery without reload', async () => { + const b = browser({ authenticated: false }); + await b.boot(); + await b.advance(30_000); + assert.equal(b.calls.pings, 0); + await b.login(); + assert.equal(b.status(), '已连接'); + b.state.bridgeAvailable = false; + await b.advance(45_000); + assert.equal(b.status(), '未连接'); + b.state.bridgeAvailable = true; + await b.advance(30_000); + assert.equal(b.status(), '已连接'); + assert.ok(b.calls.heartbeats >= 2); +}); + +test('a pending task-list refresh does not stop bridge health or subsequent heartbeat recovery', async () => { + const b = browser(); await b.boot(); + b.state.holdTasks = true; + b.state.bridgeAvailable = false; + await b.advance(45_000); + assert.equal(b.status(), '未连接'); + const attempts = b.calls.pings; + b.state.bridgeAvailable = true; + await b.advance(30_000); + assert.ok(b.calls.pings > attempts, 'task synchronization must not hold the bridge scheduler'); + assert.equal(b.status(), '已连接'); +}); + +test('a two-second worker/ERP response stays connected and reaches the server heartbeat', async () => { + const b = browser({ bridgeDelay: 2_000 }); await b.boot(); + await b.advance(2_000); + assert.equal(b.status(), '已连接'); + assert.equal(b.calls.heartbeats, 1); +}); + +test('simultaneous focus and manual checks coalesce into one account-bound probe', async () => { + const b = browser(); await b.boot(); + b.state.bridgeDelay = 2_000; + const before = b.calls.pings; + b.emit('focus'); b.emit('focus'); + const first = vm.runInContext('pingBridge()', b.context); + const second = vm.runInContext('pingBridge()', b.context); + await b.advance(2_000); + assert.equal(await first, true); assert.equal(await second, true); + assert.equal(b.calls.pings - before, 1); +}); + +test('late status replies after logout cannot publish a heartbeat or restore connected status', async () => { + const b = browser({ bridgeDelay: 2_000 }); await b.boot(); + vm.runInContext("showLoginPanel(); setBridgeState('未连接', 'state-bad');", b.context); + await b.advance(2_000); + assert.equal(b.calls.heartbeats, 0); + assert.equal(b.status(), '未连接'); +}); + +test('bridge-ready announcement refreshes account-bound state and never accepts an unbound snapshot', async () => { + const b = browser(); await b.boot(); + const before = b.calls.pings; + b.emit('message', { type: 'BRIDGE_READY', payload: { ok: true, version: '99.0.0', erp_session: { account_matched: false } } }); + await b.advance(); + assert.equal(b.calls.pings, before + 1); + assert.equal(b.status(), '已连接'); +}); + +test('an admin page never sends a plugin probe or worker heartbeat', async () => { + const b = browser({ role: 'admin' }); await b.boot(); + await b.advance(90_000); b.emit('focus'); await b.advance(); + assert.equal(b.calls.pings, 0); assert.equal(b.calls.heartbeats, 0); +}); + +test('repeated login retains one timer and one focus listener; logout makes polling inert', async () => { + const b = browser({ authenticated: false }); await b.boot(); + for (let i = 0; i < 2; i++) { + await b.login(); + assert.equal(b.status(), '已连接'); + vm.runInContext('showLoginPanel()', b.context); + const count = b.calls.pings; + await b.advance(60_000); + assert.equal(b.calls.pings, count); + } + assert.equal([...b.timers.values()].filter(timer => timer.interval === 30_000).length, 1); + assert.equal(b.listeners.get('window:focus').length, 1); + assert.equal(b.listeners.get('document:visibilitychange').length, 1); +}); + +test('server worker rejection remains a warning until a later verified heartbeat recovers', async () => { + const b = browser(); b.state.executionReady = false; + await b.boot(); + assert.equal(b.status(), '已连接,有告警'); + b.state.executionReady = true; + await b.advance(30_000); + assert.equal(b.status(), '已连接'); +}); + +test('an old session response cannot overwrite a newer session check or heartbeat identity', async () => { + const b = browser(); await b.boot(); + b.state.bridgeDelay = 2_000; + const old = vm.runInContext('pingBridge()', b.context); + vm.runInContext("authUser = { id: 'next-user', role: 'user', erp_account: 'next-erp' }; browserConnectionId = 'next-connection';", b.context); + b.state.bridgeDelay = 0; + const current = vm.runInContext('pingBridge()', b.context); + await b.advance(); + assert.equal(await current, true); + const count = b.calls.heartbeats; + await b.advance(2_000); + assert.equal(await old, false); + assert.equal(b.calls.heartbeats, count); + assert.equal(b.status(), '已连接'); +}); diff --git a/LianSyn-platform/app.js b/LianSyn-platform/app.js index 2d74c6d..afccd80 100644 --- a/LianSyn-platform/app.js +++ b/LianSyn-platform/app.js @@ -17,6 +17,7 @@ const HISTORY_TASK_PAGE_SIZE = 24; const OPERATIONS_DASHBOARD_PAGE_SIZE = 20; const DEFAULT_API_TIMEOUT_MS = 15_000; const AUTH_API_TIMEOUT_MS = 10_000; +const BRIDGE_PING_TIMEOUT_MS = 10_000; const RESULT_API_TIMEOUT_MS = 20_000; const TASK_DELETE_API_TIMEOUT_MS = 60_000; const LOCAL_TASK_OVERLAY_TTL_MS = 10 * 60_000; @@ -70,6 +71,7 @@ const taskInputHistoryRequests = new Map(); const localTaskOverlayStore = new Map(); let pollInProgress = false; let backgroundRefreshInProgress = false; +let bridgePingInFlight = null; let taskListMeta = { total: 0, offset: 0, @@ -4706,7 +4708,9 @@ window.addEventListener('message', (event) => { if (message.source !== EXTENSION_SOURCE) return; if (!canUseTaskDataPlane()) return; if (message.type === 'BRIDGE_READY') { - applyBridgePayload(message.payload || { ok: true }); + // The announcement has no expected ERP account. Verify this session rather + // than overwriting an account-bound result with its unbound snapshot. + pingBridge().catch(() => {}); return; } if (message.type === 'TASK_RESULT_CHANGED') { @@ -5062,23 +5066,40 @@ async function confirmAndSubmitToErpPlugin(task) { async function pingBridge() { if (!canUseTaskDataPlane()) return false; + const user = authUser; + const connectionId = browserConnectionId; + if (bridgePingInFlight?.user === user && bridgePingInFlight.connectionId === connectionId) { + return bridgePingInFlight.promise; + } + const probe = { user, connectionId, promise: null }; + probe.promise = checkBridgeConnection(user, connectionId).finally(() => { + if (bridgePingInFlight === probe) bridgePingInFlight = null; + }); + bridgePingInFlight = probe; + return probe.promise; +} + +async function checkBridgeConnection(user, connectionId) { + const isCurrentSession = () => authUser === user && browserConnectionId === connectionId && canUseTaskDataPlane(); try { const result = await sendToExtension('PING', { - expected_erp_account: authUser?.erp_account || '' - }, 1200); + expected_erp_account: user.erp_account || '' + }, BRIDGE_PING_TIMEOUT_MS); + if (!isCurrentSession()) return false; applyBridgePayload(result); - if (authUser && result?.ok) { + if (result?.ok) { try { const heartbeat = await apiRequest('/api/connections/heartbeat', { method: 'POST', body: { - connection_id: browserConnectionId, + connection_id: connectionId, extension_version: result.version || '', - erp_account: authUser.erp_account || '', + erp_account: user.erp_account || '', erp_account_matched: result.erp_session?.account_matched === true, metadata: { bridge_installed_at: result.bridge_installed_at || '' } } }); + if (!isCurrentSession()) return false; if (heartbeat.execution_ready !== true) { erpSessionReady = false; latestBridgeStatus = { @@ -5094,6 +5115,7 @@ async function pingBridge() { return false; } } catch (heartbeatError) { + if (!isCurrentSession()) return false; erpSessionReady = false; latestBridgeStatus = { ...latestBridgeStatus, @@ -5107,6 +5129,7 @@ async function pingBridge() { } return bridgeConnected && erpSessionReady; } catch (error) { + if (!isCurrentSession()) return false; bridgeConnected = false; erpAutomationEnabled = false; extensionCompatible = false; @@ -5181,11 +5204,17 @@ async function createTask() { } async function refreshBackgroundState() { - if (!authUser || backgroundRefreshInProgress) return; + if (!authUser) return; + // Worker liveness must not wait for task-list/database synchronization. + // pingBridge coalesces timer, focus and manual checks for this session. + const bridgeRefresh = canUseTaskDataPlane() ? pingBridge() : Promise.resolve(false); + if (backgroundRefreshInProgress) { + await bridgeRefresh; + return; + } backgroundRefreshInProgress = true; try { - const operations = [pingAi()]; - if (canUseTaskDataPlane()) operations.push(pingBridge()); + const operations = [pingAi(), bridgeRefresh]; if (isAdministrator()) operations.push(syncAutomationSettings({ background: true })); if (IS_CHANNELS_PAGE && isAdministrator()) { operations.push(syncChannels(), syncLeaderSummaryWebhookStatus()); @@ -6295,26 +6324,27 @@ document.addEventListener('DOMContentLoaded', async () => { if (!button) return; void copyTaskLifecycle(button); }); + // Register once per page, even when initial session restoration fails. + // refreshBackgroundState remains inert while logged out; later login uses + // these same listeners/timer without requiring a full page reload. + setInterval(() => { + refreshBackgroundState().catch(() => {}); + }, 30_000); + document.addEventListener('visibilitychange', () => { + if (document.visibilityState === 'hidden') { + stopPolling(); + return; + } + refreshBackgroundState().catch(() => {}); + if (hasPollableRuntimeTasks()) startPolling(); + }); + window.addEventListener('focus', () => { + refreshBackgroundState().catch(() => {}); + }); if (await initializeSession()) { if (IS_TASK_PAGE && canUseTaskDataPlane()) renderTaskCards(); pingAi().catch(() => {}); if (canUseTaskDataPlane()) pingBridge().catch(() => {}); - // The control plane caches this health probe; keep the browser refresh - // interval conservative so status checks cannot pressure the Agent API. - setInterval(() => { - refreshBackgroundState().catch(() => {}); - }, 30_000); - document.addEventListener('visibilitychange', () => { - if (document.visibilityState === 'hidden') { - stopPolling(); - return; - } - refreshBackgroundState().catch(() => {}); - if (hasPollableRuntimeTasks()) startPolling(); - }); - window.addEventListener('focus', () => { - refreshBackgroundState().catch(() => {}); - }); if (IS_TASK_PAGE && canUseTaskDataPlane() && currentTaskId) renderTaskDetail(); if (IS_TASK_PAGE && canUseTaskDataPlane() && hasPollableRuntimeTasks()) startPolling(); }