confluentinc / confluentinc/vscode

Extension activation can hang indefinitely locating a writeable tmp dir; misleading Sentry-init log noise on every production activation

Open
#3,416 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
TypeScript
Stars
34
Forks
17
Avg merge
1d 22h
Merged PRs (30d)
8

Description

## Summary

Two related flaws in the extension's startup/logging bootstrap (`src/extension.ts`,
`src/logging.ts`, `src/utils/file.ts`):

1. **No timeout when probing for a writeable tmp directory.** `WriteableTmpDir.determine()` is
awaited as the very first statement of `activate()`. Its per-directory write/delete probes have
no timeout, so a slow or hung filesystem call blocks the entire extension's activation
indefinitely — with no fallback.
2. **Misleading log noise on every production-build activation.** Sentry initialization runs before
`determine()` is awaited, and indirectly triggers a `Logger.debug()` call that hits
`WriteableTmpDir.get()` while `_tmpdir` is still unset, producing a scary but harmless
`"get() called before determine() was awaited."` console error on every single activation where
telemetry is enabled (i.e. every official release build).

## Observed symptoms

Reported in the field on v2.3.1 (macOS), with the extension host repeatedly going unresponsive and
restarting:

```
00:07:34 [error] Unexpected error during log file operations: Error: get() called before determine() was awaited.
...at confluentinc.vscode-confluent-2.3.1-darwin-x64/extension-AgQzEPwI.js...
00:07:42 [info] Extension host (LocalProcess pid: 80295) is unresponsive.
00:09:45 [warning] Attempted to report in-progress status for unknown chat session type 'claude-code'
00:09:47 [info] Started local extension host with pid 81851.
00:09:52 [error] Unexpected error during log file operations: Error: get() called before determine() was awaited. ← same bug again
```

Because all extensions in VS Code share a single extension host process, a hang during this
extension's activation can prevent other extensions (in this case, a chat extension) from finishing
their own activation before VS Code's heartbeat check restarts the host — and since activation runs
from scratch on every restart, the cycle can repeat indefinitely on an affected machine.

## Root cause analysis

### Flaw 1 — unbounded tmp-dir probing (`src/utils/file.ts:81-113`)

`WriteableTmpDir.determine()` tries up to 7 candidate directories in sequence:

```ts
for (const dir of possibleDirs) {
...
await writeFile(fileUri, Buffer.from("test"));
await deleteFile(fileUri);
...
}
```

`writeFile`/`deleteFile` route through `vscode.workspace.fs`, with no timeout anywhere in the loop.
`extension.ts:123` awaits this as the literal first statement of `activate()` — nothing else in the
extension runs until it resolves. If any candidate directory's write/delete round-trip stalls
(rather than failing fast with a permission error), the whole extension hangs forever.

The code already anticipates flaky filesystem behavior in this area (see the existing comment about
JamfAppInstallers on macOS at `utils/file.ts:79`), but doesn't defend against a _slow_ filesystem,
only an _unwriteable_ one. Enterprise-managed machines (MDM/Jamf policy enforcement, EDR/AV scanning
newly-created files, VPN- or network-mounted home directories) can intermittently stall plain file
I/O well past what's noticeable on an unmanaged local dev machine — enough to trip VS Code's
extension-host unresponsiveness detector.

### Flaw 2 — Sentry init logs before `determine()` resolves (`src/extension.ts:11-13`, `src/telemetry/sentryClient.ts:21-23`)

`initSentry()` is called at module-evaluation time, before `activate()` runs:

```ts
// extension.ts
if (process.env.SENTRY_DSN) {
initSentry();
}
```

Inside `initSentry()` → `getSentryScope()`, the first-ever call creates the scope and logs:

```ts
// sentryClient.ts
export function getSentryScope(): Scope {
if (!sentryScope) {
logger.debug("Creating new Sentry scope"); // <-- fires here, before determine() has run
sentryScope = new Scope();
}
return sentryScope;
}
```

That `logger.debug(...)` flows through `Logger.debug` → `EXTENSION_OUTPUT_CHANNEL.debug` →
`writeToLogFile` → `RotatingLogManager.getDir()` → `WriteableTmpDir.get()` (`logging.ts:131`), which
throws because `determine()` hasn't set `_tmpdir` yet. The throw is caught by `writeToLogFile`'s own
try/catch (`logging.ts:~235`) and surfaces as
`console.error("Unexpected error during log file operations:", error)` — exactly the log line
reported above.

