fix(ext): v0.5.8 false positive zombie socket disconnect bug resolve (timestamp replace setTimeout)

This commit is contained in:
Variet Worker
2026-03-24 07:00:43 +09:00
parent ecebec3906
commit f13bcc871c
12 changed files with 141 additions and 73 deletions

View File

@@ -12,7 +12,12 @@
## 포맷
```markdown
### [2026-03-23] [Extension] Cross-Project DOM Observer Leakage
- **증상**: 다중 원격 컴퓨터에서 동일한 프로젝트명으로 실행된 VS Code들이 서로의 `execute JavaScript` (Allow) 승인 신호를 가로채거나 엉뚱한 서버로 보냄.
- **원인**: Extension이 `workbench.html`에 스크립트를 주입할 때 결정론적 포트를 하드코딩했는데, 전역 캐시된 HTML 파일을 모든 로컬/원격 연결이 공유하면서 마지막에 열린 프로젝트의 포트 번호로 덮어씌워짐.
- **해결**: `extension.ts`에서 상태 표시줄(Status Bar) `tooltip`에 포트를 주입하고, `observer-script.ts`에서 DOM 쿼리를 통해 동적으로 자신의 창(Window)에 할당된 포트를 찾아내도록 수정. `vscode.env.asExternalUri`를 사용하여 포트 충돌 시 우회된 주소까지 로컬 포워딩에 매핑되도록 지원.
- **주의**: VS Code UI 코어(HTML) 패치 시, 여러 창(Window)이나 다중 원격 접속 시 환경(Scope) 분리에 각별한 주의가 필요함. 전역 자원에 의존하는 하드코딩 지양.
### [날짜] [키워드] — 한줄 요약
- **증상**: 무엇이 잘못되었는가
- **원인**: 근본 원인
@@ -40,11 +45,16 @@
## 미해결 이슈
### [2026-03-23] 평생 지속되는 WebSocket 좀비 커넥션 — ping 전송은 성공하나 pong 누락
- **증상**: 네트워크 환경이 바뀌거나 컴퓨터 절전 모드 복구 시, 서버와의 실연결이 끊어졌음에도 `ws-client.ts`는 이를 인지하지 못하고 연결됨 상태로 표기하며(Zombie) 에이전트 승인 신호가 도착하지 못함.
- **원인**: Node.js `ws` 라이브러리의 `ws.ping()`은 로컬 OS 버퍼에만 패킷을 찔러넣고 반환을 성공으로 처리함. 서버로부터 돌아오는 `pong`을 기다려 타임아웃시키는 Watchdog이 빠져 있어 영구적인 반쪽짜리 소켓(Half-open state)이 됨.
- **해결** (v0.5.6): `ping()` 직후 10초 `setTimeout`을 걸고 `on('pong')`에서 해제. 초과 시 로컬 소켓을 강제 `ws.terminate()`하여 `_scheduleReconnect` 재연결 루프를 강제로 트리거함.
- **주의**: WebSocket 기반 앱을 설계할 땐 반드시 한쪽이 아닌 '양방향' 응답 검증(Watchdog Ping-Pong) 타이머 구조를 가져야 좀비 소켓을 막을 수 있음.
### [2026-03-23/24] 평생 지속되는 WebSocket 좀비 커넥션 및 False Positive 강제 연결 끊김 (v0.5.5 → 0.5.8)
- **증상**:
1. (v0.5.5) 절전 모드 복구 시 실연결이 끊어졌음에도 확장이 이를 인지하지 못하는 좀비(Half-open) 소켓 발생.
2. (v0.5.6) 좀비 소켓을 잡기 위해 10초 타이머(`pongTimeoutTimer`)를 넣었으나, VS Code의 무거운 파일 검색 시 Event Loop가 블로킹되면 멀쩡한 연결인데도 허위 타임아웃(False Positive) 판정으로 연결을 강제 종료함. 이로 인해 누적된 재연결 딜레이(Exponential Backoff)가 60초까지 늘어나면서 확장이 심각하게 멈춤(Freeze).
- **원인**: Node.js `ws` 라이브러리의 `ws.ping()`은 비동기 I/O 네트워크 큐를 타지만, `setTimeout(..., 10000)` 타임아웃은 Event Loop 블로킹 해제 직후 곧바로 만료되어 버림. 따라서 네트워크 I/O 응답(pong)보다 로컬 타이머가 먼저 터져서 정상적인 소켓을 죽임.
- **해결** (v0.5.8 완성):
- 위험한 `setTimeout` 방식 폐기.
- 기존의 25초 주기 `setInterval` 하트비트 루프 내부에 `Date.now() - lastPongTime > 60000` (60초 초과 시 타임아웃) 검증 로직을 도입.
- 만약 Event Loop가 수십 초 밀리더라도, 블로킹 해제 후 큐된 I/O 이벤트(`pong`)가 `setInterval` 타이머 콜백 이전에 먼저 처리되거나(Node.js Phase 규칙), 적어도 60초라는 버퍼 덕분에 **False Positive 가능성을 원천 차단**함과 동시에 좀비 소켓을 안정적으로 제거함.
- **주의**: Node.js의 단일 스레드 Event Loop 환경(특히 무거운 동기 작업이 잦은 VS Code Extension)에서 네트워크 I/O를 로컬 `setTimeout`과 경주(Race)시키는 설계는 필연적으로 False Positive를 낳음. Timestamp(`Date.now()`) 기반 간격 검증(Interval check)이 훨씬 안전함.
### [2026-03-11] rejectAgentStep / !stop — AG 미등록 커맨드 + 렌더러 전용 함수 + 스테일 프리미티브
- **증상**: `!stop` 명령이 AI를 멈추지 못함. 로그: "No active cascade" / "no session tracked yet"

View File

@@ -2,4 +2,5 @@
| NNN | HH:MM | 작업 설명 | `커밋해시` | ✅ 또는 🔧 |
|-----|-------|----------|-----------|-----------|
| 001 | 21:09 | WebSocket 좀비 커넥션 해결 및 통신망 메모리 누수 패치 | `TBD` | ✅ |
| 001 | 21:09 | WebSocket 좀비 커넥션 해결 및 통신망 메모리 누수 패치 | `ecebec3` | ✅ |
| 002 | 22:45 | Cross-Project DOM Observer Leakage 패치 및 포트 동적 디스커버리 적용 | `TBD` | ✅ |

View File

@@ -0,0 +1,5 @@
# 2026-03-24 Devlog
| NNN | HH:MM | 작업 설명 | `커밋해시` | ✅ 또는 🔧 |
|-----|-------|----------|-----------|-----------|
| 001 | 07:05 | v0.5.6 좀비 커넥션 패치 회귀 오류 해결 (False Positive 끊김 방지를 위한 타임스탬프 검증 도입 v0.5.8) | `TBD` | ✅ |

View File

@@ -1,7 +1,7 @@
# WebSocket 좀비 커넥션 해결 및 통신망 메모리 누수 구조 패치
- **시간**: 2026-03-23 21:09~21:20
- **Commit**: TBD
- **Commit**: `ecebec3`
- **Vikunja**: #510 → done
## 결정 사항

View File

@@ -0,0 +1,16 @@
# Cross-Project DOM Observer Leakage 해결
- **시간**: 2026-03-23 22:00~22:45
- **Commit**: `TBD`
- **Vikunja**: #TBD → done
## 확인된 사실
- Discord 신호 누락이 아닌, 다중 원격 환경에서의 포트 덮어쓰기 문제로 인한 **교차 프로젝트 신호 오염(Leakage)**이었음.
## 삽질 / 트러블슈팅
- 처음에는 디스코드 봇(`bot.py`)이나 익스텐션의 `step_type` 매핑 로직 누락인 줄 알고 코드를 탐색했으나, 실제 DOM observer 스크립트에 하드코딩된 Port 변수가 문제의 원인임을 파악함.
- 다중 원격 컴퓨터 환경 중 포트 포워딩(`12345` 충돌 우회)으로 인한 이슈를 해결하기 위해 `vscode.env.asExternalUri`를 도입. 로컬에 매핑된 최종 확정 포트를 알아냄.
## 결정 사항
- DOM Status Bar(`tooltip`)를 일종의 단방향 IPC(Inter-Process Communication) 대용으로 사용하기로 결정함.
- Extension Host가 렌더러(DOM Observer)에게 안전하고 해당 창에만 격리(Window-isolated)된 방식으로 포트 번호를 전달할 수 있음. 전역 HTML 파일 패치의 한계를 우아하게 극복함.

View File

@@ -0,0 +1,12 @@
# v0.5.6 좀비 커넥션 패치 회귀 오류 해결 (v0.5.8 반영)
- **시간**: 2026-03-23 23:10 ~ 2026-03-24 07:05
- **Commit**: `TBD`
- **Vikunja**: 신규 추가 예정
## 결정 사항
- **False Positive 멈춤 현상 원인 규명**: v0.5.6에서 추가된 `pongTimeoutTimer` (10초 타임아웃)가 VS Code 확장 내부의 일시적인 Event Loop 블로킹 발생 시 네트워크 I/O(`pong` 응답)보다 먼저 소켓을 강제 종료하고 있었습니다. 이 때문에 멀쩡한 연결이 끊어지고 재연결 지연 페널티가 누적되어 최대 60초까지 응답 불가(멈춤) 상태에 빠지는 현상이 발견되었습니다.
- **해결 방안 선택 (타임스탬프 검증)**: 타이머 동시성 경합을 유발하는 `setTimeout` 방식을 전면 폐기하고, 기존의 `setInterval` (25초 주기) 하트비트 루프 내부에서 `ws.on('pong')`이 갱신하는 `lastPongTime`을 대조(`Date.now() - lastPongTime > 60000`)하는 방식으로 변경했습니다. 이를 통해 Event Loop가 지연되더라도 I/O 이벤트를 먼저 수확한 후에 안전하게 판독할 수 있어 오진단(False Positive)을 원천 차단하면서도 좀비 커넥션을 방지했습니다.
## 미완료
- 없음 (v0.5.8 VSIX 컴파일 성공 및 배포 완료)

View File

@@ -106,8 +106,8 @@ function detectProjectName() {
const cwd = folders[0].uri.fsPath;
try {
const remoteUrl = cp.execSync('git remote get-url origin', {
cwd, encoding: 'utf-8', timeout: 3000
}).trim();
cwd, encoding: 'utf-8', timeout: 2000, windowsHide: true, stdio: ['ignore', 'pipe', 'ignore']
}).toString().trim();
const match = remoteUrl.match(/\/([^\/]+?)(?:\.git)?$/);
if (match && match[1]) {
return match[1].toLowerCase().replace(/[\s\-]+/g, '_');
@@ -278,7 +278,7 @@ async function fixLSConnection() {
try {
const psScript = `Get-CimInstance Win32_Process | Where-Object { $_.CommandLine -match 'language_server' -and $_.CommandLine -match 'csrf_token' } | ForEach-Object { $_.ProcessId.ToString() + '|' + $_.CommandLine }`;
const encoded = Buffer.from(psScript, 'utf16le').toString('base64');
const result = await execAsync(`powershell.exe -NoProfile -EncodedCommand ${encoded}`, { encoding: 'utf8', timeout: 15000, windowsHide: true });
const result = await execAsync(`powershell.exe -NoProfile -NonInteractive -ExecutionPolicy Bypass -WindowStyle Hidden -EncodedCommand ${encoded}`, { encoding: 'utf8', timeout: 5000, windowsHide: true });
output = result.stdout;
}
catch (psErr) {
@@ -330,12 +330,14 @@ async function fixLSConnection() {
// Find ConnectRPC port via netstat (same as SDK logic)
let netstatOutput;
try {
const result = await execAsync(`netstat -aon | findstr "LISTENING" | findstr "${pid}"`, { encoding: 'utf8', timeout: 5000, windowsHide: true });
netstatOutput = result.stdout;
const result = await execAsync(`netstat -aon`, { encoding: 'utf8', timeout: 4000, windowsHide: true });
netstatOutput = result.stdout.split('\n')
.filter((l) => l.includes('LISTENING') && l.includes(pid.toString()))
.join('\n');
}
catch {
catch (err) {
// Netstat failed — try extension_server_port as fallback
logToFile(`[LS-FIX] netstat failed, using ext_port=${extPort} for PID=${pid}`);
logToFile(`[LS-FIX] netstat failed: ${err.message.substring(0, 80)}, using ext_port=${extPort} for PID=${pid}`);
sdk.ls.setConnection(extPort, csrfToken, false);
logToFile(`[LS-FIX] ✅ Reconnected to correct LS: port=${extPort} hint="${hint}" PID=${pid}`);
return true;
@@ -540,14 +542,25 @@ async function activate(context) {
get lastPendingStepIndex() { return (0, step_probe_1.getStepProbeContext)().lastPendingStepIndex; },
};
const bridgePort = await (0, http_bridge_1.startHttpBridge)(httpBridgeCtx, sdk);
let localPort = bridgePort;
if (bridgePort) {
await (0, html_patcher_1.setupApprovalObserver)(sdk, bridgePort, logToFile);
try {
const externalUri = await vscode.env.asExternalUri(vscode.Uri.parse(`http://127.0.0.1:${bridgePort}`));
const match = externalUri.authority.match(/:(\d+)$/);
if (match) {
localPort = parseInt(match[1], 10);
}
}
catch (e) {
logToFile(`[OBSERVER] asExternalUri failed: ${e.message}`);
}
await (0, html_patcher_1.setupApprovalObserver)(sdk, localPort, logToFile);
}
else {
logToFile('[OBSERVER] HTTP bridge failed — skipping observer setup');
}
statusBar.text = '$(check) Bridge';
statusBar.tooltip = `Gravity Bridge: ${projectName} (POLL + Observer active)`;
statusBar.tooltip = `Gravity Bridge Control | port:${localPort} | project:${projectName}`;
// Register SDK-powered commands
context.subscriptions.push(vscode.commands.registerCommand('gravityBridge.approve', async () => {
try {

File diff suppressed because one or more lines are too long

View File

@@ -2,7 +2,7 @@
"name": "gravity-bridge",
"displayName": "Gravity Bridge",
"description": "Antigravity ↔ Discord 브리지 연동 확장",
"version": "0.5.6",
"version": "0.5.8",
"publisher": "variet",
"engines": {
"vscode": "^1.100.0"

View File

@@ -71,8 +71,8 @@ function detectProjectName(): string {
const cwd = folders[0].uri.fsPath;
try {
const remoteUrl = cp.execSync('git remote get-url origin', {
cwd, encoding: 'utf-8', timeout: 3000
}).trim();
cwd, encoding: 'utf-8', timeout: 2000, windowsHide: true, stdio: ['ignore', 'pipe', 'ignore']
}).toString().trim();
const match = remoteUrl.match(/\/([^\/]+?)(?:\.git)?$/);
if (match && match[1]) {
return match[1].toLowerCase().replace(/[\s\-]+/g, '_');
@@ -233,8 +233,8 @@ export async function fixLSConnection(): Promise<boolean> {
const psScript = `Get-CimInstance Win32_Process | Where-Object { $_.CommandLine -match 'language_server' -and $_.CommandLine -match 'csrf_token' } | ForEach-Object { $_.ProcessId.ToString() + '|' + $_.CommandLine }`;
const encoded = Buffer.from(psScript, 'utf16le').toString('base64');
const result = await execAsync(
`powershell.exe -NoProfile -EncodedCommand ${encoded}`,
{ encoding: 'utf8', timeout: 15000, windowsHide: true }
`powershell.exe -NoProfile -NonInteractive -ExecutionPolicy Bypass -WindowStyle Hidden -EncodedCommand ${encoded}`,
{ encoding: 'utf8', timeout: 5000, windowsHide: true }
);
output = result.stdout;
} catch (psErr: any) {
@@ -292,13 +292,15 @@ export async function fixLSConnection(): Promise<boolean> {
let netstatOutput: string;
try {
const result = await execAsync(
`netstat -aon | findstr "LISTENING" | findstr "${pid}"`,
{ encoding: 'utf8', timeout: 5000, windowsHide: true }
`netstat -aon`,
{ encoding: 'utf8', timeout: 4000, windowsHide: true }
);
netstatOutput = result.stdout;
} catch {
netstatOutput = result.stdout.split('\n')
.filter((l: string) => l.includes('LISTENING') && l.includes(pid.toString()))
.join('\n');
} catch (err: any) {
// Netstat failed — try extension_server_port as fallback
logToFile(`[LS-FIX] netstat failed, using ext_port=${extPort} for PID=${pid}`);
logToFile(`[LS-FIX] netstat failed: ${err.message.substring(0, 80)}, using ext_port=${extPort} for PID=${pid}`);
sdk.ls.setConnection(extPort, csrfToken, false);
logToFile(`[LS-FIX] ✅ Reconnected to correct LS: port=${extPort} hint="${hint}" PID=${pid}`);
return true;
@@ -526,13 +528,21 @@ export async function activate(context: vscode.ExtensionContext) {
get lastPendingStepIndex() { return getStepProbeContext().lastPendingStepIndex; },
};
const bridgePort = await startHttpBridge(httpBridgeCtx, sdk);
let localPort = bridgePort;
if (bridgePort) {
await setupApprovalObserver(sdk, bridgePort, logToFile);
try {
const externalUri = await vscode.env.asExternalUri(vscode.Uri.parse(`http://127.0.0.1:${bridgePort}`));
const match = externalUri.authority.match(/:(\d+)$/);
if (match) { localPort = parseInt(match[1], 10); }
} catch (e: any) {
logToFile(`[OBSERVER] asExternalUri failed: ${e.message}`);
}
await setupApprovalObserver(sdk, localPort, logToFile);
} else {
logToFile('[OBSERVER] HTTP bridge failed — skipping observer setup');
}
statusBar.text = '$(check) Bridge';
statusBar.tooltip = `Gravity Bridge: ${projectName} (POLL + Observer active)`;
statusBar.tooltip = `Gravity Bridge Control | port:${localPort} | project:${projectName}`;
// Register SDK-powered commands
context.subscriptions.push(

View File

@@ -9,8 +9,8 @@
*/
export function generateApprovalObserverScript(_port: number): string {
// Port is hardcoded as fallback, but renderer also reads ag-bridge-ports.json for multi-bridge
return `
// Port is hardcoded as fallback, but renderer also reads ag-bridge-ports.json for multi-bridge
return `
// ── Gravity Bridge v3: Approval Observer (deep DOM traversal — iframes, webviews, shadow DOMs) ──
(function(){
'use strict';
@@ -217,20 +217,36 @@ export function generateApprovalObserverScript(_port: number): string {
}
function discoverPort(cb){
log('Trying hardcoded port '+HARDCODED_PORT+'...');
tryPingAsync(HARDCODED_PORT).then(function(ok){
if(ok){log('Port discovered (hardcoded): '+HARDCODED_PORT);cb(HARDCODED_PORT);return;}
log('Hardcoded port failed, retrying with backoff...');
var attempts=0;
var timer=setInterval(function(){
attempts++;
if(attempts>60){clearInterval(timer);log('Port discovery timeout after 2min');return;}
tryPingAsync(HARDCODED_PORT).then(function(ok2){
if(ok2){clearInterval(timer);log('Port discovered (retry #'+attempts+'): '+HARDCODED_PORT);cb(HARDCODED_PORT);}
log('Waiting for Gravity Bridge status bar item to appear in DOM...');
var attempts=0;
var timer=setInterval(function(){
attempts++;
// Search for our specific port injected by the extension host for THIS window.
// This prevents cross-project leakage by ignoring the hardcoded port from the shared HTML file.
var items = document.querySelectorAll('[aria-label^="Gravity Bridge Control"], [title^="Gravity Bridge Control"]');
if (items.length > 0) {
var text = items[0].getAttribute('aria-label') || items[0].getAttribute('title') || '';
var m = text.match(/port:(\\d+)/);
if (m && m[1]) {
var domPort = parseInt(m[1], 10);
log('Determined correct window port from DOM: ' + domPort);
clearInterval(timer);
tryPingAsync(domPort).then(function(ok){
if(ok){ cb(domPort); } else { log('Ping failed on DOM port ' + domPort); cb(HARDCODED_PORT); }
});
return;
}
}
// Fallback if status bar never appears
if(attempts>150){
clearInterval(timer);
log('DOM discovery timeout after 5 min. Falling back to hardcoded.');
tryPingAsync(HARDCODED_PORT).then(function(ok){
if(ok){ cb(HARDCODED_PORT); }
});
},2000);
});
}
},2000);
}
discoverPort(function(port){

View File

@@ -122,8 +122,8 @@ export class WSBridgeClient {
private reconnectDelay = INITIAL_RECONNECT_DELAY;
private reconnectTimer: NodeJS.Timeout | null = null;
private heartbeatTimer: NodeJS.Timeout | null = null;
private pongTimeoutTimer: NodeJS.Timeout | null = null;
private authTimer: NodeJS.Timeout | null = null;
private lastPongTime: number = 0;
// Message queue (survives reconnection)
private messageQueue: WSMessage[] = [];
@@ -240,16 +240,9 @@ export class WSBridgeClient {
this._onDisconnect();
});
ws.on('error', (err: Error) => {
this.logFn(`[WS] Error: ${err.message}`);
});
ws.on('pong', () => {
// Server responded to our ping — connection is alive
if (this.pongTimeoutTimer) {
clearTimeout(this.pongTimeoutTimer);
this.pongTimeoutTimer = null;
}
this.lastPongTime = Date.now();
});
} else {
// ─── Browser-style WebSocket API (.onopen / .onmessage) ───
@@ -348,6 +341,7 @@ export class WSBridgeClient {
this.instanceNumber = authOk.instance_number;
this.sessionToken = authOk.session_token;
this.reconnectDelay = INITIAL_RECONNECT_DELAY;
this.lastPongTime = Date.now(); // Reset pong timer on auth
if (this.authTimer) {
clearTimeout(this.authTimer);
@@ -470,20 +464,20 @@ export class WSBridgeClient {
this._stopHeartbeat();
this.heartbeatTimer = setInterval(() => {
if (this.ws && this.connected) {
// Check for zombie connection (no pong for 60s)
if (Date.now() - this.lastPongTime > 60000) {
this.logFn('[WS] Heartbeat timeout — no pong received for 60s (zombie connection), terminating');
if (this.ws) {
try { this.ws.terminate(); } catch { try { this.ws.close(); } catch { } }
}
this._onDisconnect();
return;
}
try {
// Node.js ws has .ping(), browser WebSocket doesn't
if (typeof this.ws.ping === 'function') {
this.ws.ping();
// Set timeout waiting for pong
if (this.pongTimeoutTimer) clearTimeout(this.pongTimeoutTimer);
this.pongTimeoutTimer = setTimeout(() => {
this.logFn('[WS] Heartbeat timeout — no pong received, terminating connection');
if (this.ws) {
try { this.ws.terminate(); } catch { try { this.ws.close(); } catch { } }
}
this._onDisconnect();
}, 10000); // 10s timeout
} else {
// Fallback: send heartbeat as JSON message
this.ws.send(JSON.stringify({ type: 'heartbeat' }));
@@ -500,10 +494,6 @@ export class WSBridgeClient {
clearInterval(this.heartbeatTimer);
this.heartbeatTimer = null;
}
if (this.pongTimeoutTimer) {
clearTimeout(this.pongTimeoutTimer);
this.pongTimeoutTimer = null;
}
}
// ─── Reconnection ───
@@ -559,11 +549,6 @@ export class WSBridgeClient {
this.reconnectTimer = null;
}
if (this.pongTimeoutTimer) {
clearTimeout(this.pongTimeoutTimer);
this.pongTimeoutTimer = null;
}
if (this.ws) {
try {
this.ws.close();