This is **not conditional on anything failing** — it fires on every activation where `SENTRY_DSN` is
set, which is every official release build (see "Why this wasn't caught earlier" below). It's
swallowed and harmless on its own, but it was a significant red herring during triage: the message
implies a code-ordering bug ("called before X was awaited"), when the actual condition is a
startup-sequencing gap between Sentry init and the extension's own logging readiness.

### Secondary robustness gap — `cleanupOldLogFiles()` (`src/logging.ts:408-412`)

```ts
export function cleanupOldLogFiles() {
const logger = new Logger("logging.cleanup");
const logfileDir = WriteableTmpDir.getInstance().get(); // <-- no try/catch
...
```

Called from `extension.ts:363`, well after `determine()` has succeeded in the current control flow,
so not implicated in the reported symptom — but it calls `.get()` directly with no guard, which
would throw uncaught if a future refactor ever reordered activation.

## Why this wasn't caught in local testing or CI

- **Flaw 2 is dead code outside of official release builds.** `Gulpfile.js`'s `build()` only calls
`setupSentry()` (which populates `process.env.SENTRY_DSN` from Vault) when
`process.env.NODE_ENV === "production"`. None of `gulp build`, `gulp test`, `gulp e2e`, or
`gulp functional` set `NODE_ENV=production` — only the release packaging pipeline does. So
`initSentry()` never runs locally or in CI test suites, and the misleading log line is
structurally unreachable outside a real `.vsix` release build.
- **Flaw 1 requires a slow/hung filesystem, which local and CI machines don't have.** Local dev
machines and CI runners have fast, local, unmanaged tmp directories — `determine()`'s probes
complete in milliseconds. The hang needs the kind of managed/virtualized storage (MDM policy
enforcement, EDR/AV file-scan interception, network-mounted home directory) more likely to be
present on a corporate-managed laptop, and even there the stall appears to be intermittent rather
than constant (explaining the flaky/non-deterministic reproduction).
- **Unit tests stub filesystem interactions**, per project convention, so the real singleton timing
across a full `activate()` sequence is never exercised end-to-end by the existing test suite.

## Suggested fixes

1. **Add a timeout to `WriteableTmpDir.determine()`'s per-directory probe** (`utils/file.ts:97-101`)
— wrap the `writeFile`/`deleteFile` pair in a bounded timeout (e.g. `Promise.race` against a 1-2s
cap) so one bad candidate can't block activation indefinitely; treat a timeout the same as any
other per-directory failure and move on to the next candidate.
2. **Fix the Sentry/logging bootstrap ordering** so `initSentry()`'s first `getSentryScope()` call
can't fire a log write before `determine()` resolves. Two options:
- Move the `initSentry()` call in `extension.ts` to after
`await WriteableTmpDir.getInstance().determine()`, or
- Make `WriteableTmpDir.get()` fail soft (e.g. return `undefined` and have callers skip the file
write) rather than throw when called before `determine()`, since an early call during Sentry
bootstrap is an expected occurrence, not a genuine "should never happen" condition.
3. **Guard `cleanupOldLogFiles()`'s direct `.get()` call** (`logging.ts:412`) defensively, so a
future activation-order refactor can't reintroduce an uncaught throw here.

## Suggested test coverage

- Unit test: `WriteableTmpDir.determine()` completes (recording an error for that candidate, not
hanging) when a candidate directory's write call never resolves.
- Unit test: pin `WriteableTmpDir.get()`'s behavior before `determine()` has run vs. after it
resolves with no writeable directory found — these are currently conflated under one error
message.
- Regression test: with `SENTRY_DSN` set, activating the extension should not produce a
`"get() called before determine() was awaited"` console error — this is the case that would have
caught flaw 2 before it shipped.

## Relationships

Target: implement as a patch on top of the `v2.3.x` release branch, ship as the next patch release,
then forward-port (cherry-pick or merge) into `main`.

Contributor guide

Open the contributing guide

Research direction

Start with src/extension.ts and trace activation order, then read src/utils/file.ts, src/logging.ts, and src/telemetry/sentryClient.ts at the locations described. Run the existing unit tests and add coverage for a never-resolving filesystem probe, pre-determination get behavior, and SENTRY_DSN activation. Done means activation remains bounded and production startup no longer emits the misleading get() error.

Written by the indexing model from the issue text.

Assessment

Tech stack
typescript
Domain
devtools, tooling
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Clearly specified
Newbie friendliness
48/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.