From bf02ab2752c9e4b3f8b6fb4c48cd4b676f9083b3 Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 18:11:51 -0400 Subject: [PATCH 1/7] Show failures and degraded states in the editor Before this change, almost every failure or degraded state of Dexter went only to the log. An editor writes that log to a file that the user does not read, so the language server looked broken. For example, an index written by a newer build was rebuilt for minutes, and the editor showed nothing. Add internal/notify, the one reporting path. A Reporter lives on the shared IndexCoordinator, so the embedded server, the daemon's headless service, and every editor session use the same one. It logs each report as before and sends it to every attached editor: - Conditions (Set/Clear) are window/showMessage: Error when Dexter does not work, Warning when it works with less. A condition that stops says so. - Long work (cold build, rebuild, large incremental pass) is work-done progress when the client supports it, with messages as the fallback. - An editor that attaches later receives the active conditions and the work in progress. Sessions attach in initialized and detach on close. - Delivery never blocks: each editor has its own queue. Report through it: an index from another index version, a damaged index that is rebuilt, an index that another process holds locked or that cannot be opened for another cause, an index without its SQL indexes, a fast build that fell back to the slow path, files that could not be indexed (one aggregate message, which also ends when their directory is removed), a root that is the home directory or not a project (now checked by the daemon), native watching unavailable, the fsnotify fallback, directories that cannot be watched and their recovery, a workspace with no stdlib (read from the shared root), a formatter that cannot run or an OTP mismatch (for each Mix project; syntax errors in user code are excluded), and a rename that could not change some files. A session with no mix and a failed rename are told to that editor only. The first build of an empty index is told once for each workspace. When `dexter lsp` cannot attach to a daemon, it now reads the initialize request, sends window/showMessage with the explanation and the fix, answers initialize with JSON-RPC error -32603, and exits. lookup, references, and reindex results carry the active index conditions with their keys, and the CLI prints them on stderr. workspace/status lists all conditions. Fix two causes of lost or duplicated index work: - openStore deleted the index for any open error, also for "database is locked". A `dexter init` or an older release that held the index in a rollback-journal transaction then lost its work in silence. Now only a damaged index (SQLITE_CORRUPT, SQLITE_NOTADB) is deleted. A locked index is waited for up to 30 seconds and then fails the daemon start with a message; permission, disk-space, and similar errors keep the index. - On macOS the workspace identity kept the case that the caller typed, so two spellings of one directory got two locks and two daemons. The identity now uses the case that the file system stores (F_GETPATH), so the second spelling gets the root-mismatch message. Reports are made only on state changes. The walk and the watchers pay one atomic load for each changed file when no file has failed, and a save pays one more atomic load to see that the set of failed files did not change. Co-Authored-By: Claude Opus 5.5 --- AGENTS.md | 1 + CHANGELOG.md | 8 + cmd/main.go | 106 ++-- cmd/main_test.go | 64 +++ docs/architecture.md | 40 +- docs/daemon.md | 25 +- internal/daemon/client.go | 31 +- internal/daemon/endpoint.go | 9 +- internal/daemon/identity_darwin.go | 39 ++ internal/daemon/identity_other.go | 7 + internal/daemon/lsp_failure.go | 264 ++++++++++ internal/daemon/report_test.go | 390 +++++++++++++++ internal/daemon/server.go | 57 ++- internal/indexer/indexer.go | 9 + internal/lsp/formatter.go | 25 +- internal/lsp/report.go | 360 ++++++++++++++ internal/lsp/report_test.go | 404 ++++++++++++++++ internal/lsp/server.go | 163 ++++--- internal/lsptest/client.go | 48 +- internal/notify/notify.go | 504 ++++++++++++++++++++ internal/notify/notify_test.go | 200 ++++++++ internal/notify/notifytest/client.go | 163 +++++++ internal/store/openerr.go | 40 ++ internal/store/project.go | 49 ++ internal/workspace/report.go | 132 +++++ internal/workspace/report_test.go | 422 ++++++++++++++++ internal/workspace/runtime.go | 133 +++++- internal/workspace/watch.go | 18 + internal/workspace/watch_fsnotify.go | 7 + internal/workspace/watch_platform_darwin.go | 6 +- lsp_integration_test.go | 23 +- 31 files changed, 3560 insertions(+), 187 deletions(-) create mode 100644 internal/daemon/identity_darwin.go create mode 100644 internal/daemon/identity_other.go create mode 100644 internal/daemon/lsp_failure.go create mode 100644 internal/daemon/report_test.go create mode 100644 internal/lsp/report.go create mode 100644 internal/lsp/report_test.go create mode 100644 internal/notify/notify.go create mode 100644 internal/notify/notify_test.go create mode 100644 internal/notify/notifytest/client.go create mode 100644 internal/store/openerr.go create mode 100644 internal/store/project.go create mode 100644 internal/workspace/report.go create mode 100644 internal/workspace/report_test.go diff --git a/AGENTS.md b/AGENTS.md index 4bf5d1f..a8d68d3 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -55,6 +55,7 @@ a store that has no rows. | Any new store query | Add an index if the query will run on hot paths (definition, hover, references) | | `internal/beam` ETF tag handling | The ERTS external term format spec. One wrong field width desynchronises every later term in the chunk (`EXPORT_EXT` carries its arity as an integer term, `NEW_FUN_EXT` as a raw byte) | | `internal/workspace/runtime.go` (mutation queue, readiness, subscribers) | `internal/lsp` write coordination (`IndexCoordinator`), `watch.go` event filtering, failed-watch retries and one-shot coverage reconciliation, `workspace/watch` subscribers, and the `Close` ordering: watchers stop before the queue drains, and the queue drains before the store checkpoints | +| A new failure or degraded state | Report it through the workspace `notify.Reporter` (`IndexCoordinator.Reporter()`): a condition key with `Set`, and `Clear` with a message when it stops. A log line alone is not seen in an editor. Report only on state changes, never per file or per request. See "Telling the user" in `docs/architecture.md` | | `internal/daemon` (protocol, registries, endpoint) | `ContractVersion`, the reserved method and kind names in `registry.go`, `client.go` multiplexing (one reader, ids matched to callers, notifications interleaved), and `docs/daemon.md`. Socket paths must stay short: `sockaddr_un` is capped near 104 bytes | ## Token walking diff --git a/CHANGELOG.md b/CHANGELOG.md index b69b5a6..901d384 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ - **Go-to-definition reaches the line that declared a generated function** — a function a macro generated used to resolve to the top of its module. Dexter now reads the line from the compiled module's debug info, which is standard compiler output, so no framework is special-cased. A generator that expands each function at the line of the call that declared it, or stamps it with `@file {file, line}`, sends definition, call hierarchy, the references declaration, and `dexter lookup` (including `--strict`) to that line. The line is used only when it was compiled from the file being opened; a BEAM older than the source still gives its line, because Dexter cannot compile the project and the last compile's line is closer than the module line; only edits to the declaring file move it, and the next compile makes it exact. A function whose only recorded line is the module line, such as one a `@before_compile` hook made, goes to the call in its module that declares it by name. When several calls spell the name, as an Ash action and the code interface that runs it do, the macro whose calls name the most of the module's generated functions wins, and a tie keeps the module line. A function with a clause per DSL call goes to every clause. A line past the end of the file is never returned. A module compiled without debug info falls back to its Docs chunk annotation, which is often, but not always, the same line. A generated module with no source of its own, such as one `Module.create` made or a Spark DSL entity, goes to the file it was compiled from, rebased onto the project when it was built elsewhere, and so does go-to-definition on its name. A module a macro made with `defmodule` and a name it computed records no line of its own, so its name goes to its first function's line. A bare call to a generated function of an imported module now resolves. Ash code interfaces go to their `define` line with released Ash, and from the recorded line with an Ash release that includes [ash-project/ash#2971](https://github.com/ash-project/ash/pull/2971) ([#108](https://github.com/remoteoss/dexter/issues/108)) +- **Failures and degraded states are shown in the editor** — before, almost every problem went only to the log, so the editor showed a language server that did nothing. Now each condition that stops Dexter from working, or makes it work with less, is a `window/showMessage` in every attached editor: an index written by a newer or older Dexter build, a damaged index that is being rebuilt, an index that another process holds locked or that cannot be opened for another cause, an index that cannot be used, a fast build that fell back to the slow path, files that could not be indexed (one aggregate message), a root that is the home directory or not a project, file watching that is unavailable or does not cover some directories, FSEvents falling back to fsnotify, a workspace with no Elixir standard library, a session with no `mix` (told to that editor only), a Mix project whose formatter cannot run (each project on its own), and a rename that could not change some files. Each message says what happened, what Dexter does about it, and what to do. Conditions that stop say so, and an editor that attaches later receives the conditions that are still active. Cold builds, rebuilds, and large incremental passes show LSP work-done progress where the editor supports it. `lookup`, `references`, and `reindex` state a rebuilding or unusable index on stderr, and `workspace/status` lists every active condition + +- **`dexter lsp` explains why it cannot start** — when the proxy cannot reach a daemon (a daemon from another build, a different spelling of the root, a workspace held by `dexter init`, or a daemon that does not start), it answers the editor's `initialize` request with an error and a `window/showMessage` that carry the full explanation and the fix, instead of printing to stderr and exiting + - **`--root`/`-C` names the workspace on every command** — `dexter init --root ~/project`, `dexter lookup --root ~/project MyApp.Repo`, and `dexter lsp --root ~/project` all run as if they had been started in that directory, so an agent, a script, or an editor wrapper can index or query a project from anywhere. Relative paths, a `reindex` target included, resolve from the named root - **Watching and runtime locations recover without periodic reindexes** — a directory the kernel refuses to watch (an inotify watch limit on a large tree) is tracked instead of disabling the whole native watcher. Dexter reconciles once when coverage is lost, retries only failed registrations, and reconciles once when coverage returns; it does not run recurring full-tree passes that cause CPU spikes. Runtime files use the environment-independent `/tmp/dexter-` directory so a GUI editor and a shell cannot derive different ownership locks. Elixir and mix detection also searches the standard mise, asdf, and Homebrew locations and falls back to a login shell, so an editor that starts the daemon with a stripped PATH no longer disables stdlib indexing or formatting @@ -32,6 +36,10 @@ - **Compressed BEAM files are read** — a module compiled with the `compressed` option, as some Erlang dependencies are, is a gzip stream around the BEAM container. Dexter rejected it as an invalid BEAM, so its exports were missing from completion and generated-function navigation. It is now decompressed, with the same size limit as an uncompressed file +- **A locked index was deleted under the process that held it** — when the index did not open, the daemon deleted and rebuilt it for any error, including `database is locked`. A `dexter init` or an older release that wrote it with a rollback journal then committed into a deleted file and lost its work in silence. Dexter now deletes the index only when it is damaged. It waits up to 30 seconds for a lock and then fails with a message in the editor, and it keeps the index for permission, disk-space, and similar errors, which a rebuild does not fix + +- **Two spellings of one directory got two daemons on macOS** — the default macOS file system ignores case, but the workspace identity kept the case the caller typed, so `~/Code/app` and `~/code/app` got two locks and two daemons that built one index at the same time. The identity now uses the case the file system stores, so the second spelling reaches the first daemon and the editor shows the root-mismatch message + - **Git worktrees nested inside a project were indexed as part of it** — a linked worktree checked out below the project root (Claude Code's `.claude/worktrees/`, or any gitignored worktree folder) is a full copy of the repository, so every go-to-definition returned one result per checkout. The indexer, the incremental sweep, the native watcher and single-file updates now skip any directory that is a linked worktree, including worktrees of bare repositories; submodules and Mix git dependencies stay indexed. Adding, changing, moving or removing such a worktree, including its `mix.exs` and `mix.lock`, no longer reindexes the enclosing project, and an existing index drops the worktree's files at the next start. A worktree that git still records stays skipped after its `.git` file is gone, as during `git worktree remove`, until `git worktree prune`. Starting Dexter inside such a worktree no longer climbs to the enclosing checkout's `.dexter/dexter.db` either: the worktree is its own project - **Branch switches were missed when the project root is a linked worktree or a submodule** — the HEAD poller read `/.git/HEAD`, but in such a checkout `.git` is a file that names the git directory. The poller now follows that file, so a branch switch reconciles the index even when the native file watcher is unavailable - **Find references through an injected alias was slow and memory-hungry on large projects** — a module such as `MyApp.Repo`, aliased by a `__using__` block that most of the project uses, made every references query read and tokenize each file that used the injector: about 20,000 files and 2.4 GB of allocations per query on a large monorepo. Only files that contain a candidate reference are read now, which brought that query from 1–2 s to under 0.3 s and its allocations to about 70 MB diff --git a/cmd/main.go b/cmd/main.go index ce8da11..4fe4629 100644 --- a/cmd/main.go +++ b/cmd/main.go @@ -14,6 +14,7 @@ import ( "github.com/remoteoss/dexter/internal/daemon" "github.com/remoteoss/dexter/internal/indexer" + "github.com/remoteoss/dexter/internal/lsp" "github.com/remoteoss/dexter/internal/stdlib" "github.com/remoteoss/dexter/internal/store" "github.com/remoteoss/dexter/internal/version" @@ -247,7 +248,7 @@ func findProjectRootWithMissing(path string, allowMissing bool) string { path = filepath.Dir(path) } root := store.FindProjectRoot(path, "mix.exs") - if home, homeErr := os.UserHomeDir(); homeErr == nil && sameDir(root, home) { + if home, homeErr := os.UserHomeDir(); homeErr == nil && store.SameDir(root, home) { if mixRoot := findMarkerBefore(path, "mix.exs", home); mixRoot != "" { return mixRoot } @@ -256,7 +257,7 @@ func findProjectRootWithMissing(path string, allowMissing bool) string { } func findMarkerBefore(path, marker, stop string) string { - for dir := path; !sameDir(dir, stop); dir = filepath.Dir(dir) { + for dir := path; !store.SameDir(dir, stop); dir = filepath.Dir(dir) { if info, err := os.Stat(filepath.Join(dir, marker)); err == nil && info.Mode().IsRegular() { return dir } @@ -268,31 +269,6 @@ func findMarkerBefore(path, marker, stop string) string { return "" } -// projectMarkers are the cheap signals that a directory is, or carries, a -// Dexter workspace. They match what store.FindProjectRoot trusts, and an -// a Dexter marker means an actual database, not an empty directory left by an -// interrupted operation. -func looksLikeProjectRoot(dir string) bool { - return regularFile(filepath.Join(dir, "mix.exs")) || - gitMarker(filepath.Join(dir, ".git")) || - regularFile(store.DBPath(dir)) || - regularFile(store.LegacyDBPath(dir)) -} - -func hasDexterMarker(dir string) bool { - return regularFile(store.DBPath(dir)) || regularFile(store.LegacyDBPath(dir)) -} - -func regularFile(path string) bool { - info, err := os.Stat(path) - return err == nil && info.Mode().IsRegular() -} - -func gitMarker(path string) bool { - info, err := os.Stat(path) - return err == nil && (info.IsDir() || info.Mode().IsRegular()) -} - // requireProjectRoot refuses to treat a directory that shows no sign of being // an Elixir project as a workspace. A mistyped directory is far more likely // than the intent to index one: a `dexter lookup` in the home directory would @@ -303,49 +279,18 @@ func requireProjectRoot(dir string, allowNonProject bool) { if allowNonProject { return } - if home, err := os.UserHomeDir(); err == nil && sameDir(dir, home) { - if hasDexterMarker(dir) { + if store.IsHomeDir(dir) { + if store.HasIndex(dir) { return } fatal(fmt.Errorf("refusing to use %s as a workspace: it is your home directory, not a project\nhint: run from a project, pass --root , or pass -y/--yes if you really mean it", dir)) } - if looksLikeProjectRoot(dir) { + if store.LooksLikeProject(dir) { return } fatal(fmt.Errorf("refusing to use %s as a workspace: no mix.exs, .git, or Dexter database found, so it does not look like an Elixir project\nhint: run from a project, pass --root , or pass -y/--yes to index it anyway", dir)) } -// warnProjectRoot is the LSP's version of the same check. An editor, unlike a -// shell command, is authoritative about what the user opened, and refusing to -// start would leave them with no language server and only a log line to -// explain it — so this warns loudly and serves the directory anyway. The warning -// is written to stderr, which every LSP client keeps in its server log. -func warnProjectRoot(dir string) { - if home, err := os.UserHomeDir(); err == nil && sameDir(dir, home) { - if hasDexterMarker(dir) { - return - } - log.Printf("Warning: %s is your home directory, not a project; indexing it because the editor asked. Set --root in the editor's dexter command if that is wrong.", dir) - return - } - if looksLikeProjectRoot(dir) { - return - } - log.Printf("Warning: %s does not look like an Elixir project (no mix.exs, .git, or Dexter database); indexing it because the editor asked. Set --root if that is the wrong directory.", dir) -} - -// sameDir reports whether two paths name the same directory. Stat is the -// authority so a symlinked spelling (or a case-insensitive filesystem) cannot -// sneak a home directory past the check. -func sameDir(a, b string) bool { - ai, aErr := os.Stat(a) - bi, bErr := os.Stat(b) - if aErr != nil || bErr != nil { - return filepath.Clean(a) == filepath.Clean(b) - } - return os.SameFile(ai, bi) -} - // defaultIdleTimeout resolves the daemon idle timeout. DEXTER_DAEMON_IDLE_TIMEOUT // overrides the built-in default for every daemon this machine spawns, including // ones an editor starts, so it can be set once in a shell profile. @@ -457,6 +402,7 @@ func cmdReindex(target string, allowNonProject bool) { if err := client.Call(callCtx, daemon.MethodReindex, daemon.ReindexParams{Target: target}, &result); err != nil { fatal(err) } + printIndexNotes(result.Notes, queryOptions{}) switch { case result.Missing: fmt.Fprintf(os.Stderr, "Nothing to reindex at %s: it does not exist and nothing is indexed there\n", target) @@ -484,8 +430,9 @@ func cmdLookup(projectRoot string, module string, function string, strict bool, }, &result); err != nil { fatal(err) } + printIndexNotes(result.Notes, opts) if len(result.Locations) == 0 { - warnIfIndexBuilding(result.Ready, opts) + warnIfIndexBuilding(result.Ready, result.Notes, opts) if strict { os.Exit(1) } @@ -511,8 +458,9 @@ func cmdReferences(projectRoot string, module string, function string, opts quer }, &result); err != nil { fatal(err) } + printIndexNotes(result.Notes, opts) if len(result.Locations) == 0 { - warnIfIndexBuilding(result.Ready, opts) + warnIfIndexBuilding(result.Ready, result.Notes, opts) fmt.Fprintf(os.Stderr, "No references found for %s", module) if function != "" { fmt.Fprintf(os.Stderr, ".%s", function) @@ -667,9 +615,13 @@ func cmdStopIncompatible(ctx context.Context, root string, e *daemon.Incompatibl // the index, watchers, and language caches are shared with every other // frontend. The daemon starts on demand: it belongs to the workspace, not to // this editor, the CLI, or any other frontend that happens to reach it first. +// +// The daemon checks the root and tells the editor when it does not look like a +// project. When the proxy cannot attach at all, ProxyLSP has already told the +// editor why, as the answer to its initialize request; fatal only repeats it on +// stderr for the editor's log. func cmdLSP(projectRoot string) { projectRoot = findProjectRoot(projectRoot) - warnProjectRoot(projectRoot) log.SetOutput(os.Stderr) log.Printf("Dexter LSP proxy v%s starting (root: %s, daemon log: %s)", version.Version, projectRoot, daemonLogPath(projectRoot)) if err := daemon.ProxyLSP(context.Background(), projectRoot, os.Stdin, os.Stdout); err != nil { @@ -716,13 +668,37 @@ func (o queryOptions) waitReadyMs() int { // control protocol never see it: every response carries `ready`, which is the // programmatic way to make the same decision, and the daemon logs any request // that actually blocked on the build. -func warnIfIndexBuilding(ready bool, opts queryOptions) { +func warnIfIndexBuilding(ready bool, notes []daemon.Note, opts queryOptions) { if ready || opts.quiet || envFlag("DEXTER_QUIET") { return } + for _, note := range notes { + switch note.Key { + case lsp.CondIndexRebuild, lsp.CondIndexUnavailable, lsp.CondIndexFallback: + return // printIndexNotes already said why the index is incomplete + } + } fmt.Fprintln(os.Stderr, "note: the workspace index is still building; re-run shortly for complete results") } +// printIndexNotes states on stderr that the index is being rebuilt or cannot +// be used, the same conditions an editor shows, so that an incomplete answer is +// not taken as complete. An error is printed even with --quiet: the answer is +// wrong without it. Info notes are left out; warnIfIndexBuilding covers a +// first build. +func printIndexNotes(notes []daemon.Note, opts queryOptions) { + quiet := opts.quiet || envFlag("DEXTER_QUIET") + for _, note := range notes { + message := strings.TrimPrefix(note.Message, "Dexter: ") + switch { + case note.Severity == "error": + fmt.Fprintf(os.Stderr, "error: %s\n", message) + case note.Severity == "warning" && !quiet: + fmt.Fprintf(os.Stderr, "note: %s\n", message) + } + } +} + func formatInt(n int) string { s := fmt.Sprintf("%d", n) if len(s) <= 3 { diff --git a/cmd/main_test.go b/cmd/main_test.go index 6955a43..84dea2d 100644 --- a/cmd/main_test.go +++ b/cmd/main_test.go @@ -2,11 +2,14 @@ package main import ( "context" + "io" "os" "path/filepath" "strings" "testing" "time" + + "github.com/remoteoss/dexter/internal/daemon" ) func TestWaitForDaemonStopBoundsProbe(t *testing.T) { @@ -59,3 +62,64 @@ func TestFindProjectRootWithMissingStartsFromExistingAncestor(t *testing.T) { t.Errorf("root outside a project = %s, want %s", got, want) } } + +// captureStderr runs fn with os.Stderr sent to a pipe and returns what it +// wrote. +func captureStderr(t *testing.T, fn func()) string { + t.Helper() + r, w, err := os.Pipe() + if err != nil { + t.Fatal(err) + } + saved := os.Stderr + os.Stderr = w + defer func() { os.Stderr = saved }() + fn() + _ = w.Close() + out, err := io.ReadAll(r) + if err != nil { + t.Fatal(err) + } + return string(out) +} + +// A rebuilding or unusable index is stated on the CLI, so that an answer from +// it is not taken as complete. --quiet hides the warning, never the error. +func TestIndexNotesAreStatedOnStderr(t *testing.T) { + t.Setenv("DEXTER_QUIET", "") + notes := []daemon.Note{ + {Key: "index.build", Severity: "info", Message: "Dexter: building the index for the first time"}, + {Key: "index.rebuild", Severity: "warning", Message: "Dexter: the index was written by a newer Dexter build. Rebuilding it now."}, + {Key: "index.unavailable", Severity: "error", Message: "Dexter: the index could not be completed."}, + } + got := captureStderr(t, func() { + printIndexNotes(notes, queryOptions{}) + warnIfIndexBuilding(false, notes, queryOptions{}) + }) + want := "note: the index was written by a newer Dexter build. Rebuilding it now.\nerror: the index could not be completed.\n" + if got != want { + t.Errorf("stderr =\n%q\nwant\n%q", got, want) + } + quiet := captureStderr(t, func() { printIndexNotes(notes, queryOptions{quiet: true}) }) + if quiet != "error: the index could not be completed.\n" { + t.Errorf("quiet stderr = %q", quiet) + } + building := captureStderr(t, func() { warnIfIndexBuilding(false, notes[:1], queryOptions{}) }) + if !strings.Contains(building, "still building") { + t.Errorf("a first build is not stated: %q", building) + } +} + +// A file that could not be indexed during the first build does not say that +// the build is still running, so it must not hide the note that does. +func TestFileFailureDoesNotHideTheBuildingNote(t *testing.T) { + t.Setenv("DEXTER_QUIET", "") + notes := []daemon.Note{ + {Key: "index.build", Severity: "info", Message: "Dexter: building the index for the first time"}, + {Key: "index.files", Severity: "warning", Message: "Dexter: 1 file could not be indexed: /p/lib/a.ex"}, + } + got := captureStderr(t, func() { warnIfIndexBuilding(false, notes, queryOptions{}) }) + if !strings.Contains(got, "still building") { + t.Errorf("the building note is hidden: %q", got) + } +} diff --git a/docs/architecture.md b/docs/architecture.md index 780b385..57910fb 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -12,6 +12,7 @@ Dexter is a fast Elixir LSP server. It indexes module and function definitions f - `internal/lsp/` — LSP server. `server.go` handles all LSP methods. `elixir.go` contains pure functions for cursor expression extraction, alias/import/use extraction (tokenizer-based), and use-chain parsing. `rename.go` has rename helpers. `hover.go` has hover formatting. `documents.go` is an in-memory open-buffer store. - `internal/workspace/` — the protocol-independent owner of one workspace: the store, the shared `lsp.IndexCoordinator`, the headless language-service instance, stdlib discovery, the native and Git watchers, and the single mutation queue every index change enters. `runtime.go` is the lifecycle and the queue; `watch.go` defines the recursive watcher abstraction, with an FSEvents backend on macOS and an fsnotify backend elsewhere or as fallback. - `internal/daemon/` — the per-workspace daemon and its local transport: endpoint and lock derivation (`endpoint.go`), handshake and framing (`protocol.go`), connection handling and the built-in control methods (`server.go`), the client and the stdio proxies (`client.go`), the adapter registries (`registry.go`), and the per-platform ownership lock. `docs/daemon.md` has the ownership, lifecycle, and extension contract. +- `internal/notify/` — the one path that tells the user about failures, degraded states, and long work. A `Reporter` logs each report and sends it to every attached editor as `window/showMessage` or work-done progress, and keeps the active conditions so it can replay them to an editor that attaches later. `notifytest` has a fake client that records what an editor would show. - `internal/treesitter/` — Tree-sitter integration for scope-aware variable rename and go-to-references. @@ -218,6 +219,41 @@ Consequences that are easy to undo by accident: The largest remaining win is interning `file_path`: every ref row stores a ~122-character absolute path, but there are only ~69k distinct paths, so the column and `idx_refs_file_path` together account for well over half the database. +## Telling the user + +A language server that fails silently looks broken: an editor writes the server's stderr to a log file that nobody reads. So every condition that stops Dexter from working, or makes it work with less, goes through `notify.Reporter`, which logs it as before and also shows it in the editor. + +- **One reporter for each workspace.** It lives on the `lsp.IndexCoordinator`, like the store, so the daemon's headless service (which runs the index builds) and every editor session share it. A session attaches its client in `initialized`, not in `initialize`, because a server must not send `window/workDoneProgress/create` before the initialize response. It detaches when the session closes. +- **Conditions, not events.** `Set(key, severity, message)` makes a condition active: Error when Dexter does not work, Warning when it works with less, Info for a normal state change such as a first build. Setting an active key again with the same severity only updates its text, so a count that changes does not send a message each time. `Clear(key, message)` says that the condition stopped. `Notify` is for an event that does not continue. +- **Replay on attach.** The daemon serves several editors. An editor that attaches while a rebuild runs, or while the watcher is degraded, receives the active conditions in the order they started, and the work in progress as a new progress begin. +- **Progress for long work.** A cold build and a rebuild show work-done progress where the client capability `window.workDoneProgress` allows it; their start and end are also conditions, so a client without progress support still sees them. An incremental pass shows progress only after 1,000 changed files, with a message at the start and the end as the fallback. +- **Aggregate, never per file.** Files that cannot be read, parsed, or written go into one set on the coordinator; the user sees one message ("3 files could not be indexed: and 2 more") and one more when the set is empty again. Recording a success costs one atomic load when no file has failed, so the walk and the watchers pay nothing in the usual case. +- **Delivery never blocks.** Each attached editor has its own queue and goroutine. A slow editor loses progress reports first, and nothing on a request path or in the mutation loop waits for an editor. +- **A frontend that cannot start still speaks LSP.** When `dexter lsp` cannot reach a daemon (a contract mismatch in either direction, a root spelling mismatch, a workspace held by `dexter init`, a daemon that does not start), it reads the editor's `initialize` request, sends `window/showMessage` with the explanation and the fix, answers `initialize` with a JSON-RPC error (-32603) that carries the same text, and exits. +- **The CLI states the index too.** `lookup`, `references`, and `reindex` results carry the active index conditions (`notes`), and the CLI prints a warning as `note:` and an error as `error:` on stderr. `--quiet` hides warnings, never errors. `workspace/status` returns every active condition. + +What is reported, and what stays in the log only: + +| Condition | Key | Severity | Clears with a message | +|---|---|---|---| +| First build of an empty index (once for each workspace: an index with no Elixir files stays empty, and each full pass over it would be "cold") | `index.build` | Info, with progress | yes ("index built") | +| Index written by another index version, or damaged (`SQLITE_CORRUPT`, `SQLITE_NOTADB`): deleted and rebuilt | `index.rebuild` | Warning, with progress | yes ("rebuild is complete") | +| Index locked by another process (`SQLITE_BUSY`, `SQLITE_LOCKED`): never deleted; the daemon waits up to 30 s, then fails to start, and the editor shows the end of the daemon log | `index.unavailable` | Error | yes, when the lock goes during the wait | +| Index that cannot be opened for another cause (permissions, full disk, open-file limit): not deleted, because a rebuild does not fix it | `index.unavailable` | Error | no (the daemon does not start) | +| Bulk build left the index without its SQL indexes | `index.unavailable` | Error | no (restart needed) | +| Fast full build failed, so files are indexed one by one | `index.fallback` | Warning | through the build end message | +| Files that could not be indexed | `index.files` | Warning | yes | +| Root is the home directory, or does not look like a project | `root` | Warning | no | +| Native file watching cannot start | `watcher` | Warning | yes | +| macOS FSEvents unavailable, so fsnotify runs | `watcher.fallback` | Warning | no | +| Directories that cannot be watched | `watcher.coverage` | Warning | yes | +| The workspace has no Elixir standard library (read from the root that all sessions share, not from what one session found) | `stdlib` | Warning | yes | +| `mix` not found for one session | (this editor only) | Warning | — | +| `mix format` cannot run, or Elixir/OTP mismatch, in one Mix project | `formatter:`, `formatter.otp:` | Warning, Error | yes ("formatting works again in ") | +| A rename that could not change some files | (this editor only) | Error | — | + +A syntax error in the user's code is not a formatter failure: it is a diagnostic. WAL checkpoint warnings, fsnotify transient errors, the per-directory watch errors (they are in the aggregate), BEAM formatter restarts that fall back to `mix format`, and requests that waited for the first build stay in the log. + ## Key design decisions - **Tokenizer instead of tree-sitter for indexing** — a hand-rolled tokenizer + walker replaced the original regex-based parser for both file indexing and runtime `__using__` parsing. The tokenizer handles heredocs, sigils, multi-line expressions, and comments as opaque tokens, eliminating fragile line-joining heuristics. Tree-sitter is only used for scope-aware variable operations in files already opened by the editor. @@ -228,10 +264,10 @@ The largest remaining win is interning `file_path`: every ref row stores a ~122- - **Emptiness is decided under the lock, never sampled.** `Server.fullBuild` tests `IsEmpty` while holding the write lock and reports through its `ran` return value, because one save arriving between a sample and the lock invalidates the answer. `Store.IsEmpty` answers `false` when its own query fails, so a database too broken to count is never taken for an empty one. - **The sweep's prune re-checks the filesystem.** `pruneMissingFiles` deletes only stored paths that are absent from the walk *and* fail to stat. The walk is one traversal, so a file saved after it passed that directory is legitimately missing from `seen`; the stat is also what stops a walker that yields nothing from deleting the whole index. - **A cold build is one WAL transaction**, so the `-wal` file grows to roughly the size of the index — a few hundred MiB on a large monorepo — until the post-build checkpoint reclaims it. `wal_autocheckpoint` cannot touch frames belonging to an open transaction, and `InProcess` deliberately leaves `journal_mode` alone, so the server cannot avoid this the way `dexter init` does. -- **A failed cold build must not stamp the index version.** `SetIndexVersion` runs last, so any failure leaves a version the next start rejects. That is the whole recovery path: the workspace runtime's `openStore` sees the mismatch on a populated index, drops the derived index, and reopens — in the one process holding the ownership lock, so there are no live readers and nothing else can be writing. `indexer.ErrUnindexed` — indexes not recreated after the load committed or rolled back — marks writes unavailable for the rest of the live process and must never fall back to the full incremental sweep, whose `DELETE` by `file_id` would scan the full `definitions` and `refs` tables once per file on disk. +- **A failed cold build must not stamp the index version.** `SetIndexVersion` runs last, so any failure leaves a version the next start rejects. That is the whole recovery path: the workspace runtime's `openStore` sees the mismatch on a populated index, drops the derived index, and reopens — in the one process holding the ownership lock, so there are no live readers and nothing else can be writing. An index that does not open is deleted only when `store.ClassifyOpenError` says that it is damaged. A locked index is never deleted: `dexter init` and older releases write it with a rollback journal, and deleting the files under such a writer loses its work in silence. `indexer.ErrUnindexed` — indexes not recreated after the load committed or rolled back — marks writes unavailable for the rest of the live process and must never fall back to the full incremental sweep, whose `DELETE` by `file_id` would scan the full `definitions` and `refs` tables once per file on disk. - **Delegate following** — `defdelegate` targets are resolved at index time (including alias resolution and `as:` renames). `LookupFollowDelegate` follows chains recursively (up to 5 hops) so `A → B → C` resolves to `C`. - **Git HEAD polling** — watches `.git/HEAD` mtime every 2 seconds to detect branch switches and trigger reindex. The workspace runtime owns this poll; a daemon-backed LSP session does not start its own. - **Full document sync** — `TextDocumentSyncKindFull`; Elixir files are small enough that incremental sync adds complexity without benefit. -- **One workspace, one owner** — a per-workspace daemon holds an advisory kernel lock (`flock`, `LockFileEx`) for its lifetime and is the only process that opens the index or watches the tree. The kernel releases the lock when the process dies, so a crash leaves no stale lock and no PID file to reconcile; the lock file may outlive the process and is never unlinked, because unlinking a lock another process holds would admit a second writer. Identity — the symlink-resolved root — decides which daemon owns the physical workspace, while the indexed root keeps the starter's spelling so stored paths still match the URIs an editor sends. A frontend using another spelling is rejected during the handshake. +- **One workspace, one owner** — a per-workspace daemon holds an advisory kernel lock (`flock`, `LockFileEx`) for its lifetime and is the only process that opens the index or watches the tree. The kernel releases the lock when the process dies, so a crash leaves no stale lock and no PID file to reconcile; the lock file may outlive the process and is never unlinked, because unlinking a lock another process holds would admit a second writer. Identity — the symlink-resolved root, in the case the file system stores it (macOS `F_GETPATH`) — decides which daemon owns the physical workspace, while the indexed root keeps the starter's spelling so stored paths still match the URIs an editor sends. A frontend using another spelling is rejected during the handshake. - **Frontends are thin** — an editor connection is a raw byte proxy after a one-line handshake, so the daemon hop costs a copy rather than a JSON parse, and a CLI call is one multiplexed control request. Protocol adapters register (`daemon.RegisterFrontend`, `daemon.RegisterMethod`) instead of editing dispatch, and reach workspace state through `workspace.Runtime` rather than opening a store, starting a watcher, or running a second LSP lifecycle. - **Index versioning** — `IndexVersion` in `internal/version/version.go`. A mismatch on startup triggers a forced rebuild *of a populated index*; an empty one has no stale data to discard, so the live server builds it in the background through `indexer.FullBuild` instead. Bump when parser or schema changes would invalidate existing indexes. diff --git a/docs/daemon.md b/docs/daemon.md index 597d442..7078503 100644 --- a/docs/daemon.md +++ b/docs/daemon.md @@ -55,7 +55,11 @@ another process holds would let a second daemon take ownership of the same index Every connection starts with a small versioned handshake carrying the workspace *identity*, the connection kind, and the frontend's `ContractVersion`. Identity is the symlink-resolved root, and it decides which daemon owns the physical -workspace. The root the daemon *indexes* keeps the spelling its starter used, +workspace. On macOS it also takes the case that the file system stores +(`F_GETPATH`), because the default file system ignores case and +`filepath.EvalSymlinks` keeps the case the caller typed: without it, +`~/Code/app` and `~/code/app` would get two locks and two daemons that build +one index at the same time. The root the daemon *indexes* keeps the spelling its starter used, because stored paths are matched against the URIs an editor sends: canonicalizing them would break every path-keyed lookup for a project reached through a symlink (on macOS a temp dir is `/var/...` to the editor and `/private/var/...` after @@ -88,7 +92,10 @@ sending each path once: ``` `file` indexes `files`, and the locations keep their result order. `kind`, -`arity`, and `declaration` are omitted when empty, zero, or false. +`arity`, and `declaration` are omitted when empty, zero, or false. A result +from an index that is being rebuilt or cannot be used also carries +`"notes":[{"severity":"warning","message":"..."}]`, the same text an editor +shows; the field is omitted when no index condition is active. ## The restart contract @@ -114,6 +121,14 @@ On a mismatch the newer side wins, and the daemon does the moving: - With nobody to notice, the idle timeout is the fallback: the daemon exits on its own and the next frontend starts the current build. +A `dexter lsp` proxy that cannot attach for any of these reasons, or for any +other startup error, does not only print to stderr: it reads the editor's +`initialize` request, sends `window/showMessage` (Error) with the explanation +and the fix, answers `initialize` with JSON-RPC error -32603 that carries the +same text, and exits. An editor that is older than the daemon is told to +restart from the current binary; a daemon that cannot be replaced, a root +spelling mismatch, and a workspace held by `dexter init` get their own fix. + ## Ownership and crash recovery The daemon holds an advisory OS lock (`flock`, `LockFileEx`) on a deterministic @@ -211,6 +226,10 @@ once when coverage is lost, retries only failed registrations, and reconciles after each restored subtree to catch changes made during its gap. Failure to create the native watcher is retried the same way. There is no periodic full-tree reindex, so a persistent kernel watch limit does not cause recurring CPU spikes. +Each of these states (no native watching, the fsnotify fallback, directories +that cannot be watched) is a condition in the workspace reporter: every attached +editor sees it, an editor that attaches later receives it, and the user is told +when coverage comes back. See "Telling the user" in `docs/architecture.md`. ## Lifecycle @@ -265,7 +284,7 @@ Built-in control surface: |---|---| | `daemon/status` | pid, version, protocol, readiness, client count, uptime, registered frontends | | `daemon/shutdown` | exit when no other client is attached; refuse otherwise | -| `workspace/status` | readiness, watcher state, stdlib root, index version and size, attached sessions; `waitReadyMs` turns it into an index barrier | +| `workspace/status` | readiness, watcher state, stdlib root, index version and size, attached sessions, active failure and degraded conditions; `waitReadyMs` turns it into an index barrier | | `workspace/lookup` | module/function lookup with the CLI's non-strict module fallback | | `workspace/references` | semantic references through the shared language service | | `workspace/reindex` | whole workspace or one path, returning after the barrier | diff --git a/internal/daemon/client.go b/internal/daemon/client.go index ac278ec..50933b1 100644 --- a/internal/daemon/client.go +++ b/internal/daemon/client.go @@ -796,9 +796,16 @@ func spawn(root string) error { return nil } -// ProxyLSP connects stdio to a daemon-hosted LSP session. +// ProxyLSP connects stdio to a daemon-hosted LSP session. When the session +// cannot start, the editor must not see only a process that exits: ProxyLSP +// answers its initialize request with the explanation and returns an +// *LSPStartupError. func ProxyLSP(ctx context.Context, root string, in io.Reader, out io.Writer) error { - return ProxyFrontend(ctx, root, kindLSP, "", in, out) + conn, reader, err := connectFrontend(ctx, root, kindLSP, "") + if err != nil { + return failLSPStartup(ctx, root, err, in, out) + } + return pipeFrontend(conn, reader, in, out) } // ProxyFrontend connects stdio to a daemon-hosted protocol adapter without @@ -806,19 +813,35 @@ func ProxyLSP(ctx context.Context, root string, in io.Reader, out io.Writer) err // a copy rather than a parse. session names an editor session the adapter should // share overlays with; empty means headless. func ProxyFrontend(ctx context.Context, root, kind, session string, in io.Reader, out io.Writer) error { + conn, reader, err := connectFrontend(ctx, root, kind, session) + if err != nil { + return err + } + return pipeFrontend(conn, reader, in, out) +} + +// connectFrontend starts the daemon when necessary and opens one frontend +// stream to it. +func connectFrontend(ctx context.Context, root, kind, session string) (net.Conn, *bufio.Reader, error) { // A control connection starts the daemon and verifies it is accepting. // Closing it before opening the frontend stream is safe because the // daemon's idle timeout is not zero. client, err := Ensure(ctx, root) if err != nil { - return err + return nil, nil, err } _ = client.Close() conn, reader, _, err := dialKind(ctx, root, kind, session) if err != nil { - return err + return nil, nil, err } + return conn, reader, nil +} + +// pipeFrontend copies bytes both ways until the daemon side ends, and closes +// the connection. +func pipeFrontend(conn net.Conn, reader *bufio.Reader, in io.Reader, out io.Writer) error { defer func() { _ = conn.Close() }() type closeWriter interface{ CloseWrite() error } diff --git a/internal/daemon/endpoint.go b/internal/daemon/endpoint.go index f5bdb68..7234094 100644 --- a/internal/daemon/endpoint.go +++ b/internal/daemon/endpoint.go @@ -33,9 +33,10 @@ type Endpoint struct { // for a project reached through one: on macOS a temp dir is /var/... to the // editor and /private/var/... after EvalSymlinks. Root string - // Identity is the symlink-resolved path. It decides which daemon owns the - // physical workspace; the handshake then rejects a different Root spelling - // because path-keyed answers cannot safely mix aliases. + // Identity is the symlink-resolved path, in the case the file system + // stores it. It decides which daemon owns the physical workspace; the + // handshake then rejects a different Root spelling because path-keyed + // answers cannot safely mix aliases. Identity string Socket string Lock string @@ -52,7 +53,7 @@ func ResolveEndpoint(root string) (Endpoint, error) { } identity := abs if resolved, err := filepath.EvalSymlinks(abs); err == nil { - identity = resolved + identity = diskSpelling(resolved) } digest := sha256.Sum256([]byte(identity)) key := hex.EncodeToString(digest[:16]) diff --git a/internal/daemon/identity_darwin.go b/internal/daemon/identity_darwin.go new file mode 100644 index 0000000..1765ac6 --- /dev/null +++ b/internal/daemon/identity_darwin.go @@ -0,0 +1,39 @@ +//go:build darwin + +package daemon + +import ( + "strings" + "syscall" + "unsafe" + + "golang.org/x/sys/unix" +) + +// diskSpelling returns path as the file system stores it. The default macOS +// file system ignores case, and filepath.EvalSymlinks keeps the case the +// caller typed, so ~/Code/app and ~/code/app would get two identities, two +// locks, and two daemons that build one index at the same time. F_GETPATH +// returns the stored spelling. The result is used only when it differs from +// path in case alone, so a firmlink or another alias cannot move an existing +// workspace to a new lock. +func diskSpelling(path string) string { + fd, err := unix.Open(path, unix.O_RDONLY|unix.O_NONBLOCK|unix.O_CLOEXEC, 0) + if err != nil { + return path + } + defer func() { _ = unix.Close(fd) }() + buf := make([]byte, unix.PathMax) + if _, _, errno := syscall.Syscall(syscall.SYS_FCNTL, uintptr(fd), uintptr(unix.F_GETPATH), uintptr(unsafe.Pointer(&buf[0]))); errno != 0 { + return path + } + n := 0 + for n < len(buf) && buf[n] != 0 { + n++ + } + stored := string(buf[:n]) + if stored != path && strings.EqualFold(stored, path) { + return stored + } + return path +} diff --git a/internal/daemon/identity_other.go b/internal/daemon/identity_other.go new file mode 100644 index 0000000..7994110 --- /dev/null +++ b/internal/daemon/identity_other.go @@ -0,0 +1,7 @@ +//go:build !darwin + +package daemon + +// diskSpelling returns path unchanged. Linux file systems are case-sensitive +// in normal use, and Windows identities go through the same path. +func diskSpelling(path string) string { return path } diff --git a/internal/daemon/lsp_failure.go b/internal/daemon/lsp_failure.go new file mode 100644 index 0000000..ce2f225 --- /dev/null +++ b/internal/daemon/lsp_failure.go @@ -0,0 +1,264 @@ +package daemon + +import ( + "bufio" + "bytes" + "context" + "encoding/json" + "errors" + "fmt" + "io" + "os" + "strconv" + "strings" + "time" + + "github.com/remoteoss/dexter/internal/version" +) + +// startupFailureWait bounds how long a proxy that cannot serve waits for the +// editor's initialize request. An editor sends it at once; the bound only keeps +// a proxy that nobody talks to from staying alive. +var startupFailureWait = 10 * time.Second + +// lspInternalError is the JSON-RPC code of the initialize error. The LSP has no +// code for "this server cannot start", and InternalError is what editors show +// as a server failure. +const lspInternalError = -32603 + +// LSPStartupError is a failure to serve an editor. The editor already received +// Message, as the answer to its initialize request and as an error message, so +// the caller only has to exit. +type LSPStartupError struct { + Message string + Err error +} + +func (e *LSPStartupError) Error() string { return e.Message } +func (e *LSPStartupError) Unwrap() error { return e.Err } + +// ExplainStartupFailure turns a failure to reach the workspace daemon into a +// message for the user: what happened, and what to do about it. +func ExplainStartupFailure(root string, err error) string { + var incompatible *IncompatibleDaemonError + var mismatch *RootMismatchError + var message string + switch { + case errors.As(err, &incompatible) && !incompatible.ClientNewer: + message = fmt.Sprintf( + "Dexter cannot start for %s: this editor started an older Dexter build (%s, daemon contract %d) than the daemon that serves the project (contract %d). Restart this editor so that it starts the current dexter binary; check which dexter the PATH of the editor finds.", + root, version.Version, ContractVersion, incompatible.DaemonContract) + case errors.As(err, &incompatible): + pid := "its process" + if incompatible.DaemonPID > 0 { + pid = fmt.Sprintf("pid %d", incompatible.DaemonPID) + } + message = fmt.Sprintf( + "Dexter cannot start for %s: an older Dexter daemon (%s, contract %d) serves the project and could not be replaced (%v). Run `dexter stop --force` in the project directory, then restart this editor.", + root, pid, incompatible.DaemonContract, err) + case errors.As(err, &mismatch): + message = fmt.Sprintf( + "Dexter cannot start for %s: a Dexter daemon already serves this project as %s, and one project cannot be served through two path spellings. Open the project as %s, or run `dexter stop --force` in %s and restart this editor.", + mismatch.Requested, mismatch.Daemon, mismatch.Daemon, mismatch.Daemon) + default: + message = fmt.Sprintf("Dexter cannot start for %s: %v.", root, err) + if strings.Contains(err.Error(), "not serving its daemon socket") { + message += " Wait until it finishes, then restart this editor. If no `dexter init` runs, `dexter stop --force` in the project directory stops the process that holds the project." + } else { + message += " Restart this editor to try again; if it fails again, `dexter stop --force` in the project directory stops a daemon that does not answer." + } + if tail := daemonLogTail(root, 3); tail != "" { + message += " Last lines of the daemon log: " + tail + } + } + if endpoint, epErr := ResolveEndpoint(root); epErr == nil { + message += fmt.Sprintf(" (daemon log: %s)", endpoint.Log) + } + return message +} + +// daemonLogTail returns the last lines of the daemon log, joined on one line, +// or "" when there is no log. It reads at most the last 4 KiB. +func daemonLogTail(root string, lines int) string { + endpoint, err := ResolveEndpoint(root) + if err != nil { + return "" + } + f, err := os.Open(endpoint.Log) + if err != nil { + return "" + } + defer func() { _ = f.Close() }() + const window = 4 << 10 + info, err := f.Stat() + if err != nil { + return "" + } + offset := info.Size() - window + if offset < 0 { + offset = 0 + } + buf := make([]byte, info.Size()-offset) + if _, err := f.ReadAt(buf, offset); err != nil && !errors.Is(err, io.EOF) { + return "" + } + var kept []string + for _, line := range strings.Split(string(buf), "\n") { + if line = strings.TrimSpace(line); line != "" { + kept = append(kept, line) + } + } + if offset > 0 && len(kept) > 0 { + kept = kept[1:] // the first line can be cut + } + if len(kept) > lines { + kept = kept[len(kept)-lines:] + } + return strings.Join(kept, " | ") +} + +// serveStartupFailure speaks enough LSP to make the editor show why Dexter +// cannot serve it. It reads messages until the initialize request, sends +// window/showMessage with the explanation, answers initialize with an error +// that carries the same text, and returns. Any other request before that gets +// the same error. It also returns on `exit`, at the end of the input, and +// after wait. +func serveStartupFailure(in io.Reader, out io.Writer, message string, wait time.Duration) error { + type frame struct { + body []byte + err error + } + frames := make(chan frame) + stop := make(chan struct{}) + defer close(stop) + go func() { + r := bufio.NewReader(in) + for { + body, err := readLSPFrame(r) + select { + case frames <- frame{body: body, err: err}: + case <-stop: + return + } + if err != nil { + return + } + } + }() + + timeout := time.NewTimer(wait) + defer timeout.Stop() + for { + var f frame + select { + case f = <-frames: + case <-timeout.C: + return errors.New("the editor sent no initialize request") + } + if f.err != nil { + if errors.Is(f.err, io.EOF) { + return nil + } + return f.err + } + var msg struct { + ID json.RawMessage `json:"id"` + Method string `json:"method"` + } + if err := json.Unmarshal(f.body, &msg); err != nil { + continue + } + hasID := len(msg.ID) > 0 && !bytes.Equal(msg.ID, []byte("null")) + switch { + case msg.Method == "exit": + return nil + case msg.Method == "initialize" && hasID: + if err := writeLSPFrame(out, map[string]any{ + "jsonrpc": "2.0", + "method": "window/showMessage", + "params": map[string]any{"type": 1, "message": message}, + }); err != nil { + return err + } + return writeLSPFrame(out, map[string]any{ + "jsonrpc": "2.0", + "id": msg.ID, + "error": map[string]any{ + "code": lspInternalError, + "message": message, + "data": map[string]any{"retry": false}, + }, + }) + case hasID: + if err := writeLSPFrame(out, map[string]any{ + "jsonrpc": "2.0", + "id": msg.ID, + "error": map[string]any{"code": lspInternalError, "message": message}, + }); err != nil { + return err + } + } + } +} + +// maxStartupFrame bounds one message read by serveStartupFailure. An +// initialize request is a few KiB. +const maxStartupFrame = 16 << 20 + +func readLSPFrame(r *bufio.Reader) ([]byte, error) { + length := -1 + for { + line, err := r.ReadString('\n') + if err != nil { + if errors.Is(err, io.EOF) && line == "" { + return nil, io.EOF + } + return nil, err + } + line = strings.TrimRight(line, "\r\n") + if line == "" { + break + } + name, value, ok := strings.Cut(line, ":") + if ok && strings.EqualFold(strings.TrimSpace(name), "Content-Length") { + n, err := strconv.Atoi(strings.TrimSpace(value)) + if err != nil { + return nil, fmt.Errorf("bad Content-Length %q", value) + } + length = n + } + } + if length < 0 || length > maxStartupFrame { + return nil, fmt.Errorf("bad LSP message length %d", length) + } + body := make([]byte, length) + if _, err := io.ReadFull(r, body); err != nil { + return nil, err + } + return body, nil +} + +func writeLSPFrame(w io.Writer, message any) error { + body, err := json.Marshal(message) + if err != nil { + return err + } + if _, err := fmt.Fprintf(w, "Content-Length: %d\r\n\r\n", len(body)); err != nil { + return err + } + _, err = w.Write(body) + return err +} + +// failLSPStartup tells the editor why Dexter cannot serve it and returns the +// error for the caller to exit with. +func failLSPStartup(ctx context.Context, root string, err error, in io.Reader, out io.Writer) error { + if ctx.Err() != nil { + return err + } + message := ExplainStartupFailure(root, err) + if serveErr := serveStartupFailure(in, out, message, startupFailureWait); serveErr != nil { + err = errors.Join(err, fmt.Errorf("telling the editor: %w", serveErr)) + } + return &LSPStartupError{Message: message, Err: err} +} diff --git a/internal/daemon/report_test.go b/internal/daemon/report_test.go new file mode 100644 index 0000000..f79b88d --- /dev/null +++ b/internal/daemon/report_test.go @@ -0,0 +1,390 @@ +package daemon + +import ( + "bufio" + "bytes" + "context" + "errors" + "fmt" + "io" + "net" + "os" + "path/filepath" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/remoteoss/dexter/internal/parser" + "github.com/remoteoss/dexter/internal/store" + "github.com/remoteoss/dexter/internal/version" + "github.com/remoteoss/dexter/internal/workspace" +) + +// heldServer is pipeServer for a workspace held before its first +// reconciliation until release runs. +func heldServer(t *testing.T, root string) (*server, Endpoint, func()) { + t.Helper() + ownership, endpoint, err := AcquireOwnership(root) + if err != nil { + t.Fatal(err) + } + hold := make(chan struct{}) + var released atomic.Bool + release := func() { + if released.CompareAndSwap(false, true) { + close(hold) + } + } + rt, err := workspace.OpenWithOptions(root, workspace.Options{NoWatch: true, BeforeInitialReconcile: func() { <-hold }}) + if err != nil { + _ = ownership.Release() + t.Fatal(err) + } + s := &server{ + root: endpoint.Root, + identity: endpoint.Identity, + runtime: rt, + idleTimeout: time.Minute, + started: time.Now(), + activity: make(chan struct{}, 1), + stopping: make(chan struct{}), + connections: make(map[net.Conn]struct{}), + } + s.ctx, s.cancelCtx = context.WithCancel(context.Background()) + t.Cleanup(func() { + release() + s.cancelCtx() + _ = rt.Close() + _ = ownership.Release() + }) + return s, endpoint, release +} + +// editor is one LSP session over a pipe that keeps every message it reads. +type editor struct { + t *testing.T + conn net.Conn + reader *bufio.Reader + seen []map[string]any +} + +func attachEditor(t *testing.T, s *server, endpoint Endpoint, root string) *editor { + t.Helper() + conn, reader, res := pipeDial(t, s, endpoint, kindLSP, "") + if !res.OK { + t.Fatalf("LSP handshake refused: %s", res.Error) + } + e := &editor{t: t, conn: conn, reader: reader} + writeLSP(t, conn, map[string]any{ + "jsonrpc": "2.0", "id": 1, "method": "initialize", + "params": map[string]any{"processId": nil, "rootUri": "file://" + root, "capabilities": map[string]any{}}, + }) + e.until("initialize response", func(m map[string]any) bool { + id, ok := idAsInt(m["id"]) + return ok && id == 1 && m["method"] == nil + }) + writeLSP(t, conn, map[string]any{"jsonrpc": "2.0", "method": "initialized", "params": map[string]any{}}) + return e +} + +// until reads messages until match accepts one. Requests from the server are +// answered with null, as an editor would. +func (e *editor) until(what string, match func(map[string]any) bool) map[string]any { + e.t.Helper() + for _, m := range e.seen { + if match(m) { + return m + } + } + _ = e.conn.SetReadDeadline(time.Now().Add(20 * time.Second)) + defer func() { _ = e.conn.SetReadDeadline(time.Time{}) }() + for { + m := readLSP(e.t, e.reader) + e.seen = append(e.seen, m) + method, _ := m["method"].(string) + if rawID, hasID := m["id"]; hasID && method != "" { + writeLSP(e.t, e.conn, map[string]any{"jsonrpc": "2.0", "id": rawID, "result": nil}) + } + if match(m) { + return m + } + if len(e.seen) > 200 { + e.t.Fatalf("no %s in %d messages", what, len(e.seen)) + } + } +} + +func (e *editor) message(typ float64, text string) string { + e.t.Helper() + m := e.until(fmt.Sprintf("showMessage containing %q", text), func(m map[string]any) bool { + if m["method"] != "window/showMessage" { + return false + } + params, _ := m["params"].(map[string]any) + message, _ := params["message"].(string) + return params["type"] == typ && strings.Contains(message, text) + }) + params := m["params"].(map[string]any) + return params["message"].(string) +} + +// One daemon serves several editors. An editor that attaches while a rebuild +// is in progress must learn about it, like the editor that was there first, +// and both must learn when it ends. +func TestEditorAttachingDuringRebuildIsTold(t *testing.T) { + quietEnv(t) + root := t.TempDir() + path := writeModule(t, root, "lib/one.ex", "SharedLib.One") + st, err := store.Open(root) + if err != nil { + t.Fatal(err) + } + defs, refs, err := parser.ParseFile(path) + if err != nil { + t.Fatal(err) + } + if err := st.IndexFileWithRefs(path, defs, refs); err != nil { + t.Fatal(err) + } + if err := st.SetIndexVersion(version.IndexVersion + 1); err != nil { + t.Fatal(err) + } + if err := st.Close(); err != nil { + t.Fatal(err) + } + + s, endpoint, release := heldServer(t, root) + first := attachEditor(t, s, endpoint, root) + first.message(2, "the index was written by a newer Dexter build") + second := attachEditor(t, s, endpoint, root) + second.message(2, "the index was written by a newer Dexter build") + + // The CLI is told too, with the same text. + control := pipeClient(t, s, endpoint) + var result LookupResult + if err := control.Call(context.Background(), MethodLookup, LookupParams{Module: "SharedLib.One"}, &result); err != nil { + t.Fatal(err) + } + if result.Ready || len(result.Notes) != 1 || result.Notes[0].Severity != "warning" || + !strings.Contains(result.Notes[0].Message, "newer Dexter build") { + t.Fatalf("lookup during the rebuild: ready=%v notes=%+v", result.Ready, result.Notes) + } + + release() + for _, e := range []*editor{first, second} { + e.message(3, "the index rebuild is complete") + } + if err := control.Call(context.Background(), MethodLookup, LookupParams{Module: "SharedLib.One", WaitReadyMs: 30_000}, &result); err != nil { + t.Fatal(err) + } + if len(result.Notes) != 0 { + t.Fatalf("notes after the rebuild: %+v", result.Notes) + } +} + +// lspRequest frames one request the way an editor writes it. +func lspRequest(t *testing.T, id int, method string) []byte { + t.Helper() + var buf bytes.Buffer + writeLSP(t, &buf, map[string]any{"jsonrpc": "2.0", "id": id, "method": method, "params": map[string]any{}}) + return buf.Bytes() +} + +// startupFailureOutput returns the messages a failed proxy wrote. +func startupFailureOutput(t *testing.T, out []byte) []map[string]any { + t.Helper() + r := bufio.NewReader(bytes.NewReader(out)) + var messages []map[string]any + for { + if _, err := r.Peek(1); errors.Is(err, io.EOF) { + return messages + } + messages = append(messages, readLSP(t, r)) + } +} + +func assertStartupFailureAnswer(t *testing.T, out []byte, wantText string) { + t.Helper() + messages := startupFailureOutput(t, out) + if len(messages) != 2 { + t.Fatalf("got %d messages, want showMessage then the initialize error: %v", len(messages), messages) + } + show := messages[0] + params, _ := show["params"].(map[string]any) + if show["method"] != "window/showMessage" || params["type"] != float64(1) || !strings.Contains(params["message"].(string), wantText) { + t.Fatalf("first message is not an error showMessage with %q: %v", wantText, show) + } + answer := messages[1] + if id, ok := idAsInt(answer["id"]); !ok || id != 1 { + t.Fatalf("answer is not for the initialize request: %v", answer) + } + rpcErr, _ := answer["error"].(map[string]any) + if rpcErr["code"] != float64(lspInternalError) || rpcErr["message"] != params["message"] { + t.Fatalf("initialize error = %v, want code %d and the shown message", rpcErr, lspInternalError) + } +} + +// When the proxy cannot reach a daemon, the editor must show why. Exiting with +// a line on stderr leaves the user with a language server that does nothing. +func TestProxyAnswersInitializeWhenTheWorkspaceIsHeld(t *testing.T) { + quietEnv(t) + root := t.TempDir() + ownership, _, err := AcquireOwnership(root) + if err != nil { + t.Fatal(err) + } + defer func() { _ = ownership.Release() }() + + var out bytes.Buffer + in := bytes.NewReader(lspRequest(t, 1, "initialize")) + err = ProxyLSP(context.Background(), root, in, &out) + var startup *LSPStartupError + if !errors.As(err, &startup) { + t.Fatalf("ProxyLSP error = %v, want *LSPStartupError", err) + } + assertStartupFailureAnswer(t, out.Bytes(), "not serving its daemon socket") + if !strings.Contains(startup.Message, "Wait until it finishes, then restart this editor") { + t.Errorf("message does not say what to do: %q", startup.Message) + } +} + +func TestProxyAnswersInitializeWhenTheDaemonCannotStart(t *testing.T) { + quietEnv(t) + root := t.TempDir() + origSpawn := spawnDaemon + spawnDaemon = func(string) error { return errors.New("start workspace daemon: exec format error") } + t.Cleanup(func() { spawnDaemon = origSpawn }) + + var out bytes.Buffer + // An editor can send a request of its own first; it gets the error too. + in := io.MultiReader(bytes.NewReader(lspRequest(t, 7, "workspace/symbol")), bytes.NewReader(lspRequest(t, 1, "initialize"))) + err := ProxyLSP(context.Background(), root, in, &out) + if err == nil { + t.Fatal("ProxyLSP succeeded without a daemon") + } + messages := startupFailureOutput(t, out.Bytes()) + if len(messages) != 3 { + t.Fatalf("got %d messages, want 3: %v", len(messages), messages) + } + if id, _ := idAsInt(messages[0]["id"]); id != 7 || messages[0]["error"] == nil { + t.Fatalf("the early request got no error: %v", messages[0]) + } + var rest bytes.Buffer + for _, m := range messages[1:] { + writeLSP(t, &rest, m) + } + assertStartupFailureAnswer(t, rest.Bytes(), "exec format error") +} + +func TestStartupFailureEndsWithoutInitialize(t *testing.T) { + var out bytes.Buffer + if err := serveStartupFailure(bytes.NewReader(nil), &out, "x", time.Second); err != nil { + t.Fatalf("end of input: %v", err) + } + exit := bytes.NewReader(append(lspRequest(t, 2, "shutdown"), []byte("Content-Length: 33\r\n\r\n{\"jsonrpc\":\"2.0\",\"method\":\"exit\"}")...)) + if err := serveStartupFailure(exit, &out, "x", time.Second); err != nil { + t.Fatalf("exit: %v", err) + } + reader, writer := io.Pipe() + defer func() { _ = writer.Close() }() + if err := serveStartupFailure(reader, &out, "x", 20*time.Millisecond); err == nil { + t.Fatal("a silent editor did not time out") + } +} + +func TestExplainStartupFailureSaysWhatToDo(t *testing.T) { + cases := []struct { + name string + err error + want []string + }{ + { + name: "daemon newer", + err: &IncompatibleDaemonError{DaemonContract: ContractVersion + 1, DaemonPID: 42}, + want: []string{"this editor started an older Dexter build", "Restart this editor so that it starts the current dexter binary"}, + }, + { + name: "daemon older and stuck", + err: errors.Join(&IncompatibleDaemonError{DaemonContract: ContractVersion - 1, DaemonPID: 42, ClientNewer: true}, errors.New("daemon pid 42 did not exit")), + want: []string{"an older Dexter daemon (pid 42", "could not be replaced", "dexter stop --force"}, + }, + { + name: "root spelling", + err: &RootMismatchError{Requested: "/link/app", Daemon: "/real/app"}, + want: []string{"already serves this project as /real/app", "Open the project as /real/app", "dexter stop --force"}, + }, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + got := ExplainStartupFailure("/real/app", tc.err) + for _, want := range tc.want { + if !strings.Contains(got, want) { + t.Errorf("message %q does not contain %q", got, want) + } + } + }) + } +} + +// caseInsensitiveRoot makes a directory with upper-case letters and returns +// its spelling and a lower-case spelling. It skips the test where the file +// system tells the two apart. +func caseInsensitiveRoot(t *testing.T) (stored, other string) { + t.Helper() + stored = filepath.Join(t.TempDir(), "CaseApp") + if err := os.Mkdir(stored, 0o755); err != nil { + t.Fatal(err) + } + other = filepath.Join(filepath.Dir(stored), "caseapp") + if _, err := os.Stat(other); err != nil { + t.Skip("the file system is case-sensitive") + } + return stored, other +} + +// On a case-insensitive file system, two spellings of one directory are one +// workspace. Two identities would give two locks and two daemons that build +// one index at the same time. +func TestCaseSpellingsShareOneWorkspace(t *testing.T) { + stored, other := caseInsensitiveRoot(t) + a, err := ResolveEndpoint(stored) + if err != nil { + t.Fatal(err) + } + b, err := ResolveEndpoint(other) + if err != nil { + t.Fatal(err) + } + if a.Identity != b.Identity || a.Lock != b.Lock || a.Socket != b.Socket { + t.Fatalf("one directory has two identities:\n %+v\n %+v", a, b) + } + if b.Root != other { + t.Errorf("Root = %q, want the caller's spelling %q", b.Root, other) + } + + ownership, _, err := AcquireOwnership(stored) + if err != nil { + t.Fatal(err) + } + defer func() { _ = ownership.Release() }() + if _, _, err := AcquireOwnership(other); !errors.Is(err, ErrWorkspaceOwned) { + t.Fatalf("the other spelling took a second lock: %v", err) + } +} + +// The second spelling reaches the daemon of the first, which refuses it with +// the root mismatch that the editor then shows. +func TestCaseSpellingGetsRootMismatch(t *testing.T) { + quietEnv(t) + stored, other := caseInsensitiveRoot(t) + s, endpoint := pipeServer(t, stored) + otherEndpoint, err := ResolveEndpoint(other) + if err != nil { + t.Fatal(err) + } + _, _, res := pipeDial(t, s, otherEndpoint, kindLSP, "") + if res.OK || res.Root != endpoint.Root { + t.Fatalf("handshake = %+v, want a refusal that names %s", res, endpoint.Root) + } +} diff --git a/internal/daemon/server.go b/internal/daemon/server.go index 0a4d7ec..a32804d 100644 --- a/internal/daemon/server.go +++ b/internal/daemon/server.go @@ -16,6 +16,7 @@ import ( "time" "github.com/remoteoss/dexter/internal/lsp" + "github.com/remoteoss/dexter/internal/notify" "github.com/remoteoss/dexter/internal/version" "github.com/remoteoss/dexter/internal/workspace" ) @@ -96,6 +97,29 @@ type WorkspaceStatus struct { Definitions int `json:"definitions"` References int `json:"references"` Sessions []SessionStatus `json:"sessions,omitempty"` + // Conditions are the failures and degraded states that are active now, + // the same ones that attached editors see. + Conditions []Note `json:"conditions,omitempty"` +} + +// Note is one active condition of the workspace, for a frontend that cannot +// show LSP messages. Key names the condition (for example "index.rebuild"); +// Severity is "error", "warning", or "info". +type Note struct { + Key string `json:"key,omitempty"` + Severity string `json:"severity"` + Message string `json:"message"` +} + +func notesFrom(conditions []notify.Condition) []Note { + if len(conditions) == 0 { + return nil + } + out := make([]Note, len(conditions)) + for i, c := range conditions { + out[i] = Note{Key: c.Key, Severity: c.Severity.String(), Message: c.Message} + } + return out } // StatusParams optionally waits for the initial reconciliation before @@ -120,18 +144,21 @@ type LookupParams struct { } // LookupResult travels in the location encoding described at locationsWire. +// Notes are the active conditions of the index, such as a rebuild, so that a +// result from an incomplete index is not taken as complete. type LookupResult struct { Locations []lsp.NameLocation Ready bool + Notes []Note } func (r LookupResult) MarshalJSON() ([]byte, error) { - return marshalLocations(r.Locations, r.Ready) + return marshalLocations(r.Locations, r.Ready, r.Notes) } func (r *LookupResult) UnmarshalJSON(data []byte) error { var err error - r.Locations, r.Ready, err = unmarshalLocations(data) + r.Locations, r.Ready, r.Notes, err = unmarshalLocations(data) return err } @@ -146,15 +173,16 @@ type ReferencesParams struct { type ReferencesResult struct { Locations []lsp.NameLocation Ready bool + Notes []Note } func (r ReferencesResult) MarshalJSON() ([]byte, error) { - return marshalLocations(r.Locations, r.Ready) + return marshalLocations(r.Locations, r.Ready, r.Notes) } func (r *ReferencesResult) UnmarshalJSON(data []byte) error { var err error - r.Locations, r.Ready, err = unmarshalLocations(data) + r.Locations, r.Ready, r.Notes, err = unmarshalLocations(data) return err } @@ -167,6 +195,7 @@ type locationsWire struct { Files []string `json:"files"` Locations []locationWire `json:"locations"` Ready bool `json:"ready"` + Notes []Note `json:"notes,omitempty"` } type locationWire struct { @@ -177,11 +206,12 @@ type locationWire struct { Declaration bool `json:"declaration,omitempty"` } -func marshalLocations(locations []lsp.NameLocation, ready bool) ([]byte, error) { +func marshalLocations(locations []lsp.NameLocation, ready bool, notes []Note) ([]byte, error) { wire := locationsWire{ Files: []string{}, Locations: make([]locationWire, len(locations)), Ready: ready, + Notes: notes, } fileIndex := make(map[string]int) for i, location := range locations { @@ -202,15 +232,15 @@ func marshalLocations(locations []lsp.NameLocation, ready bool) ([]byte, error) return json.Marshal(wire) } -func unmarshalLocations(data []byte) ([]lsp.NameLocation, bool, error) { +func unmarshalLocations(data []byte) ([]lsp.NameLocation, bool, []Note, error) { var wire locationsWire if err := json.Unmarshal(data, &wire); err != nil { - return nil, false, err + return nil, false, nil, err } locations := make([]lsp.NameLocation, len(wire.Locations)) for i, location := range wire.Locations { if location.File < 0 || location.File >= len(wire.Files) { - return nil, false, fmt.Errorf("location %d names file %d of %d", i, location.File, len(wire.Files)) + return nil, false, nil, fmt.Errorf("location %d names file %d of %d", i, location.File, len(wire.Files)) } locations[i] = lsp.NameLocation{ FilePath: wire.Files[location.File], @@ -220,7 +250,7 @@ func unmarshalLocations(data []byte) ([]lsp.NameLocation, bool, error) { IsDeclaration: location.Declaration, } } - return locations, wire.Ready, nil + return locations, wire.Ready, wire.Notes, nil } type ReindexParams struct { @@ -234,6 +264,8 @@ type ReindexResult struct { // already matches the disk, and the watcher may simply have pruned a // deleted file first. A mistyped path is the usual cause. Missing bool `json:"missing,omitempty"` + // Notes are the active conditions of the index after the reindex. + Notes []Note `json:"notes,omitempty"` } // WatchParams subscribes a connection to coalesced index mutations. @@ -838,6 +870,7 @@ func (s *server) handleRequest(c *conn, mc MethodContext, req request) (any, err Root: st.Root, Ready: st.Ready, Watching: st.Watching, StdlibRoot: st.StdlibRoot, IndexVersion: st.IndexVersion, ExpectedIndexVersion: st.ExpectedIndexVersion, Files: st.Files, Definitions: st.Definitions, References: st.References, + Conditions: notesFrom(s.runtime.Reporter().Conditions()), } for _, sess := range s.runtime.Sessions() { out.Sessions = append(out.Sessions, SessionStatus{ @@ -861,7 +894,7 @@ func (s *server) handleRequest(c *conn, mc MethodContext, req request) (any, err if err != nil { return nil, err } - return LookupResult{Locations: locations, Ready: s.runtime.IsReady()}, err + return LookupResult{Locations: locations, Ready: s.runtime.IsReady(), Notes: notesFrom(s.runtime.IndexConditions())}, err case MethodReferences: var params ReferencesParams if err := json.Unmarshal(req.Params, ¶ms); err != nil { @@ -875,7 +908,7 @@ func (s *server) handleRequest(c *conn, mc MethodContext, req request) (any, err if err != nil { return nil, err } - return ReferencesResult{Locations: locations, Ready: s.runtime.IsReady()}, err + return ReferencesResult{Locations: locations, Ready: s.runtime.IsReady(), Notes: notesFrom(s.runtime.IndexConditions())}, err case MethodReindex: var params ReindexParams if err := json.Unmarshal(req.Params, ¶ms); err != nil { @@ -897,7 +930,7 @@ func (s *server) handleRequest(c *conn, mc MethodContext, req request) (any, err } err = s.runtime.ReindexPath(mc.Context, params.Target) } - return ReindexResult{Elapsed: time.Since(start).Round(time.Millisecond), Missing: missing}, err + return ReindexResult{Elapsed: time.Since(start).Round(time.Millisecond), Missing: missing, Notes: notesFrom(s.runtime.IndexConditions())}, err case MethodWatch: var params WatchParams if len(req.Params) > 0 { diff --git a/internal/indexer/indexer.go b/internal/indexer/indexer.go index 35c11cd..9aca9fb 100644 --- a/internal/indexer/indexer.go +++ b/internal/indexer/indexer.go @@ -48,6 +48,12 @@ type Options struct { // accumulates should still not assume single-threaded access from any other // caller. Warn func(format string, args ...interface{}) + + // FileError is called, after Warn, for each file that could not be read or + // parsed. Optional. The LSP server uses it to tell the user how many files + // are missing from the index. It is called from every parse worker, so it + // must be safe for concurrent use. + FileError func(path string, err error) } // serialWarn returns a callback that forwards to Warn under a mutex. Options is @@ -190,6 +196,9 @@ func FullBuild(s *store.Store, projectRoot string, opts Options) (Stats, error) defs, refs, err := parser.ParseFile(f.path) if err != nil { warn("%s: %v", f.path, err) + if opts.FileError != nil { + opts.FileError(f.path, err) + } continue } parseNanos.Add(int64(time.Since(t0))) diff --git a/internal/lsp/formatter.go b/internal/lsp/formatter.go index a9c9c00..bf0bdfa 100644 --- a/internal/lsp/formatter.go +++ b/internal/lsp/formatter.go @@ -753,7 +753,7 @@ func (s *Server) startBeamProcess(buildRoot string) (*beamProcess, error) { if bp.startErr != nil { _ = cmd.Process.Kill() <-done - s.notifyOTPMismatch(stderrBuf.String()) + s.notifyOTPMismatch(buildRoot, stderrBuf.String()) } case <-time.After(beamStuckTimeout): bp.finishStartup(fmt.Errorf("BEAM startup timed out")) @@ -852,14 +852,14 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin bp := s.getBeamProcess(ctx, buildRoot) if bp == nil { log.Printf("Formatting: BEAM process unavailable, falling back to mix format") - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) } if bp.formatterConfigChanged(formatterExs) { s.evictBeam(bp, fmt.Sprintf("formatter config changed: %s", formatterExs)) bp = s.getBeamProcess(ctx, buildRoot) if bp == nil { log.Printf("Formatting: BEAM process unavailable after formatter config change, falling back to mix format") - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) } _ = bp.formatterConfigChanged(formatterExs) } @@ -870,7 +870,7 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin if bp.startErr != nil { s.evictBeam(bp, fmt.Sprintf("formatContent: startup finished with error: %v", bp.startErr)) log.Printf("Formatting: BEAM process failed to start, falling back to mix format: %v", bp.startErr) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) } default: // Not ready yet — decide based on how long it's been starting @@ -879,11 +879,11 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin case age > beamStuckTimeout: log.Printf("Formatting: BEAM process stuck (started %s ago), restarting", age.Truncate(time.Second)) s.evictBeam(bp, fmt.Sprintf("formatContent: startup exceeded %s without becoming ready", beamStuckTimeout)) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) case age > beamWaitTimeout: log.Printf("Formatting: BEAM process not ready after %s, falling back to mix format", age.Truncate(time.Millisecond)) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) default: if err := bp.Ready(ctx); err != nil { @@ -892,7 +892,7 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin } s.evictBeam(bp, fmt.Sprintf("formatContent: Ready failed: %v", err)) log.Printf("Formatting: BEAM process failed to start, falling back to mix format: %v", err) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) } } } @@ -917,6 +917,7 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin } log.Printf("Formatting: %s (%s, persistent)", path, time.Since(start)) + s.reportFormatWorks(mixRoot, buildRoot) return result, nil } @@ -945,7 +946,10 @@ func (s *Server) evictBeam(bp *beamProcess, reason string) { bp.closeWithReason("evicted: " + reason) } -func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, path, content string) (string, error) { +// formatWithMixFormat runs `mix format` in mixRoot. buildRoot is the build root +// of the file, whose BEAM formatter can have reported an OTP mismatch; a +// success clears that report too. +func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, buildRoot, path, content string) (string, error) { if s.mixBin == "" { return "", fmt.Errorf("mix binary not found") } @@ -957,10 +961,13 @@ func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, path, content cmd.Stderr = &stderr if err := cmd.Run(); err != nil { log.Printf("Formatting: mix format failed for %s (%s): %v\n%s", path, time.Since(start), err, stderr.String()) - s.notifyOTPMismatch(stderr.String()) + if ctx.Err() == nil && !s.notifyOTPMismatch(mixRoot, stderr.String()) { + s.reportFormatFailure(mixRoot, err, stderr.String()) + } return "", err } log.Printf("Formatting: %s (%s, mix format)", path, time.Since(start)) + s.reportFormatWorks(mixRoot, buildRoot) return stdout.String(), nil } diff --git a/internal/lsp/report.go b/internal/lsp/report.go new file mode 100644 index 0000000..70bf8a8 --- /dev/null +++ b/internal/lsp/report.go @@ -0,0 +1,360 @@ +package lsp + +import ( + "errors" + "fmt" + "io/fs" + "path/filepath" + "sort" + "strings" + "sync" + "sync/atomic" + "time" + + "github.com/remoteoss/dexter/internal/notify" +) + +// Condition keys. A key names one state; setting it again does not send a new +// message, and clearing it tells the user that the state stopped. Keys that +// start with "index." describe the index, and the CLI shows them too. +const ( + // CondIndexBuild is the first build of an empty index. + CondIndexBuild = "index.build" + // CondIndexRebuild is a rebuild of an index that Dexter had to delete: it + // was written by another build, or it could not be opened. + CondIndexRebuild = "index.rebuild" + // CondIndexUnavailable is an index that Dexter cannot use at all. + CondIndexUnavailable = "index.unavailable" + // CondIndexFallback is a fast full build that failed, so the files are + // indexed one by one. + CondIndexFallback = "index.fallback" + // CondIndexFiles is a set of files that could not be indexed. + CondIndexFiles = "index.files" + + condStdlib = "stdlib" + condFormatter = "formatter" + condOTP = "formatter.otp" +) + +// IndexConditionPrefix starts the key of every condition that describes the +// index. +const IndexConditionPrefix = "index." + +// reconcileProgressThreshold is how many changed files an incremental pass +// updates before it shows progress. A save or a small branch switch stays +// silent; a large one, which can take minutes, does not. +const reconcileProgressThreshold = 1000 + +// Reporter returns the reporter that every session of this workspace shares. +func (c *IndexCoordinator) Reporter() *notify.Reporter { return c.reporter } + +// fileFailures is the set of files that could not be indexed. Each file is +// told to the user only as a part of one aggregate message. +type fileFailures struct { + count atomic.Int32 // len(paths), read without the lock on the hot path + changed atomic.Bool // the set changed since the last report + mu sync.Mutex + paths map[string]string // path → error text +} + +// fail records a file that could not be read, parsed, or written. A file that +// went away in the middle of the work is not a failure. +func (f *fileFailures) fail(path string, err error) { + if errors.Is(err, fs.ErrNotExist) { + f.ok(path) + return + } + f.mu.Lock() + defer f.mu.Unlock() + if f.paths == nil { + f.paths = make(map[string]string) + } + if _, ok := f.paths[path]; !ok { + f.changed.Store(true) + } + f.paths[path] = err.Error() + f.count.Store(int32(len(f.paths))) +} + +// ok records a file that was indexed or removed. It costs one atomic load when +// no file has failed, which is the usual case. +func (f *fileFailures) ok(path string) { + if f.count.Load() == 0 { + return + } + f.mu.Lock() + defer f.mu.Unlock() + if _, found := f.paths[path]; found { + delete(f.paths, path) + f.changed.Store(true) + f.count.Store(int32(len(f.paths))) + } +} + +// removed drops the failures at path and below it. A file that failed was +// never stored, so removing a directory from the index does not list it; the +// prefix finds it anyway. +func (f *fileFailures) removed(path string) { + if f.count.Load() == 0 { + return + } + prefix := strings.TrimSuffix(path, string(filepath.Separator)) + string(filepath.Separator) + f.mu.Lock() + defer f.mu.Unlock() + for failed := range f.paths { + if failed == path || strings.HasPrefix(failed, prefix) { + delete(f.paths, failed) + f.changed.Store(true) + } + } + f.count.Store(int32(len(f.paths))) +} + +// retain drops failures for files that a full walk did not see: they are gone +// or no longer belong to the workspace. +func (f *fileFailures) retain(seen map[string]struct{}) { + if f.count.Load() == 0 { + return + } + f.mu.Lock() + defer f.mu.Unlock() + for path := range f.paths { + if _, ok := seen[path]; !ok { + delete(f.paths, path) + f.changed.Store(true) + } + } + f.count.Store(int32(len(f.paths))) +} + +// reportFileFailures tells the user when the set of failed files changed since +// the last report. When it did not change, which is the usual case, it costs +// one atomic load. +func (c *IndexCoordinator) reportFileFailures() { + f := &c.failures + if !f.changed.Load() { + return + } + f.mu.Lock() + if !f.changed.Swap(false) { + f.mu.Unlock() + return + } + paths := make([]string, 0, len(f.paths)) + for path := range f.paths { + paths = append(paths, path) + } + sort.Strings(paths) + firstErr := "" + if len(paths) > 0 { + firstErr = f.paths[paths[0]] + } + f.mu.Unlock() + + if len(paths) == 0 { + c.reporter.Clear(CondIndexFiles, "Dexter: all files that could not be indexed are indexed now.") + return + } + noun := "files" + if len(paths) == 1 { + noun = "file" + } + c.reporter.Set(CondIndexFiles, notify.Warning, fmt.Sprintf( + "Dexter: %d %s could not be indexed: %s (%s); see the log. Navigation does not find their definitions until Dexter can index them. Dexter tries again when they change.", + len(paths), noun, notify.Summarize(paths), firstErr)) +} + +// beginIndexBuild tells the user that an empty index is being built. A rebuild +// already has its own condition, which says why; a first build gets an Info +// message, as before. A workspace with no Elixir files stays empty, so every +// full pass over it starts as a cold build: it is told only once for each +// workspace, and later passes return a nil task, which reports nothing. +func (s *Server) beginIndexBuild() *notify.Task { + r := s.index.reporter + first := s.index.firstBuildReported.CompareAndSwap(false, true) + if r.Active(CondIndexRebuild) { + return r.Begin(CondIndexBuild, "Dexter: building the index", "parsing every Elixir file in the project", false) + } + if !first { + return nil + } + r.Set(CondIndexBuild, notify.Info, "Dexter: building the index for the first time; go-to-definition will be available shortly.") + return r.Begin(CondIndexBuild, "Dexter: building the index", "parsing every Elixir file in the project", false) +} + +// indexBuildFailedUnindexed tells the user that the bulk build left an index +// that Dexter cannot use. +func (s *Server) indexBuildFailedUnindexed(task *notify.Task, err error) { + r := s.index.reporter + task.End("Dexter: the index could not be completed") + r.Clear(CondIndexBuild, "") + r.Clear(CondIndexRebuild, "") + r.Set(CondIndexUnavailable, notify.Error, fmt.Sprintf( + "Dexter: the index could not be completed (%v), so navigation, references, and completion from the index do not work. Close the editors on this project, run `dexter init --force` in the project root, then open the editor again. If it happens again, please report it.", err)) +} + +// indexBuildFellBack tells the user that the fast build failed and the slow +// path is used. +func (s *Server) indexBuildFellBack(err error) { + s.index.reporter.Set(CondIndexFallback, notify.Warning, fmt.Sprintf( + "Dexter: the fast index build failed (%v). Dexter now indexes the files one by one, which is slower; navigation is limited until it ends. See the log for details.", err)) +} + +// finishReindex ends the reports of one full-or-incremental pass. The clear +// messages say that the index works fully again. +func (s *Server) finishReindex(task *notify.Task, files int, elapsed time.Duration) { + r := s.index.reporter + built := fmt.Sprintf("Dexter: index built (%d files in %s).", files, elapsed) + task.End(built) + r.Clear(CondIndexFallback, "") + if r.Clear(CondIndexRebuild, fmt.Sprintf("Dexter: the index rebuild is complete (%d files in %s); navigation works fully again.", files, elapsed)) { + r.Clear(CondIndexBuild, "") + } else { + r.Clear(CondIndexBuild, built) + } + s.index.reportFileFailures() +} + +// reconcileProgress shows progress for an incremental pass that turns out to +// be large. It starts only after reconcileProgressThreshold changed files, so +// the usual pass costs one comparison per changed file. +type reconcileProgress struct { + reporter *notify.Reporter + task *notify.Task + files int + last time.Time +} + +func (p *reconcileProgress) file() { + p.files++ + if p.files < reconcileProgressThreshold { + return + } + if p.task == nil { + p.task = p.reporter.Begin("index.reconcile", "Dexter: updating the index", + fmt.Sprintf("%d changed files so far", p.files), true) + p.last = time.Now() + return + } + if p.files%100 == 0 && time.Since(p.last) >= time.Second { + p.last = time.Now() + p.task.Report(fmt.Sprintf("%d changed files so far", p.files), -1) + } +} + +func (p *reconcileProgress) end(elapsed time.Duration) { + if p.task != nil { + p.task.End(fmt.Sprintf("Dexter: index updated (%d changed files in %s).", p.files, elapsed)) + } +} + +// ReportStdlib tells the user whether the workspace has an Elixir standard +// library. It reads the root that every session shares, not what one session +// found: one editor can pass stdlibPath while another has no way to find it, +// and the second must not report a library that the workspace already has. +func (s *Server) ReportStdlib() { + r := s.index.reporter + if root := s.StdlibRoot(); root != "" { + r.Clear(condStdlib, fmt.Sprintf("Dexter: found the Elixir standard library at %s; navigation into it works now.", root)) + return + } + r.Set(condStdlib, notify.Warning, "Dexter: could not find the Elixir standard library, so standard library modules (Enum, String, and so on) do not resolve. Make sure that the Elixir version in .tool-versions or mise.toml is installed (for example `mise install`), or set DEXTER_ELIXIR_LIB_ROOT or the stdlibPath initialization option, then restart the editor.") +} + +// mixMissingMessage tells one editor that its session has no mix binary. Each +// session finds mix for itself and uses it for its own formatting, so the +// report goes to that editor only. +const mixMissingMessage = "Dexter: could not find the `mix` binary, so formatting does not work in this editor. Install the Elixir version of this project (for example `mise install`) or put mix on the PATH of the editor, then restart the editor." + +// reportFormatWorks clears the formatter conditions of one Mix project after a +// format succeeded there. The conditions are kept for each project: in an +// umbrella or a monorepo, one project can fail to format while another works, +// and a success in one must not clear, or set again, the report of the other. +func (s *Server) reportFormatWorks(mixRoot, buildRoot string) { + r := s.index.reporter + cleared := r.Clear(condFormatter+":"+mixRoot, "") + if r.Clear(condOTP+":"+mixRoot, "") { + cleared = true + } + if buildRoot != mixRoot && r.Clear(condOTP+":"+buildRoot, "") { + cleared = true + } + if cleared { + r.Notify(notify.Info, fmt.Sprintf("Dexter: formatting works again in %s.", mixRoot)) + } +} + +// reportFormatFailure tells the user that formatting cannot run in one Mix +// project. A syntax error in the user's code is not a failure of Dexter: it +// already shows as a diagnostic, or mix reports it. +func (s *Server) reportFormatFailure(mixRoot string, err error, stderr string) { + if isUserCodeFormatError(stderr) { + return + } + detail := err.Error() + if line := firstErrorLine(stderr); line != "" { + detail = line + } + s.index.reporter.Set(condFormatter+":"+mixRoot, notify.Warning, fmt.Sprintf( + "Dexter: formatting does not work in %s: `mix format` failed (%s). See the log for the full output. Make sure that the project compiles and that its formatter plugins are installed (`mix deps.get`).", mixRoot, detail)) +} + +// isUserCodeFormatError reports whether mix format failed because of the code +// it had to format. +func isUserCodeFormatError(stderr string) bool { + for _, marker := range []string{"SyntaxError", "TokenMissingError", "MismatchedDelimiterError"} { + if strings.Contains(stderr, marker) { + return true + } + } + return false +} + +func firstErrorLine(stderr string) string { + for _, line := range strings.Split(stderr, "\n") { + line = strings.TrimSpace(line) + if line != "" { + if len(line) > 200 { + line = line[:200] + "..." + } + return line + } + } + return "" +} + +// renameFailures collects the files that one rename could not change. Writes +// run in parallel, so it is safe for concurrent use. +type renameFailures struct { + mu sync.Mutex + paths []string + first string +} + +func (f *renameFailures) add(path string, err error) { + if f == nil { + return + } + f.mu.Lock() + defer f.mu.Unlock() + if len(f.paths) == 0 { + f.first = err.Error() + } + f.paths = append(f.paths, path) +} + +// report tells this editor, and only this editor, that its rename is +// incomplete. +func (s *Server) reportRenameFailures(f *renameFailures) { + f.mu.Lock() + paths := append([]string(nil), f.paths...) + first := f.first + f.mu.Unlock() + if len(paths) == 0 { + return + } + sort.Strings(paths) + s.notifySession(notify.Error, fmt.Sprintf( + "Dexter: the rename could not change %d files: %s (%s). These files still use the old name; see the log, then fix them by hand or undo the rename.", + len(paths), notify.Summarize(paths), first)) +} diff --git a/internal/lsp/report_test.go b/internal/lsp/report_test.go new file mode 100644 index 0000000..c3a29d5 --- /dev/null +++ b/internal/lsp/report_test.go @@ -0,0 +1,404 @@ +package lsp + +import ( + "context" + "errors" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "go.lsp.dev/protocol" + + "github.com/remoteoss/dexter/internal/notify" + "github.com/remoteoss/dexter/internal/notify/notifytest" +) + +const reportWait = 10 * time.Second + +// attachFakeEditor connects a recording client to the server the way a real +// editor session does: capabilities in Initialize, reports from initialized. +func attachFakeEditor(t *testing.T, server *Server, progress bool) *notifytest.Client { + t.Helper() + client := notifytest.New() + server.client = client + server.workDoneProgress = progress + if err := server.Initialized(context.Background(), &protocol.InitializedParams{}); err != nil { + t.Fatal(err) + } + t.Cleanup(server.detachFromReporter) + return client +} + +func countMessages(client *notifytest.Client, text string) int { + n := 0 + for _, m := range client.Messages() { + if strings.Contains(m.Message, text) { + n++ + } + } + return n +} + +// A cold build is long work: the editor must see that it started, its +// progress, and that it ended. +func TestColdBuildShowsProgressAndResult(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + writeTestFile(t, server.projectRoot, "lib/accounts.ex", "defmodule MyApp.Accounts do\n def get, do: :ok\nend\n") + client := attachFakeEditor(t, server, true) + + server.backgroundReindex() + server.index.backgroundWork.Wait() + + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: building the index for the first time") + client.WaitFor(t, reportWait, "progress begin", func(e notifytest.Event) bool { + return e.Method == protocol.MethodProgress && e.Kind == "begin" && e.Title == "Dexter: building the index" + }) + client.WaitFor(t, reportWait, "progress end", func(e notifytest.Event) bool { + return e.Method == protocol.MethodProgress && e.Kind == "end" && strings.HasPrefix(e.Message, "Dexter: index built (1 files in ") + }) + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: index built (1 files in ") + for _, c := range server.index.reporter.Conditions() { + if strings.HasPrefix(c.Key, IndexConditionPrefix) { + t.Errorf("index condition %q is still active after the build", c.Key) + } + } +} + +// A workspace with no Elixir files stays empty, so each full pass over it +// starts as a cold build. The editors must hear about the first build once, +// not on every git HEAD change or watcher overflow. +func TestEmptyWorkspaceReportsTheFirstBuildOnce(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + client := attachFakeEditor(t, server, true) + for i := 0; i < 3; i++ { + server.backgroundReindex() + server.index.backgroundWork.Wait() + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: index built (0 files in ") + time.Sleep(50 * time.Millisecond) + begins := 0 + for _, e := range client.Events() { + if e.Method == protocol.MethodProgress && e.Kind == "begin" { + begins++ + } + } + if n := countMessages(client, "building the index for the first time"); n != 1 || begins != 1 || countMessages(client, "index built") != 1 { + t.Fatalf("three passes over an empty workspace sent %d first-build messages and %d progress begins:\n%s", n, begins, client.Dump()) + } +} + +// A rebuild (set by the workspace when it deleted an index) replaces the +// first-build message, and its end says that navigation works fully again. +func TestRebuildEndsWithItsOwnMessage(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + writeTestFile(t, server.projectRoot, "lib/accounts.ex", "defmodule MyApp.Accounts do\nend\n") + server.index.reporter.Set(CondIndexRebuild, notify.Warning, "Dexter: the index was written by a newer Dexter build") + client := attachFakeEditor(t, server, false) + + server.backgroundReindex() + server.index.backgroundWork.Wait() + + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: the index rebuild is complete (1 files in ") + if n := countMessages(client, "building the index for the first time"); n != 0 { + t.Errorf("a rebuild was also told as a first build:\n%s", client.Dump()) + } + if n := countMessages(client, "Dexter: index built"); n != 0 { + t.Errorf("a rebuild sent a second end message:\n%s", client.Dump()) + } + if server.index.reporter.Active(CondIndexRebuild) { + t.Error("the rebuild condition is still active") + } +} + +func TestUnusableIndexIsAnError(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + client := attachFakeEditor(t, server, true) + task := server.beginIndexBuild() + server.indexBuildFailedUnindexed(task, errors.New("index creation failed")) + + got := client.WaitMessage(t, reportWait, protocol.MessageTypeError, "the index could not be completed (index creation failed)") + if !strings.Contains(got.Message, "dexter init --force") { + t.Errorf("message does not say what to do: %q", got.Message) + } + client.WaitFor(t, reportWait, "progress end", func(e notifytest.Event) bool { + return e.Method == protocol.MethodProgress && e.Kind == "end" + }) + if server.index.reporter.Active(CondIndexBuild) { + t.Error("the build condition is still active") + } +} + +// Files that cannot be indexed are told in one message, not one each, and the +// user is told when they are indexed again. +func TestFileFailuresAreAggregated(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("root can read files without read permission") + } + server, cleanup := setupTestServer(t) + defer cleanup() + indexFile(t, server.store, server.projectRoot, "lib/good.ex", "defmodule Good do\nend\n") + var bad []string + for _, name := range []string{"a", "b", "c"} { + path := filepath.Join(server.projectRoot, "lib", name+".ex") + writeTestFile(t, server.projectRoot, "lib/"+name+".ex", "defmodule Bad do\nend\n") + if err := os.Chmod(path, 0); err != nil { + t.Fatal(err) + } + bad = append(bad, path) + } + t.Cleanup(func() { + for _, path := range bad { + _ = os.Chmod(path, 0o644) + } + }) + client := attachFakeEditor(t, server, false) + + server.backgroundReindex() + server.index.backgroundWork.Wait() + + got := client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Dexter: 3 files could not be indexed: "+bad[0]+" and 2 more (") + if !strings.Contains(got.Message, "see the log") { + t.Errorf("message does not point to the log: %q", got.Message) + } + + for i, path := range bad { + if err := os.Chmod(path, 0o644); err != nil { + t.Fatal(err) + } + server.ReconcileFile(path) + if i < len(bad)-1 && !server.index.reporter.Active(CondIndexFiles) { + t.Fatal("condition cleared while files still fail") + } + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "all files that could not be indexed are indexed now") + if n := countMessages(client, "could not be indexed:"); n != 1 { + t.Errorf("got %d failure messages, want 1:\n%s", n, client.Dump()) + } +} + +// A failed file was never stored, so removing its directory from the index +// does not list it. The report must still end when the directory goes. +func TestRemovedDirectoryEndsItsFileFailures(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("root can read files without read permission") + } + server, cleanup := setupTestServer(t) + defer cleanup() + indexFile(t, server.store, server.projectRoot, "lib/good.ex", "defmodule Good do\nend\n") + writeTestFile(t, server.projectRoot, "lib/gen/bad.ex", "defmodule Gen.Bad do\nend\n") + bad := filepath.Join(server.projectRoot, "lib", "gen", "bad.ex") + if err := os.Chmod(bad, 0); err != nil { + t.Fatal(err) + } + client := attachFakeEditor(t, server, false) + server.backgroundReindex() + server.index.backgroundWork.Wait() + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "1 file could not be indexed: "+bad) + + gen := filepath.Join(server.projectRoot, "lib", "gen") + moved := filepath.Join(t.TempDir(), "gen") + if err := os.Rename(gen, moved); err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = os.Chmod(filepath.Join(moved, "bad.ex"), 0o644) }) + // What the workspace runtime does for a directory that went away. + under, err := server.store.ListFilePathsUnder(gen) + if err != nil { + t.Fatal(err) + } + server.RemoveFiles(append(under, gen)) + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "all files that could not be indexed are indexed now") +} + +// A file that went away during a walk is not a failure. +func TestMissingFileIsNotAFailure(t *testing.T) { + var f fileFailures + f.fail("/gone.ex", &os.PathError{Op: "open", Path: "/gone.ex", Err: os.ErrNotExist}) + if f.count.Load() != 0 { + t.Fatal("a missing file was recorded as a failure") + } +} + +func TestMissingStdlibAndMixAreShown(t *testing.T) { + t.Setenv("PATH", t.TempDir()) + t.Setenv("SHELL", "/bin/false") + t.Setenv("HOME", t.TempDir()) + t.Setenv("DEXTER_ELIXIR_LIB_ROOT", "") + server, cleanup := setupTestServer(t) + defer cleanup() + server.manageWorkspace = false // no background build in this test + server.mixBin = "" + + if _, err := server.Initialize(context.Background(), &protocol.InitializeParams{ + Capabilities: protocol.ClientCapabilities{Window: &protocol.WindowClientCapabilities{WorkDoneProgress: true}}, + }); err != nil { + t.Fatal(err) + } + if !server.workDoneProgress { + t.Error("the workDoneProgress capability was not read") + } + client := attachFakeEditor(t, server, true) + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "could not find the Elixir standard library") + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "could not find the `mix` binary, so formatting does not work in this editor") + + server.SetStdlibRoot("/opt/elixir/lib") + server.ReportStdlib() + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "found the Elixir standard library at /opt/elixir/lib") +} + +// Editors share one stdlib root and one reporter, but each finds mix for +// itself. An editor that cannot find either on its own must not tell every +// editor that the workspace has no stdlib when another editor already set it, +// and its missing mix concerns only that editor. +func TestStdlibIsReportedFromTheSharedRootAndMixPerEditor(t *testing.T) { + t.Setenv("PATH", t.TempDir()) + t.Setenv("SHELL", "/bin/false") + t.Setenv("HOME", t.TempDir()) + t.Setenv("DEXTER_ELIXIR_LIB_ROOT", "") + first, cleanup := setupTestServer(t) + defer cleanup() + first.manageWorkspace = false + stdlibRoot := t.TempDir() + first.SetStdlibRoot(stdlibRoot) // as an editor with stdlibPath does + firstClient := attachFakeEditor(t, first, false) + + second := NewServerWithOptions(first.store, first.projectRoot, ServerOptions{Index: first.index}) + if _, err := second.Initialize(context.Background(), &protocol.InitializeParams{}); err != nil { + t.Fatal(err) + } + secondClient := attachFakeEditor(t, second, false) + secondClient.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "could not find the `mix` binary") + + time.Sleep(50 * time.Millisecond) + if first.index.reporter.Active(condStdlib) { + t.Errorf("the stdlib is reported missing although the workspace has %s", stdlibRoot) + } + for _, m := range firstClient.Messages() { + t.Errorf("the first editor received a report about the second: %v", m) + } +} + +// fakeMix writes a mix script that fails `mix format` in a directory named +// "broken" and with a syntax error in a directory named "typo", and that +// formats everywhere else by echoing its input. +func fakeMix(t *testing.T) string { + t.Helper() + path := filepath.Join(t.TempDir(), "mix") + script := `#!/bin/sh +case "$PWD" in + */broken) echo "** (Mix) Formatter plugin Styler cannot be found" >&2; exit 1 ;; + */typo) echo "** (SyntaxError) lib/a.ex:3: unexpected token" >&2; exit 1 ;; +esac +cat +` + if err := os.WriteFile(path, []byte(script), 0o755); err != nil { + t.Fatal(err) + } + return path +} + +// In an umbrella or a monorepo, one Mix project can fail to format while +// another works. Saves that alternate between them must not send a warning and +// a "works again" message to every editor each time. +func TestFormatterFailuresAreKeptForEachProject(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + server.mixBin = fakeMix(t) + client := attachFakeEditor(t, server, false) + broken := filepath.Join(server.projectRoot, "apps", "broken") + good := filepath.Join(server.projectRoot, "apps", "good") + typo := filepath.Join(server.projectRoot, "apps", "typo") + for _, dir := range []string{broken, good, typo} { + if err := os.MkdirAll(dir, 0o755); err != nil { + t.Fatal(err) + } + } + format := func(mixRoot string) error { + _, err := server.formatWithMixFormat(context.Background(), mixRoot, mixRoot, filepath.Join(mixRoot, "lib", "a.ex"), "x\n") + return err + } + + for i := 0; i < 3; i++ { + if err := format(broken); err == nil { + t.Fatal("the broken project formatted") + } + if err := format(good); err != nil { + t.Fatalf("the good project did not format: %v", err) + } + } + if err := format(typo); err == nil { + t.Fatal("the project with a syntax error formatted") + } + got := client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "formatting does not work in "+broken+": `mix format` failed (** (Mix) Formatter plugin Styler cannot be found)") + if !strings.Contains(got.Message, "mix deps.get") { + t.Errorf("message does not say what to do: %q", got.Message) + } + time.Sleep(50 * time.Millisecond) + if n := len(client.Messages()); n != 1 { + t.Fatalf("alternate saves sent %d messages, want 1:\n%s", n, client.Dump()) + } + if server.index.reporter.Active(condFormatter + ":" + typo) { + t.Error("a syntax error in user code was reported as a formatter failure") + } + + // A later success in the broken project is what clears its report. + server.reportFormatWorks(broken, broken) + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: formatting works again in "+broken+".") + + if !server.notifyOTPMismatch(good, "** (UndefinedFunctionError) requires a more recent Erlang/OTP") { + t.Fatal("OTP mismatch was not recognized") + } + client.WaitMessage(t, reportWait, protocol.MessageTypeError, "Elixir/OTP version mismatch in "+good) + other := filepath.Join(server.projectRoot, "apps", "other") + if err := os.MkdirAll(other, 0o755); err != nil { + t.Fatal(err) + } + if err := format(other); err != nil { + t.Fatal(err) + } + if !server.index.reporter.Active(condOTP + ":" + good) { + t.Fatal("a success in one project cleared the OTP report of another") + } +} + +func TestRenameFailuresAreShownToTheRequestingEditor(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + client := notifytest.New() + server.client = client + var failures renameFailures + failures.add("/p/lib/b.ex", errors.New("permission denied")) + failures.add("/p/lib/a.ex", errors.New("read-only file system")) + server.reportRenameFailures(&failures) + got := client.WaitMessage(t, reportWait, protocol.MessageTypeError, "the rename could not change 2 files: /p/lib/a.ex and 1 more (permission denied)") + if !strings.Contains(got.Message, "still use the old name") { + t.Errorf("message does not say what is left: %q", got.Message) + } + server.reportRenameFailures(&renameFailures{}) + time.Sleep(20 * time.Millisecond) + if n := len(client.Messages()); n != 1 { + t.Errorf("a rename without failures sent a message:\n%s", client.Dump()) + } +} + +// Sessions attach in initialized and detach when they close, so a closed +// editor gets nothing more. +func TestClosedSessionStopsReceivingReports(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + client := attachFakeEditor(t, server, false) + server.index.reporter.Notify(notify.Warning, "Dexter: before close") + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "before close") + server.CloseSession() + server.index.reporter.Notify(notify.Warning, "Dexter: after close") + time.Sleep(20 * time.Millisecond) + if n := countMessages(client, "after close"); n != 0 { + t.Errorf("a closed session received a report:\n%s", client.Dump()) + } +} diff --git a/internal/lsp/server.go b/internal/lsp/server.go index 3e5cbfc..db38417 100644 --- a/internal/lsp/server.go +++ b/internal/lsp/server.go @@ -32,6 +32,7 @@ import ( "github.com/remoteoss/dexter/internal/beam" "github.com/remoteoss/dexter/internal/indexer" + "github.com/remoteoss/dexter/internal/notify" "github.com/remoteoss/dexter/internal/parser" "github.com/remoteoss/dexter/internal/stdlib" "github.com/remoteoss/dexter/internal/store" @@ -103,6 +104,14 @@ type IndexCoordinator struct { unavailable bool // guarded by writes backgroundWork sync.WaitGroup + + // reporter tells every attached editor about failures, degraded states, + // and long work. It is shared like the store: one workspace, one set of + // conditions. + reporter *notify.Reporter + failures fileFailures + // firstBuildReported makes the first-build report once per workspace. + firstBuildReported atomic.Bool } func (c *IndexCoordinator) setStdlibRoot(root string) (string, bool) { @@ -124,7 +133,7 @@ func (c *IndexCoordinator) getStdlibRoot() string { // NewIndexCoordinator returns write coordination for one workspace store. func NewIndexCoordinator() *IndexCoordinator { - return &IndexCoordinator{} + return &IndexCoordinator{reporter: notify.New()} } // ServerOptions configures a Server attached to a daemon-owned workspace. @@ -178,11 +187,14 @@ type Server struct { // negotiation can set it without touching every call site. positionEncoding PositionEncoding - index *IndexCoordinator - workspaceEvents WorkspaceEvents - manageWorkspace bool - notifiedOTPMismatch sync.Once // prevents repeated OTP mismatch warnings - closeOnce sync.Once + index *IndexCoordinator + workspaceEvents WorkspaceEvents + manageWorkspace bool + closeOnce sync.Once + + workDoneProgress bool // client supports window/workDoneProgress/create + mixMissing bool // Initialize found no mix binary for this session + detachReporter atomic.Value // func(); set when the client sent initialized } func (s *Server) debugf(format string, args ...interface{}) { @@ -279,6 +291,7 @@ func ServeStream(server *Server, rwc io.ReadWriteCloser) error { conn.Go(ctx, handler) <-conn.Done() + server.detachFromReporter() if err := conn.Err(); err != nil && !isStreamClosed(err) { return err } @@ -441,17 +454,20 @@ func underTop(root, dir string, tops map[string]struct{}) bool { return false } -// showError reports a problem the user has to act on. The caller logs as well, -// so a client without window/showMessage support still leaves a trace. -func (s *Server) showError(message string) { - if s.client == nil { - return +// notifySession logs a report about this editor's own request and shows it +// to this editor only. Workspace states go through the shared reporter. +func (s *Server) notifySession(sev notify.Severity, message string) { + prefix := map[notify.Severity]string{notify.Error: "Error: ", notify.Warning: "Warning: "}[sev] + log.Printf("%s%s", prefix, strings.TrimPrefix(message, "Dexter: ")) + if s.client != nil { + notify.Show(context.Background(), s.client, sev, message) } - if err := s.client.ShowMessage(context.Background(), &protocol.ShowMessageParams{ - Type: protocol.MessageTypeError, - Message: message, - }); err != nil { - log.Printf("ShowMessage: %v", err) +} + +// detachFromReporter stops sending workspace reports to this editor. +func (s *Server) detachFromReporter() { + if detach, ok := s.detachReporter.Load().(func()); ok { + detach() } } @@ -490,6 +506,7 @@ func (s *Server) fullBuild() (stats indexer.Stats, ran bool, err error) { Warn: func(format string, args ...interface{}) { log.Printf("Warning: "+format, args...) }, + FileError: s.index.failures.fail, }) if errors.Is(err, indexer.ErrUnindexed) { s.index.unavailable = true @@ -505,6 +522,7 @@ func (s *Server) indexOneFile(path string) { return } s.indexOneFileLocked(path) + s.index.reportFileFailures() } // indexOneFileLocked is indexOneFile for callers already holding indexWrites. @@ -518,11 +536,15 @@ func (s *Server) indexOneFileLocked(path string) { defs, refs, err := parser.ParseFile(path) if err != nil { log.Printf("Error parsing %s: %v", path, err) + s.index.failures.fail(path, err) return } if err := s.store.IndexFileWithRefs(path, defs, refs); err != nil { log.Printf("Error indexing %s: %v", path, err) + s.index.failures.fail(path, err) + return } + s.index.failures.ok(path) } // backgroundReindex runs in the background. If the index is empty it does a @@ -544,17 +566,11 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { reindexed := 0 coldStart := s.store.IsEmpty() fullBuilt := false + var buildTask *notify.Task + progress := reconcileProgress{reporter: s.index.reporter} if coldStart { - log.Printf("No index found, building from scratch...") - if s.client != nil { - if err := s.client.ShowMessage(context.Background(), &protocol.ShowMessageParams{ - Type: protocol.MessageTypeInfo, - Message: "Dexter: building index for the first time, go-to-definition will be available shortly...", - }); err != nil { - log.Printf("ShowMessage: %v", err) - } - } + buildTask = s.beginIndexBuild() stats, ran, err := s.fullBuild() switch { @@ -567,8 +583,7 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { // index version unset, so the next editor start rebuilds from // scratch through cmdInit — in a process with no live readers, // where deleting the database is safe. - log.Printf("Error: SQL indexes could not be restored after the bulk build: %v", err) - s.showError("Dexter: the index could not be completed. Run `dexter init --force` in your project root and restart your editor. If it happens again, please report it.") + s.indexBuildFailedUnindexed(buildTask, err) // Collapse any committed data in the WAL rather than leaving it at // its high-water mark for the rest of the process. if err := s.store.Checkpoint(); err != nil { @@ -579,7 +594,7 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { // The incremental walk below needs nothing to be true of the // database, so it is the safe thing to fall back to. It is // slower, not wrong. - log.Printf("Warning: full index build failed, falling back to incremental: %v", err) + s.indexBuildFellBack(err) case !ran: // Something wrote to the index between the check above and the // build's lock. Nothing was built, and the incremental path @@ -615,6 +630,10 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { defs, refs, err := parser.ParseFile(path) if err != nil { + if !errors.Is(err, fs.ErrNotExist) { + log.Printf("Warning: reindex %s: %v", path, err) + } + s.index.failures.fail(path, err) return nil } if !indexRefs { @@ -622,8 +641,14 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { } if err := s.store.IndexFileWithRefs(path, defs, refs); err != nil { log.Printf("Warning: reindex %s: %v", path, err) + s.index.failures.fail(path, err) + } else { + s.index.failures.ok(path) } reindexed++ + if !coldStart { + progress.file() + } return nil }) } @@ -639,6 +664,7 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { s.index.writes.RLock() if s.index.unavailable { s.index.writes.RUnlock() + buildTask.End("") return } // Index stdlib first (definitions only). @@ -650,6 +676,7 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { s.index.writes.RUnlock() s.pruneMissingFiles(seen) + s.index.failures.retain(seen) } // Collapse the WAL back to disk now that the (potentially large) reindex @@ -665,15 +692,8 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { elapsed := time.Since(start).Round(time.Millisecond) log.Printf("Background reindex: %d files updated (%s)", reindexed, elapsed) - - if coldStart && s.client != nil { - if err := s.client.ShowMessage(context.Background(), &protocol.ShowMessageParams{ - Type: protocol.MessageTypeInfo, - Message: fmt.Sprintf("Dexter: index built (%d files in %s)", reindexed, elapsed), - }); err != nil { - log.Printf("ShowMessage: %v", err) - } - } + progress.end(elapsed) + s.finishReindex(buildTask, reindexed, elapsed) }() return done } @@ -709,7 +729,15 @@ func (s *Server) RemoveFiles(paths []string) { } if err := s.store.RemoveFiles(paths); err != nil { log.Printf("Error removing %d files from index: %v", len(paths), err) + for _, path := range paths { + s.index.failures.fail(path, err) + } + } else { + for _, path := range paths { + s.index.failures.removed(path) + } } + s.index.reportFileFailures() } // RemoveFilesUnderRoot removes indexed files below root as one workspace @@ -768,19 +796,16 @@ func (s *Server) watchGitHead() { }() } -// notifyOTPMismatch checks stderr output for an OTP version mismatch and -// sends a one-time warning to the editor so the user doesn't have to dig -// through logs. -func (s *Server) notifyOTPMismatch(stderr string) { - if s.client == nil || !strings.Contains(stderr, "requires a more recent Erlang/OTP") { - return +// notifyOTPMismatch checks stderr output for an OTP version mismatch and, when +// it finds one, makes it a condition of the project at root, so every editor +// shows it once and the user does not have to dig through logs. It reports +// whether it found one. +func (s *Server) notifyOTPMismatch(root, stderr string) bool { + if !strings.Contains(stderr, "requires a more recent Erlang/OTP") { + return false } - s.notifiedOTPMismatch.Do(func() { - _ = s.client.ShowMessage(context.Background(), &protocol.ShowMessageParams{ - Type: protocol.MessageTypeError, - Message: "Dexter: Elixir/OTP version mismatch - your Elixir install for this project was compiled for a newer OTP version than what is running. Update your Erlang to match, or switch to an Elixir build that targets your current OTP (e.g. elixir@...-otp-27).", - }) - }) + s.index.reporter.Set(condOTP+":"+root, notify.Error, fmt.Sprintf("Dexter: Elixir/OTP version mismatch in %s: the Elixir install for this project was compiled for a newer OTP version than the one that runs, so formatting does not work. Update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27).", root)) + return true } // === LSP Lifecycle === @@ -875,15 +900,8 @@ func (s *Server) Initialize(ctx context.Context, params *protocol.InitializePara s.mixBin = mixBin log.Printf("Mix binary at: %s", mixBin) } - } else { - log.Printf("Could not detect Elixir stdlib (set stdlibPath in initializationOptions or DEXTER_ELIXIR_LIB_ROOT)") - if s.client != nil { - _ = s.client.ShowMessage(context.Background(), &protocol.ShowMessageParams{ - Type: protocol.MessageTypeWarning, - Message: "Dexter: could not detect Elixir stdlib - stdlib modules (Enum, String, etc.) won't resolve. Verify the Elixir version in your .tool-versions or mise.toml is installed (e.g. `mise install`), or set DEXTER_ELIXIR_LIB_ROOT.", - }) - } } + s.ReportStdlib() // Fallback: the PATH, then the standard version-manager locations and a // login shell, because an editor-launched process often never ran the mise @@ -895,10 +913,12 @@ func (s *Server) Initialize(ctx context.Context, params *protocol.InitializePara } else if p, ok := stdlib.FindViaLoginShell("mix"); ok { s.mixBin = p log.Printf("Mix binary at: %s (login shell)", p) - } else { - log.Printf("Could not find mix binary — formatting will not work") } } + s.mixMissing = s.mixBin == "" + if s.mixMissing { + log.Printf("Warning: %s", strings.TrimPrefix(mixMissingMessage, "Dexter: ")) + } if !s.initialized && s.manageWorkspace { s.initialized = true @@ -909,6 +929,7 @@ func (s *Server) Initialize(ctx context.Context, params *protocol.InitializePara if params.Capabilities.Window != nil && params.Capabilities.Window.ShowDocument != nil { s.showDocumentSupported = params.Capabilities.Window.ShowDocument.Support } + s.workDoneProgress = params.Capabilities.Window != nil && params.Capabilities.Window.WorkDoneProgress // Resource operations only exist inside documentChanges, so advertising // them implies documentChanges support. Neovim, for one, lists // resourceOperations without setting the separate documentChanges flag. @@ -968,6 +989,20 @@ func (s *Server) Initialize(ctx context.Context, params *protocol.InitializePara } func (s *Server) Initialized(ctx context.Context, params *protocol.InitializedParams) error { + // Workspace reports start now, not in Initialize: before the initialize + // response, a server must not send requests such as + // window/workDoneProgress/create. The reporter replays what started + // earlier, so nothing is lost. + if s.client != nil { + detach := s.index.reporter.Attach(s.client, s.workDoneProgress) + if previous, ok := s.detachReporter.Swap(detach).(func()); ok { + previous() + } + if s.mixMissing { + notify.Show(ctx, s.client, notify.Warning, mixMissingMessage) + } + } + // Registered for daemon-backed sessions too. The workspace's native watcher // deliberately skips deps/ — one watch per dependency directory would cost // thousands of descriptors — while the editor's glob covers it, along with @@ -1005,6 +1040,7 @@ func (s *Server) Shutdown(ctx context.Context) error { // call it even when a client disconnects without the protocol shutdown request. func (s *Server) CloseSession() { s.closeOnce.Do(func() { + s.detachFromReporter() s.closeBeams() s.docs.CloseAll() }) @@ -5930,6 +5966,7 @@ func (s *Server) renameModuleEdits(oldModule, newModule string) (*WorkspaceEdit, movedFiles, clientRenames := mr.moveConventionalFiles(fileCache) openChanges := mr.applyEdits(fileCache, movedFiles) mr.reindex(fileCache, movedFiles, clientRenames) + s.reportRenameFailures(&mr.failures) if len(clientRenames) == 0 { return &WorkspaceEdit{Changes: openChanges}, nil @@ -5988,6 +6025,7 @@ type moduleRename struct { tokenReplacements map[string]string // old token → new token allModuleDefs []store.LookupResult sitesByFile map[string][]moduleEditSite + failures renameFailures // files the rename could not change } type moduleEditSite struct { @@ -6404,15 +6442,18 @@ func (mr *moduleRename) moveConventionalFiles(fileCache map[string]moduleFileInf if err := os.MkdirAll(filepath.Dir(newPath), 0755); err != nil { log.Printf("Rename: cannot create dir for %s: %v", newPath, err) + mr.failures.add(r.FilePath, err) continue } if err := os.WriteFile(newPath, []byte(content), 0644); err != nil { log.Printf("Rename: cannot write %s: %v", newPath, err) + mr.failures.add(r.FilePath, err) continue } if err := os.Remove(r.FilePath); err != nil { log.Printf("Rename: cannot remove %s: %v", r.FilePath, err) + mr.failures.add(r.FilePath, err) } mr.server.debugf("Rename: %s → %s", r.FilePath, newPath) movedFiles[r.FilePath] = newPath @@ -6470,6 +6511,7 @@ func (mr *moduleRename) applyEdits(fileCache map[string]moduleFileInfo, movedFil updatedLines := mr.applyEditsToLines(fi.lines, sites) if err := os.WriteFile(fp, []byte(strings.Join(updatedLines, "\n")), 0644); err != nil { log.Printf("Rename: cannot write %s: %v", fp, err) + mr.failures.add(fp, err) } }() } @@ -6624,6 +6666,7 @@ func (s *Server) buildTextEdits(sites []renameSite, oldToken, newToken string) * var wg sync.WaitGroup var reindexPaths []string var openReindexes []textReindex + var failures renameFailures for fp, fileSites := range sitesByFile { fi, ok := fileCache[fp] @@ -6667,12 +6710,14 @@ func (s *Server) buildTextEdits(sites []renameSite, oldToken, newToken string) * defer wg.Done() if err := os.WriteFile(fp, []byte(strings.Join(updatedLines, "\n")), 0644); err != nil { log.Printf("Rename: cannot write %s: %v", fp, err) + failures.add(fp, err) } }() reindexPaths = append(reindexPaths, fp) } } wg.Wait() + s.reportRenameFailures(&failures) s.reindexAfterRename(nil, reindexPaths, openReindexes) diff --git a/internal/lsptest/client.go b/internal/lsptest/client.go index 5ab1a61..79e242d 100644 --- a/internal/lsptest/client.go +++ b/internal/lsptest/client.go @@ -87,6 +87,13 @@ type Client struct { nextID int opened map[string]bool closed bool + shown []ShownMessage +} + +// ShownMessage is one window/showMessage the server sent. +type ShownMessage struct { + Type int `json:"type"` + Message string `json:"message"` } type message struct { @@ -273,7 +280,17 @@ func (c *Client) Request(method string, params interface{}) (json.RawMessage, er return } if m.ID == nil { - continue // notification from the server + // A notification from the server. Messages for the user are + // kept, so a test can check what an editor would show. + if m.Method == "window/showMessage" { + var shown ShownMessage + if json.Unmarshal(m.Params, &shown) == nil { + c.mu.Lock() + c.shown = append(c.shown, shown) + c.mu.Unlock() + } + } + continue } if string(*m.ID) == wantID { if m.Error != nil { @@ -301,6 +318,35 @@ func (c *Client) Request(method string, params interface{}) (json.RawMessage, er } } +// Shown returns the window/showMessage notifications read so far. The server's +// output is read only while a request waits, so a caller that waits for a +// message sends requests (WaitShown does). +func (c *Client) Shown() []ShownMessage { + c.mu.Lock() + defer c.mu.Unlock() + return append([]ShownMessage(nil), c.shown...) +} + +// WaitShown sends cheap requests until the server has shown a message that +// contains text, and returns it. +func (c *Client) WaitShown(text string, timeout time.Duration) (ShownMessage, error) { + deadline := time.Now().Add(timeout) + for { + for _, m := range c.Shown() { + if strings.Contains(m.Message, text) { + return m, nil + } + } + if time.Now().After(deadline) { + return ShownMessage{}, fmt.Errorf("no message containing %q; shown: %+v", text, c.Shown()) + } + if _, err := c.Request("workspace/symbol", map[string]interface{}{"query": "\x00"}); err != nil { + return ShownMessage{}, err + } + time.Sleep(10 * time.Millisecond) + } +} + // Notify sends a notification, for which no reply is expected. func (c *Client) Notify(method string, params interface{}) error { return c.write(map[string]interface{}{"jsonrpc": "2.0", "method": method, "params": params}) diff --git a/internal/notify/notify.go b/internal/notify/notify.go new file mode 100644 index 0000000..fdbef48 --- /dev/null +++ b/internal/notify/notify.go @@ -0,0 +1,504 @@ +// Package notify is the one path by which Dexter tells the user that it does +// not work, that it works with less, or that it does long work. +// +// A Reporter writes each report to the log, as before, and also sends it to +// every attached editor: failures and degraded states as window/showMessage, +// long work as LSP work-done progress. The workspace daemon serves several +// editors, so the Reporter keeps the conditions that are active now and the +// work that is in progress, and it replays them to an editor that attaches +// later. +// +// Reports are made only when a state changes. Nothing here is on a request +// path, and delivery never blocks the caller: each editor has its own queue +// and its own goroutine. +package notify + +import ( + "context" + "fmt" + "log" + "sort" + "strings" + "sync" + "time" + + "go.lsp.dev/protocol" +) + +// Severity is how bad a condition is for the user. +type Severity int + +const ( + // Info is a normal state change, for example "the index is built". + Info Severity = iota + 1 + // Warning is a degraded state: Dexter works, but with less. + Warning + // Error is a state in which Dexter does not work. + Error +) + +func (s Severity) String() string { + switch s { + case Error: + return "error" + case Warning: + return "warning" + default: + return "info" + } +} + +func (s Severity) messageType() protocol.MessageType { + switch s { + case Error: + return protocol.MessageTypeError + case Warning: + return protocol.MessageTypeWarning + default: + return protocol.MessageTypeInfo + } +} + +func (s Severity) logPrefix() string { + switch s { + case Error: + return "Error: " + case Warning: + return "Warning: " + default: + return "" + } +} + +// Condition is one active state that the user must know about. +type Condition struct { + Key string + Severity Severity + Message string +} + +// deliveryTimeout bounds one request to an editor, such as +// window/workDoneProgress/create. An editor that does not answer must not stop +// the queue for ever. +const deliveryTimeout = 5 * time.Second + +// maxQueue is the number of undelivered reports one editor can have. Reports +// are made only on state changes, so a full queue means that the editor does +// not read; progress reports are then dropped first. +const maxQueue = 256 + +// Reporter holds the active conditions and the work in progress for one +// workspace, and the editors attached to it. A nil Reporter discards reports, +// so code that has none needs no checks. +type Reporter struct { + mu sync.Mutex + logf func(format string, args ...any) + seq uint64 + conds map[string]*entry + tasks map[string]*Task + sinks map[*sink]struct{} +} + +type entry struct { + Condition + seq uint64 +} + +// New returns a Reporter that logs through the standard logger. +func New() *Reporter { + return &Reporter{ + logf: log.Printf, + conds: make(map[string]*entry), + tasks: make(map[string]*Task), + sinks: make(map[*sink]struct{}), + } +} + +// SetLogf replaces the log function. Tests use it to keep their output quiet or +// to record what is logged. +func (r *Reporter) SetLogf(logf func(format string, args ...any)) { + if r == nil { + return + } + r.mu.Lock() + r.logf = logf + r.mu.Unlock() +} + +func (r *Reporter) log(sev Severity, message string) { + r.logLine("%s%s", sev.logPrefix(), strings.TrimPrefix(message, "Dexter: ")) +} + +func (r *Reporter) logLine(format string, args ...any) { + if r.logf != nil { + r.logf(format, args...) + } +} + +// Set makes a condition active, logs it, and shows it in every attached editor. +// A condition that is already active with the same severity only takes the new +// message, which later editors see: this keeps a count that changes from +// sending a message each time. +func (r *Reporter) Set(key string, sev Severity, message string) { + if r == nil { + return + } + r.mu.Lock() + defer r.mu.Unlock() + if existing, ok := r.conds[key]; ok && existing.Severity == sev { + existing.Message = message + return + } + r.seq++ + r.conds[key] = &entry{Condition: Condition{Key: key, Severity: sev, Message: message}, seq: r.seq} + r.log(sev, message) + r.broadcast(op{kind: opShow, sev: sev, message: message}) +} + +// Clear ends an active condition. A message that is not empty tells the user +// that the condition stopped; it is logged and shown as Info. Clear reports +// whether the condition was active. +func (r *Reporter) Clear(key, message string) bool { + if r == nil { + return false + } + r.mu.Lock() + defer r.mu.Unlock() + if _, ok := r.conds[key]; !ok { + return false + } + delete(r.conds, key) + if message != "" { + r.log(Info, message) + r.broadcast(op{kind: opShow, sev: Info, message: message}) + } + return true +} + +// Active reports whether a condition is active. +func (r *Reporter) Active(key string) bool { + if r == nil { + return false + } + r.mu.Lock() + defer r.mu.Unlock() + _, ok := r.conds[key] + return ok +} + +// Notify logs one event and shows it in every attached editor. It is not kept, +// so an editor that attaches later does not see it. Use Set for a state that +// continues. +func (r *Reporter) Notify(sev Severity, message string) { + if r == nil { + return + } + r.mu.Lock() + defer r.mu.Unlock() + r.log(sev, message) + r.broadcast(op{kind: opShow, sev: sev, message: message}) +} + +// Conditions returns the active conditions, oldest first. +func (r *Reporter) Conditions() []Condition { + if r == nil { + return nil + } + r.mu.Lock() + defer r.mu.Unlock() + entries := make([]*entry, 0, len(r.conds)) + for _, e := range r.conds { + entries = append(entries, e) + } + sort.Slice(entries, func(i, j int) bool { return entries[i].seq < entries[j].seq }) + out := make([]Condition, len(entries)) + for i, e := range entries { + out[i] = e.Condition + } + return out +} + +// Task is one piece of long work, shown as LSP work-done progress. +type Task struct { + r *Reporter + key string + token string + title string + message string + percent int + fallback bool + ended bool + seq uint64 +} + +// Begin starts long work and shows it in every attached editor that supports +// work-done progress. When fallback is true, an editor without that support +// gets a window/showMessage at the start and at the end instead; pass false when +// a condition already tells the user about the same work. A second Begin with a +// key that is in progress returns the task that is in progress. Progress is not +// logged: the caller logs the outcome, or a condition does. +func (r *Reporter) Begin(key, title, message string, fallback bool) *Task { + if r == nil { + return nil + } + r.mu.Lock() + defer r.mu.Unlock() + if t, ok := r.tasks[key]; ok { + return t + } + r.seq++ + t := &Task{ + r: r, + key: key, + token: fmt.Sprintf("dexter/%s/%d", key, r.seq), + title: title, + message: message, + percent: -1, + fallback: fallback, + seq: r.seq, + } + r.tasks[key] = t + r.broadcast(t.beginOp()) + return t +} + +func (t *Task) beginOp() op { + return op{kind: opBegin, token: t.token, title: t.title, message: t.message, percent: t.percent, fallback: t.fallback} +} + +// Report updates the message and, when percent is 0 to 100, the percentage of +// the work. Callers report at most a few times a second. +func (t *Task) Report(message string, percent int) { + if t == nil { + return + } + r := t.r + r.mu.Lock() + defer r.mu.Unlock() + if t.ended || (message == t.message && percent == t.percent) { + return + } + t.message = message + t.percent = percent + r.broadcast(op{kind: opReport, token: t.token, message: message, percent: percent}) +} + +// End finishes the work. The message tells the outcome. +func (t *Task) End(message string) { + if t == nil { + return + } + r := t.r + r.mu.Lock() + defer r.mu.Unlock() + if t.ended { + return + } + t.ended = true + delete(r.tasks, t.key) + r.broadcast(op{kind: opEnd, token: t.token, message: message, fallback: t.fallback}) +} + +// broadcast queues one op on every sink. The caller holds r.mu, which keeps the +// order of ops the same in every editor and keeps a replay in step with them. +func (r *Reporter) broadcast(o op) { + for s := range r.sinks { + s.enqueue(o) + } +} + +// Attach sends the active conditions and the work in progress to client, then +// sends every later report to it until detach is called. progress tells +// whether the client supports work-done progress (the window.workDoneProgress +// client capability). Call Attach only after the client sent `initialized`. +func (r *Reporter) Attach(client protocol.Client, progress bool) (detach func()) { + if r == nil || client == nil { + return func() {} + } + s := &sink{ + client: client, + progress: progress, + wake: make(chan struct{}, 1), + stop: make(chan struct{}), + created: make(map[string]bool), + } + r.mu.Lock() + entries := make([]*entry, 0, len(r.conds)) + for _, e := range r.conds { + entries = append(entries, e) + } + sort.Slice(entries, func(i, j int) bool { return entries[i].seq < entries[j].seq }) + for _, e := range entries { + s.enqueue(op{kind: opShow, sev: e.Severity, message: e.Message}) + } + tasks := make([]*Task, 0, len(r.tasks)) + for _, t := range r.tasks { + tasks = append(tasks, t) + } + sort.Slice(tasks, func(i, j int) bool { return tasks[i].seq < tasks[j].seq }) + for _, t := range tasks { + s.enqueue(t.beginOp()) + } + r.sinks[s] = struct{}{} + r.mu.Unlock() + + go s.run() + var once sync.Once + return func() { + once.Do(func() { + r.mu.Lock() + delete(r.sinks, s) + r.mu.Unlock() + close(s.stop) + }) + } +} + +type opKind uint8 + +const ( + opShow opKind = iota + opBegin + opReport + opEnd +) + +type op struct { + kind opKind + sev Severity + message string + token string + title string + percent int + fallback bool +} + +// sink delivers reports to one editor in order. +type sink struct { + client protocol.Client + progress bool + + mu sync.Mutex + queue []op + wake chan struct{} + stop chan struct{} + + created map[string]bool // tokens the editor accepted; only run uses it +} + +func (s *sink) enqueue(o op) { + s.mu.Lock() + if len(s.queue) >= maxQueue && o.kind == opReport { + s.mu.Unlock() + return + } + s.queue = append(s.queue, o) + s.mu.Unlock() + select { + case s.wake <- struct{}{}: + default: + } +} + +func (s *sink) run() { + for { + select { + case <-s.stop: + return + case <-s.wake: + } + for { + s.mu.Lock() + if len(s.queue) == 0 { + s.mu.Unlock() + break + } + batch := s.queue + s.queue = nil + s.mu.Unlock() + for _, o := range batch { + select { + case <-s.stop: + return + default: + } + s.deliver(o) + } + } + } +} + +func (s *sink) deliver(o op) { + ctx, cancel := context.WithTimeout(context.Background(), deliveryTimeout) + defer cancel() + switch o.kind { + case opShow: + Show(ctx, s.client, o.sev, o.message) + case opBegin: + if s.progress { + token := protocol.NewProgressToken(o.token) + if err := s.client.WorkDoneProgressCreate(ctx, &protocol.WorkDoneProgressCreateParams{Token: *token}); err == nil { + s.created[o.token] = true + begin := protocol.WorkDoneProgressBegin{Kind: protocol.WorkDoneProgressKindBegin, Title: o.title, Message: o.message} + if o.percent >= 0 { + begin.Percentage = uint32(o.percent) + } + _ = s.client.Progress(ctx, &protocol.ProgressParams{Token: *token, Value: begin}) + return + } + } + if o.fallback { + text := o.title + if o.message != "" { + text += ": " + o.message + } + Show(ctx, s.client, Info, text) + } + case opReport: + if !s.created[o.token] { + return + } + report := protocol.WorkDoneProgressReport{Kind: protocol.WorkDoneProgressKindReport, Message: o.message} + if o.percent >= 0 { + report.Percentage = uint32(o.percent) + } + _ = s.client.Progress(ctx, &protocol.ProgressParams{Token: *protocol.NewProgressToken(o.token), Value: report}) + case opEnd: + if s.created[o.token] { + delete(s.created, o.token) + _ = s.client.Progress(ctx, &protocol.ProgressParams{ + Token: *protocol.NewProgressToken(o.token), + Value: protocol.WorkDoneProgressEnd{Kind: protocol.WorkDoneProgressKindEnd, Message: o.message}, + }) + return + } + if o.fallback && o.message != "" { + Show(ctx, s.client, Info, o.message) + } + } +} + +// Show sends one window/showMessage to one client. Use it only for a report +// that concerns that one editor, for example the result of its own request; +// workspace states go through a Reporter. +func Show(ctx context.Context, client protocol.Client, sev Severity, message string) { + if client == nil { + return + } + if err := client.ShowMessage(ctx, &protocol.ShowMessageParams{Type: sev.messageType(), Message: message}); err != nil { + log.Printf("ShowMessage: %v", err) + } +} + +// Summarize writes a list of paths the way a message to the user needs it: +// the first path and how many more there are. +func Summarize(paths []string) string { + switch len(paths) { + case 0: + return "" + case 1: + return paths[0] + default: + return fmt.Sprintf("%s and %d more", paths[0], len(paths)-1) + } +} diff --git a/internal/notify/notify_test.go b/internal/notify/notify_test.go new file mode 100644 index 0000000..d128ace --- /dev/null +++ b/internal/notify/notify_test.go @@ -0,0 +1,200 @@ +package notify_test + +import ( + "fmt" + "strings" + "sync" + "testing" + "time" + + "go.lsp.dev/protocol" + + "github.com/remoteoss/dexter/internal/notify" + "github.com/remoteoss/dexter/internal/notify/notifytest" +) + +const wait = 5 * time.Second + +func quiet(r *notify.Reporter) *notify.Reporter { + r.SetLogf(func(string, ...any) {}) + return r +} + +func TestSetShowsOnceAndLogs(t *testing.T) { + r := notify.New() + var mu sync.Mutex + var logged []string + r.SetLogf(func(format string, args ...any) { + mu.Lock() + defer mu.Unlock() + logged = append(logged, strings.TrimSpace(sprintf(format, args...))) + }) + client := notifytest.New() + detach := r.Attach(client, false) + defer detach() + + r.Set("index.rebuild", notify.Warning, "Dexter: rebuilding (1 file)") + // The same severity again only updates the text: no second message. + r.Set("index.rebuild", notify.Warning, "Dexter: rebuilding (2 files)") + r.Set("index.unavailable", notify.Error, "Dexter: the index is broken") + + client.WaitMessage(t, wait, protocol.MessageTypeError, "the index is broken") + messages := client.Messages() + if len(messages) != 2 { + t.Fatalf("got %d messages, want 2:\n%s", len(messages), client.Dump()) + } + if messages[0].Type != protocol.MessageTypeWarning || messages[0].Message != "Dexter: rebuilding (1 file)" { + t.Fatalf("first message = %v", messages[0]) + } + mu.Lock() + defer mu.Unlock() + if len(logged) != 2 || logged[0] != "Warning: rebuilding (1 file)" || logged[1] != "Error: the index is broken" { + t.Fatalf("log = %q", logged) + } +} + +func TestClearSaysThatTheConditionStopped(t *testing.T) { + r := quiet(notify.New()) + client := notifytest.New() + defer r.Attach(client, false)() + + if r.Clear("watcher", "Dexter: watching again") { + t.Fatal("Clear of a condition that is not active reported true") + } + r.Set("watcher", notify.Warning, "Dexter: cannot watch") + if !r.Clear("watcher", "Dexter: watching again") { + t.Fatal("Clear of an active condition reported false") + } + client.WaitMessage(t, wait, protocol.MessageTypeInfo, "watching again") + if r.Active("watcher") || len(r.Conditions()) != 0 { + t.Fatalf("condition is still active: %+v", r.Conditions()) + } + if n := len(client.Messages()); n != 2 { + t.Fatalf("got %d messages, want 2:\n%s", n, client.Dump()) + } +} + +// An editor that attaches after a condition started still has to learn about +// it, and about work that is in progress. +func TestAttachReplaysConditionsAndWorkInProgress(t *testing.T) { + r := quiet(notify.New()) + r.Set("root", notify.Warning, "Dexter: not a project") + r.Set("index.rebuild", notify.Warning, "Dexter: rebuilding") + r.Set("gone", notify.Warning, "Dexter: gone") + r.Clear("gone", "") + task := r.Begin("index.build", "Dexter: indexing", "12 files", false) + + late := notifytest.New() + defer r.Attach(late, true)() + late.WaitFor(t, wait, "replayed progress begin", func(e notifytest.Event) bool { + return e.Method == protocol.MethodProgress && e.Kind == "begin" && e.Title == "Dexter: indexing" && e.Message == "12 files" + }) + messages := late.Messages() + if len(messages) != 2 || messages[0].Message != "Dexter: not a project" || messages[1].Message != "Dexter: rebuilding" { + t.Fatalf("replayed messages in the wrong order or count:\n%s", late.Dump()) + } + + task.Report("40 files", -1) + task.End("Dexter: indexed 40 files") + late.WaitFor(t, wait, "progress end", func(e notifytest.Event) bool { + return e.Method == protocol.MethodProgress && e.Kind == "end" && e.Message == "Dexter: indexed 40 files" + }) + events := late.Events() + var kinds []string + for _, e := range events { + if e.Method == protocol.MethodProgress { + kinds = append(kinds, e.Kind) + } + if e.Method == protocol.MethodWorkDoneProgressCreate && e.Token == "" { + t.Fatal("progress token is empty") + } + } + if strings.Join(kinds, ",") != "begin,report,end" { + t.Fatalf("progress kinds = %v:\n%s", kinds, late.Dump()) + } + + // Ended work is not replayed. + later := notifytest.New() + defer r.Attach(later, true)() + later.WaitMessage(t, wait, protocol.MessageTypeWarning, "rebuilding") + time.Sleep(20 * time.Millisecond) + for _, e := range later.Events() { + if e.Method != protocol.MethodWindowShowMessage { + t.Fatalf("ended work was replayed:\n%s", later.Dump()) + } + } +} + +// A client without work-done progress gets a message at the start and at the +// end, but only when the work asks for that fallback. +func TestProgressFallsBackToMessages(t *testing.T) { + r := quiet(notify.New()) + plain := notifytest.New() + defer r.Attach(plain, false)() + refusing := notifytest.New() + refusing.RefuseProgress = true + defer r.Attach(refusing, true)() + + task := r.Begin("index.reconcile", "Dexter: updating the index", "1000 changed files", true) + task.Report("2000 changed files", -1) + task.End("Dexter: updated 2400 files in 3s") + silent := r.Begin("index.build", "Dexter: indexing", "", false) + silent.End("Dexter: built") + + for _, client := range []*notifytest.Client{plain, refusing} { + client.WaitMessage(t, wait, protocol.MessageTypeInfo, "updated 2400 files") + messages := client.Messages() + if len(messages) != 2 || messages[0].Message != "Dexter: updating the index: 1000 changed files" { + t.Fatalf("fallback messages:\n%s", client.Dump()) + } + for _, e := range client.Events() { + if e.Method == protocol.MethodProgress { + t.Fatalf("progress sent to a client that cannot show it:\n%s", client.Dump()) + } + } + } +} + +func TestNilReporterIsSafe(t *testing.T) { + var r *notify.Reporter + r.Set("a", notify.Error, "x") + r.Clear("a", "y") + r.Notify(notify.Info, "z") + task := r.Begin("b", "t", "m", true) + task.Report("m", 1) + task.End("e") + r.Attach(notifytest.New(), true)() + if r.Active("a") || r.Conditions() != nil { + t.Fatal("nil reporter kept state") + } +} + +func TestDetachStopsDelivery(t *testing.T) { + r := quiet(notify.New()) + client := notifytest.New() + detach := r.Attach(client, false) + r.Notify(notify.Warning, "Dexter: first") + client.WaitMessage(t, wait, protocol.MessageTypeWarning, "first") + detach() + detach() + r.Notify(notify.Warning, "Dexter: second") + time.Sleep(20 * time.Millisecond) + if n := len(client.Messages()); n != 1 { + t.Fatalf("detached client received %d messages", n) + } +} + +func TestSummarize(t *testing.T) { + cases := map[string][]string{ + "": nil, + "/a.ex": {"/a.ex"}, + "/a.ex and 2 more": {"/a.ex", "/b.ex", "/c.ex"}, + } + for want, paths := range cases { + if got := notify.Summarize(paths); got != want { + t.Errorf("Summarize(%v) = %q, want %q", paths, got, want) + } + } +} + +func sprintf(format string, args ...any) string { return fmt.Sprintf(format, args...) } diff --git a/internal/notify/notifytest/client.go b/internal/notify/notifytest/client.go new file mode 100644 index 0000000..efaf1d7 --- /dev/null +++ b/internal/notify/notifytest/client.go @@ -0,0 +1,163 @@ +// Package notifytest has a fake LSP client that records what Dexter shows to +// the user, for tests of the notify path. +package notifytest + +import ( + "context" + "encoding/json" + "fmt" + "strings" + "sync" + "testing" + "time" + + "go.lsp.dev/protocol" +) + +// Event is one thing the fake client received. +type Event struct { + // Method is window/showMessage, window/workDoneProgress/create, or + // $/progress. + Method string + // Type is the showMessage type. + Type protocol.MessageType + // Kind is the progress kind: begin, report, or end. + Kind string + // Token is the progress token. + Token string + // Title is the progress title of a begin. + Title string + // Message is the showMessage text or the progress message. + Message string +} + +func (e Event) String() string { + switch e.Method { + case protocol.MethodWindowShowMessage: + return fmt.Sprintf("showMessage(%s): %s", e.Type, e.Message) + case protocol.MethodProgress: + return fmt.Sprintf("progress %s %s: %s %s", e.Kind, e.Token, e.Title, e.Message) + default: + return fmt.Sprintf("%s %s", e.Method, e.Token) + } +} + +// Client records showMessage, workDoneProgress/create, and $/progress. Other +// methods panic through the nil embedded interface, so a test finds out when +// Dexter sends something it did not expect. +type Client struct { + protocol.Client + + // RefuseProgress makes window/workDoneProgress/create fail, as an editor + // can do. + RefuseProgress bool + + mu sync.Mutex + events []Event + signal chan struct{} +} + +// New returns an empty recording client. +func New() *Client { return &Client{signal: make(chan struct{}, 1)} } + +func (c *Client) record(e Event) { + c.mu.Lock() + c.events = append(c.events, e) + c.mu.Unlock() + select { + case c.signal <- struct{}{}: + default: + } +} + +func (c *Client) ShowMessage(_ context.Context, params *protocol.ShowMessageParams) error { + c.record(Event{Method: protocol.MethodWindowShowMessage, Type: params.Type, Message: params.Message}) + return nil +} + +func (c *Client) LogMessage(context.Context, *protocol.LogMessageParams) error { return nil } + +func (c *Client) WorkDoneProgressCreate(_ context.Context, params *protocol.WorkDoneProgressCreateParams) error { + c.record(Event{Method: protocol.MethodWorkDoneProgressCreate, Token: params.Token.String()}) + if c.RefuseProgress { + return fmt.Errorf("progress refused") + } + return nil +} + +func (c *Client) Progress(_ context.Context, params *protocol.ProgressParams) error { + raw, err := json.Marshal(params.Value) + if err != nil { + return err + } + var value struct { + Kind string `json:"kind"` + Title string `json:"title"` + Message string `json:"message"` + } + if err := json.Unmarshal(raw, &value); err != nil { + return err + } + c.record(Event{Method: protocol.MethodProgress, Token: params.Token.String(), Kind: value.Kind, Title: value.Title, Message: value.Message}) + return nil +} + +func (c *Client) RegisterCapability(context.Context, *protocol.RegistrationParams) error { return nil } + +// Events returns a copy of what was received so far. +func (c *Client) Events() []Event { + c.mu.Lock() + defer c.mu.Unlock() + return append([]Event(nil), c.events...) +} + +// Messages returns the showMessage events. +func (c *Client) Messages() []Event { + var out []Event + for _, e := range c.Events() { + if e.Method == protocol.MethodWindowShowMessage { + out = append(out, e) + } + } + return out +} + +// WaitFor waits until match accepts one event and returns it. It fails the +// test after timeout and lists what arrived. +func (c *Client) WaitFor(t testing.TB, timeout time.Duration, what string, match func(Event) bool) Event { + t.Helper() + deadline := time.After(timeout) + for { + for _, e := range c.Events() { + if match(e) { + return e + } + } + select { + case <-c.signal: + case <-time.After(10 * time.Millisecond): + case <-deadline: + t.Fatalf("no %s; received:\n%s", what, c.Dump()) + return Event{} + } + } +} + +// WaitMessage waits for a showMessage of the given type that contains text. +func (c *Client) WaitMessage(t testing.TB, timeout time.Duration, typ protocol.MessageType, text string) Event { + t.Helper() + return c.WaitFor(t, timeout, fmt.Sprintf("showMessage(%s) containing %q", typ, text), func(e Event) bool { + return e.Method == protocol.MethodWindowShowMessage && e.Type == typ && strings.Contains(e.Message, text) + }) +} + +// Dump lists every event, one on each line. +func (c *Client) Dump() string { + var b strings.Builder + for _, e := range c.Events() { + b.WriteString(" ") + b.WriteString(e.String()) + b.WriteByte('\n') + } + return b.String() +} diff --git a/internal/store/openerr.go b/internal/store/openerr.go new file mode 100644 index 0000000..e7b8348 --- /dev/null +++ b/internal/store/openerr.go @@ -0,0 +1,40 @@ +package store + +import ( + "errors" + + sqlite3 "github.com/mattn/go-sqlite3" +) + +// OpenFailure is the kind of an error from Open. The kind decides what the +// caller may do with the database files. +type OpenFailure int + +const ( + // OpenFailureOther is a failure that does not come from the database + // file itself: permissions, a full disk, too many open files, a directory + // that cannot be made. Deleting the index does not fix it, and it can + // destroy an index that is good. + OpenFailureOther OpenFailure = iota + // OpenFailureDamaged is a file that is not a database or is malformed. + // The index is a derived cache, so deleting it and rebuilding is safe. + OpenFailureDamaged + // OpenFailureBusy is a database that another connection holds locked. + // That process can still be writing it: deleting the files then loses + // its work in silence. + OpenFailureBusy +) + +// ClassifyOpenError tells which kind of failure an error from Open is. +func ClassifyOpenError(err error) OpenFailure { + var se sqlite3.Error + if errors.As(err, &se) { + switch se.Code { + case sqlite3.ErrCorrupt, sqlite3.ErrNotADB: + return OpenFailureDamaged + case sqlite3.ErrBusy, sqlite3.ErrLocked: + return OpenFailureBusy + } + } + return OpenFailureOther +} diff --git a/internal/store/project.go b/internal/store/project.go new file mode 100644 index 0000000..a02aaf4 --- /dev/null +++ b/internal/store/project.go @@ -0,0 +1,49 @@ +package store + +import ( + "os" + "path/filepath" +) + +// LooksLikeProject reports whether dir shows the cheap signs of a Dexter +// workspace: a mix.exs, a .git, or a Dexter database. They match what +// FindProjectRoot trusts, and a Dexter marker means an actual database, not an +// empty directory left by an interrupted operation. +func LooksLikeProject(dir string) bool { + return regularFile(filepath.Join(dir, "mix.exs")) || + gitMarker(filepath.Join(dir, ".git")) || + HasIndex(dir) +} + +// HasIndex reports whether dir holds a Dexter database. +func HasIndex(dir string) bool { + return regularFile(DBPath(dir)) || regularFile(LegacyDBPath(dir)) +} + +// IsHomeDir reports whether dir is the user's home directory. +func IsHomeDir(dir string) bool { + home, err := os.UserHomeDir() + return err == nil && SameDir(dir, home) +} + +// SameDir reports whether two paths name the same directory. Stat is the +// authority so a symlinked spelling (or a case-insensitive filesystem) cannot +// sneak a home directory past a check. +func SameDir(a, b string) bool { + ai, aErr := os.Stat(a) + bi, bErr := os.Stat(b) + if aErr != nil || bErr != nil { + return filepath.Clean(a) == filepath.Clean(b) + } + return os.SameFile(ai, bi) +} + +func regularFile(path string) bool { + info, err := os.Stat(path) + return err == nil && info.Mode().IsRegular() +} + +func gitMarker(path string) bool { + info, err := os.Stat(path) + return err == nil && (info.IsDir() || info.Mode().IsRegular()) +} diff --git a/internal/workspace/report.go b/internal/workspace/report.go new file mode 100644 index 0000000..3c77340 --- /dev/null +++ b/internal/workspace/report.go @@ -0,0 +1,132 @@ +package workspace + +import ( + "fmt" + + "github.com/remoteoss/dexter/internal/notify" + "github.com/remoteoss/dexter/internal/store" +) + +// Condition keys of the workspace runtime. The index keys are in package lsp, +// which also clears them. +const ( + condRoot = "root" + condWatch = "watcher" + condWatchCoverage = "watcher.coverage" + condWatchFallback = "watcher.fallback" +) + +// reportRoot warns when the workspace root does not look like a project. An +// editor decides what it opens, so Dexter serves the directory anyway; the +// warning is shown in every editor that attaches, because each of them pays for +// the index. +func reportRoot(root string, reporter *notify.Reporter) { + if store.IsHomeDir(root) { + if store.HasIndex(root) { + return + } + reporter.Set(condRoot, notify.Warning, fmt.Sprintf( + "Dexter: %s is your home directory, not a project, but the editor opened it as the workspace. Dexter indexes it anyway, which can take a long time. Open the project directory instead, or set --root in the dexter command of the editor.", root)) + return + } + if store.LooksLikeProject(root) { + return + } + reporter.Set(condRoot, notify.Warning, fmt.Sprintf( + "Dexter: %s does not look like an Elixir project (no mix.exs, .git, or Dexter database). Dexter indexes it anyway. If it is the wrong directory, open the project directory instead, or set --root in the dexter command of the editor.", root)) +} + +// damagedIndexMessage explains an index that was damaged and was deleted for +// a rebuild. +func damagedIndexMessage(root string, err error) string { + return fmt.Sprintf( + "Dexter: the index at %s is damaged (%v). Dexter deleted it and is rebuilding it now; navigation is limited until the rebuild ends.", + store.DBPath(root), err) +} + +// lockedIndexMessage explains an index that another process kept locked. +func lockedIndexMessage(root string, err error) string { + return fmt.Sprintf( + "Dexter: another process holds the index at %s locked (%v), so Dexter cannot open it. Dexter did not change the index. If `dexter init` runs for this project, wait until it ends; otherwise stop the other Dexter process (`dexter stop --force` in the project directory, or close the editor that runs a different Dexter build). Then restart this editor.", + store.DBPath(root), err) +} + +// otherOpenFailureMessage explains an index that could not be opened for a +// cause that a rebuild does not fix, such as permissions or a full disk. +func otherOpenFailureMessage(root string, err error) string { + return fmt.Sprintf( + "Dexter: the index at %s could not be opened (%v). Dexter did not delete it, because the cause is not a damaged index. Fix the cause (for example the file permissions of %s, free disk space, or the limit of open files), then restart this editor. To start again with an empty index, delete %s.", + store.DBPath(root), err, store.DBDir(root), store.DBDir(root)) +} + +// versionMismatchMessage explains an index that was written by another index +// version and must be rebuilt. +func versionMismatchMessage(stored, current int) string { + switch { + case stored == 0: + return "Dexter: the index has no version, so the build that wrote it did not finish. Rebuilding it now; navigation is limited until the rebuild ends." + case stored > current: + return fmt.Sprintf( + "Dexter: the index was written by a newer Dexter build (index version %d; this build uses %d). Rebuilding it now; navigation is limited until the rebuild ends. To avoid this, run the same Dexter build in every editor and terminal for this project.", + stored, current) + default: + return fmt.Sprintf( + "Dexter: the index was written by an older Dexter build (index version %d; this build uses %d). Rebuilding it now; navigation is limited until the rebuild ends. This occurs one time after an upgrade.", + stored, current) + } +} + +// reportWatchUnavailable tells the user that native file watching does not +// work. The runtime retries; a retry that fails again sends nothing new. +func (r *Runtime) reportWatchUnavailable(err error) { + r.Reporter().Set(condWatch, notify.Warning, fmt.Sprintf( + "Dexter: cannot watch the files of %s (%v). Changes made outside the editor (git checkout, code generators, other editors) are not indexed until Dexter can watch again; Dexter tries again every %s. Files that you save in the editor are still indexed.", + r.root, err, watchRetryInterval)) +} + +// reportWatcherStarted ends an unavailable-watcher condition and reports what +// the new watcher cannot do. +func (r *Runtime) reportWatcherStarted(w *Watcher) { + reporter := r.Reporter() + reporter.Clear(condWatch, fmt.Sprintf( + "Dexter: file watching works again for %s; Dexter is checking the files that changed in the meantime.", r.root)) + if err := w.Fallback(); err != nil { + reporter.Set(condWatchFallback, notify.Warning, fmt.Sprintf( + "Dexter: the native file watcher is not available for %s (%v), so Dexter watches each directory on its own. This uses one file descriptor for each directory; in a very large project, some directories can stay unwatched, and Dexter tells you if that occurs.", + r.root, err)) + } + r.reportCoverage() +} + +// reportCoverage tells the user when directories cannot be watched, and when +// the watcher covers the whole project again. It reads the state of the +// watcher itself, under coverageMu, and does not trust a value that a caller +// read before: the watcher can restore its last directory between that read +// and the report, and its own report could then come first and leave a warning +// that never ends. Each call reports the state at that time, so the last call +// is always right. +func (r *Runtime) reportCoverage() { + r.coverageMu.Lock() + defer r.coverageMu.Unlock() + r.watcherMu.RLock() + w := r.watcher + r.watcherMu.RUnlock() + if w == nil { + return // reportWatcherStarted reports when the watcher is in place + } + reporter := r.Reporter() + if !w.Degraded() { + reporter.Clear(condWatchCoverage, "Dexter: file watching covers the whole project again; Dexter is checking the files that changed in the meantime.") + return + } + failed := w.FailedDirectories() + what := "Some directories" + if len(failed) == 1 { + what = fmt.Sprintf("1 directory (%s)", failed[0]) + } else if len(failed) > 1 { + what = fmt.Sprintf("%d directories (%s)", len(failed), notify.Summarize(failed)) + } + reporter.Set(condWatchCoverage, notify.Warning, fmt.Sprintf( + "Dexter: %s under %s cannot be watched, often because of the file watch limit of the system; see the log for the error. Changes in them made outside the editor are not indexed until Dexter can watch them; Dexter tries again every %s.", + what, r.root, watchRetryInterval)) +} diff --git a/internal/workspace/report_test.go b/internal/workspace/report_test.go new file mode 100644 index 0000000..3ac6004 --- /dev/null +++ b/internal/workspace/report_test.go @@ -0,0 +1,422 @@ +package workspace + +import ( + "context" + "database/sql" + "errors" + "fmt" + "os" + "path/filepath" + "strings" + "sync" + "sync/atomic" + "syscall" + "testing" + "time" + + "go.lsp.dev/protocol" + + "github.com/remoteoss/dexter/internal/lsp" + "github.com/remoteoss/dexter/internal/notify" + "github.com/remoteoss/dexter/internal/notify/notifytest" + "github.com/remoteoss/dexter/internal/parser" + "github.com/remoteoss/dexter/internal/store" + "github.com/remoteoss/dexter/internal/version" +) + +const reportWait = 10 * time.Second + +func quietReportEnv(t *testing.T) { + t.Helper() + t.Setenv("PATH", t.TempDir()) + t.Setenv("SHELL", "/bin/false") +} + +// writeStaleIndex leaves an index with one file in it, stamped with another +// index version. +func writeStaleIndex(t *testing.T, root string, indexVersion int) { + t.Helper() + path := writeTestModule(t, root, "lib/old.ex", "SharedLib.Old") + s, err := store.Open(root) + if err != nil { + t.Fatal(err) + } + defs, refs, err := parser.ParseFile(path) + if err != nil { + t.Fatal(err) + } + if err := s.IndexFileWithRefs(path, defs, refs); err != nil { + t.Fatal(err) + } + if err := s.SetIndexVersion(indexVersion); err != nil { + t.Fatal(err) + } + if err := s.Close(); err != nil { + t.Fatal(err) + } +} + +// openHeld opens a runtime and holds it before its first reconciliation until +// the returned release runs. +func openHeld(t *testing.T, root string) (*Runtime, func()) { + t.Helper() + hold := make(chan struct{}) + var once atomic.Bool + release := func() { + if once.CompareAndSwap(false, true) { + close(hold) + } + } + rt, err := OpenWithOptions(root, Options{NoWatch: true, BeforeInitialReconcile: func() { <-hold }}) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { + release() + _ = rt.Close() + }) + return rt, release +} + +// The incident this guards: an index written by a newer build was rebuilt for +// minutes, and the editor showed nothing. +func TestNewerIndexVersionIsShownUntilTheRebuildEnds(t *testing.T) { + quietReportEnv(t) + root := t.TempDir() + writeTestModule(t, root, "mix.exs", "SharedLib.MixProject") + writeStaleIndex(t, root, version.IndexVersion+1) + + rt, release := openHeld(t, root) + client := notifytest.New() + defer rt.Reporter().Attach(client, false)() + + want := fmt.Sprintf("Dexter: the index was written by a newer Dexter build (index version %d; this build uses %d). Rebuilding it now; navigation is limited until the rebuild ends. To avoid this, run the same Dexter build in every editor and terminal for this project.", + version.IndexVersion+1, version.IndexVersion) + got := client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "written by a newer Dexter build") + if got.Message != want { + t.Errorf("message =\n %q\nwant\n %q", got.Message, want) + } + conditions := rt.IndexConditions() + if len(conditions) != 1 || conditions[0].Key != lsp.CondIndexRebuild { + t.Fatalf("index conditions during the rebuild = %+v", conditions) + } + + release() + if err := rt.WaitReady(testContext(t, 30*time.Second)); err != nil { + t.Fatal(err) + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: the index rebuild is complete (") + if conditions := rt.IndexConditions(); len(conditions) != 0 { + t.Errorf("index conditions after the rebuild = %+v", conditions) + } +} + +func TestIndexThatCannotBeOpenedIsShown(t *testing.T) { + quietReportEnv(t) + root := t.TempDir() + writeTestModule(t, root, "lib/one.ex", "SharedLib.One") + if err := os.MkdirAll(store.DBDir(root), 0o755); err != nil { + t.Fatal(err) + } + if err := os.WriteFile(store.DBPath(root), []byte(strings.Repeat("not a database ", 512)), 0o644); err != nil { + t.Fatal(err) + } + + rt, release := openHeld(t, root) + client := notifytest.New() + defer rt.Reporter().Attach(client, false)() + got := client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Dexter: the index at "+store.DBPath(root)+" is damaged (") + if !strings.Contains(got.Message, "Dexter deleted it and is rebuilding it now") { + t.Errorf("message does not say what Dexter does: %q", got.Message) + } + release() + if err := rt.WaitReady(testContext(t, 30*time.Second)); err != nil { + t.Fatal(err) + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "the index rebuild is complete") + if countModule(t, rt, "SharedLib.One") == 0 { + t.Fatal("the rebuild did not index the project") + } +} + +func TestIndexMessagesSayWhatHappened(t *testing.T) { + locked := lockedIndexMessage("/p", errors.New("database is locked")) + if !strings.Contains(locked, "Dexter did not change the index") || !strings.Contains(locked, "dexter stop --force") { + t.Errorf("locked message gives no hint: %q", locked) + } + other := otherOpenFailureMessage("/p", errors.New("permission denied")) + if strings.Contains(other, "deleted it") || !strings.Contains(other, "did not delete it") { + t.Errorf("a failure that is not damage claims a delete: %q", other) + } + if older := versionMismatchMessage(3, 4); !strings.Contains(older, "older Dexter build (index version 3; this build uses 4)") { + t.Errorf("older-build message = %q", older) + } + if none := versionMismatchMessage(0, 4); !strings.Contains(none, "did not finish") { + t.Errorf("no-version message = %q", none) + } +} + +// seedIndex writes an index that holds one file. +func seedIndex(t *testing.T, root string) { + t.Helper() + writeStaleIndex(t, root, version.IndexVersion) +} + +func inode(t *testing.T, path string) uint64 { + t.Helper() + info, err := os.Stat(path) + if err != nil { + t.Fatalf("index file is gone: %v", err) + } + return info.Sys().(*syscall.Stat_t).Ino +} + +// Another process can hold the index in a write transaction: `dexter init` and +// older releases use a rollback journal, which locks the whole file. Deleting +// the files under it loses its work in silence, so a locked index must never +// be deleted. +func TestLockedIndexIsNeverDeleted(t *testing.T) { + quietReportEnv(t) + root := t.TempDir() + seedIndex(t, root) + dbPath := store.DBPath(root) + before := inode(t, dbPath) + + other, err := sql.Open("sqlite3", dbPath) + if err != nil { + t.Fatal(err) + } + defer func() { _ = other.Close() }() + other.SetMaxOpenConns(1) + conn, err := other.Conn(context.Background()) + if err != nil { + t.Fatal(err) + } + defer func() { _ = conn.Close() }() + for _, stmt := range []string{ + "PRAGMA journal_mode=MEMORY", + "BEGIN EXCLUSIVE", + "INSERT INTO metadata (key, value) VALUES ('other_process', 'wrote this')", + } { + if _, err := conn.ExecContext(context.Background(), stmt); err != nil { + t.Fatalf("%s: %v", stmt, err) + } + } + + previous := openBusyWait + openBusyWait = 50 * time.Millisecond + t.Cleanup(func() { openBusyWait = previous }) + r := notify.New() + r.SetLogf(func(string, ...any) {}) + s, err := openStore(root, r) + if err == nil { + _ = s.Close() + t.Fatal("openStore opened an index that another process holds locked") + } + if !strings.Contains(err.Error(), "another process holds the index") { + t.Errorf("error = %q", err) + } + if !r.Active(lsp.CondIndexUnavailable) || r.Active(lsp.CondIndexRebuild) { + t.Errorf("conditions = %+v, want only index.unavailable", r.Conditions()) + } + if after := inode(t, dbPath); after != before { + t.Fatal("the locked index was deleted and created again") + } + + if _, err := conn.ExecContext(context.Background(), "COMMIT"); err != nil { + t.Fatal(err) + } + var value string + if err := conn.QueryRowContext(context.Background(), "SELECT value FROM metadata WHERE key = 'other_process'").Scan(&value); err != nil || value != "wrote this" { + t.Fatalf("the other process lost its write: %q, %v", value, err) + } +} + +// A permission error is not fixed by a rebuild. The index must stay, and the +// message must not say that it was deleted. +func TestUnreadableIndexIsNotDeleted(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("root ignores file permissions") + } + quietReportEnv(t) + root := t.TempDir() + seedIndex(t, root) + dir := store.DBDir(root) + if err := os.Chmod(store.DBPath(root), 0); err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = os.Chmod(store.DBPath(root), 0o644) }) + r := notify.New() + r.SetLogf(func(string, ...any) {}) + s, err := openStore(root, r) + if err == nil { + _ = s.Close() + t.Fatal("openStore opened an index without read permission") + } + if _, statErr := os.Stat(store.DBPath(root)); statErr != nil { + t.Fatalf("the index was deleted: %v", statErr) + } + conditions := r.Conditions() + if len(conditions) != 1 || conditions[0].Key != lsp.CondIndexUnavailable || conditions[0].Severity != notify.Error || + !strings.Contains(conditions[0].Message, "Dexter did not delete it") || !strings.Contains(conditions[0].Message, dir) { + t.Fatalf("conditions = %+v", conditions) + } +} + +func TestRootThatIsNotAProjectIsShown(t *testing.T) { + r := notify.New() + r.SetLogf(func(string, ...any) {}) + reportRoot(t.TempDir(), r) + if c := r.Conditions(); len(c) != 1 || !strings.Contains(c[0].Message, "does not look like an Elixir project") { + t.Fatalf("conditions = %+v", c) + } + + project := t.TempDir() + writeTestModule(t, project, "mix.exs", "SharedLib.MixProject") + r = notify.New() + reportRoot(project, r) + if c := r.Conditions(); len(c) != 0 { + t.Fatalf("a project was reported: %+v", c) + } + + home := t.TempDir() + t.Setenv("HOME", home) + writeTestModule(t, home, "mix.exs", "SharedLib.MixProject") + r = notify.New() + r.SetLogf(func(string, ...any) {}) + reportRoot(home, r) + if c := r.Conditions(); len(c) != 1 || !strings.Contains(c[0].Message, "is your home directory, not a project") { + t.Fatalf("conditions = %+v", c) + } +} + +func TestUnavailableWatchingIsShownAndItsRecovery(t *testing.T) { + quietReportEnv(t) + root := t.TempDir() + previousStart := startNativeWatch + previousInterval := watchRetryInterval + var attempts atomic.Int32 + startNativeWatch = func(root string, callbacks WatchCallbacks) (*Watcher, error) { + if attempts.Add(1) <= 2 { + return nil, errors.New("too many open files") + } + return &Watcher{backend: &fsnotifyWatcher{failed: map[string]struct{}{}}, kind: "fake"}, nil + } + watchRetryInterval = 20 * time.Millisecond + t.Cleanup(func() { + startNativeWatch = previousStart + watchRetryInterval = previousInterval + }) + rt, err := Open(root) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { + rt.watcherMu.Lock() + rt.watcher = nil // the fake has no fsnotify handle to close + rt.watcherMu.Unlock() + _ = rt.Close() + }) + client := notifytest.New() + defer rt.Reporter().Attach(client, false)() + + got := client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Dexter: cannot watch the files of "+root+" (too many open files)") + if !strings.Contains(got.Message, "Files that you save in the editor are still indexed") { + t.Errorf("message does not say what still works: %q", got.Message) + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: file watching works again for "+root) + watchMessages := 0 + for _, m := range client.Messages() { + if strings.Contains(m.Message, "watch") { + watchMessages++ + } + } + if watchMessages != 2 { + t.Errorf("a failed retry sent a message again:\n%s", client.Dump()) + } +} + +func TestWatcherFallbackAndCoverageAreShown(t *testing.T) { + root := t.TempDir() + rt := &Runtime{root: root, index: lsp.NewIndexCoordinator()} + rt.Reporter().SetLogf(func(string, ...any) {}) + client := notifytest.New() + defer rt.Reporter().Attach(client, false)() + + a, b := filepath.Join(root, "a"), filepath.Join(root, "b") + backend := &fsnotifyWatcher{ + failed: map[string]struct{}{a: {}, b: {}}, + fallbackReason: errors.New("macOS FSEvents: stream failed"), + } + w := &Watcher{backend: backend, kind: "fsnotify"} + rt.watcher = w + rt.reportWatcherStarted(w) + + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "the native file watcher is not available for "+root+" (macOS FSEvents: stream failed)") + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Dexter: 2 directories ("+a+" and 1 more) under "+root+" cannot be watched") + + // One directory comes back: still degraded, so no new message. + delete(backend.failed, a) + rt.reportCoverage() + delete(backend.failed, b) + rt.reportCoverage() + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: file watching covers the whole project again") + if n := len(client.Messages()); n != 3 { + t.Errorf("got %d messages, want 3:\n%s", n, client.Dump()) + } +} + +// racingBackend restores its last failed directory right after the first +// Degraded check, and runs the watcher's coverage callback for that restore +// before the caller of the check goes on, when nothing stops it. +type racingBackend struct { + mu sync.Mutex + calls int + degraded bool + onRestore func() +} + +func (b *racingBackend) Close() error { return nil } + +func (b *racingBackend) Degraded() bool { + b.mu.Lock() + b.calls++ + first := b.calls == 1 + was := b.degraded + if first { + b.degraded = false + } + b.mu.Unlock() + if first { + done := make(chan struct{}) + go func() { + b.onRestore() + close(done) + }() + select { + case <-done: + case <-time.After(100 * time.Millisecond): + } + return was + } + return b.degraded +} + +// The last directory can come back between the check that the watcher is +// degraded and the warning. The warning must not stay after the report that +// coverage returned. +func TestCoverageRestoredDuringStartIsNotLeftDegraded(t *testing.T) { + rt := &Runtime{root: t.TempDir(), index: lsp.NewIndexCoordinator()} + rt.Reporter().SetLogf(func(string, ...any) {}) + backend := &racingBackend{degraded: true, onRestore: rt.reportCoverage} + w := &Watcher{backend: backend, kind: "fsnotify"} + rt.watcher = w + rt.reportWatcherStarted(w) + deadline := time.Now().Add(2 * time.Second) + for rt.Reporter().Active(condWatchCoverage) { + if time.Now().After(deadline) { + t.Fatal("the coverage warning stayed after coverage came back") + } + time.Sleep(5 * time.Millisecond) + } +} diff --git a/internal/workspace/runtime.go b/internal/workspace/runtime.go index f2c8eb3..c21e77e 100644 --- a/internal/workspace/runtime.go +++ b/internal/workspace/runtime.go @@ -12,10 +12,12 @@ import ( "os" "path/filepath" "sort" + "strings" "sync" "time" "github.com/remoteoss/dexter/internal/lsp" + "github.com/remoteoss/dexter/internal/notify" "github.com/remoteoss/dexter/internal/parser" "github.com/remoteoss/dexter/internal/stdlib" "github.com/remoteoss/dexter/internal/store" @@ -51,6 +53,7 @@ type event struct { // external ownership lock. type Runtime struct { root string + hook func() store *store.Store index *lsp.IndexCoordinator core *lsp.Server @@ -64,6 +67,7 @@ type Runtime struct { closeOnce sync.Once closeErr error + coverageMu sync.Mutex // orders coverage reports; see reportCoverage watcherMu sync.RWMutex watcher *Watcher watcherReady chan struct{} @@ -89,6 +93,11 @@ type Options struct { // requests; it just does not observe the tree itself. Tests use it to drive // the mutation queue deterministically. NoWatch bool + + // BeforeInitialReconcile runs on the mutation loop before the first + // reconciliation. Tests use it to hold a workspace in that state, for + // example to attach an editor while a rebuild is in progress. + BeforeInitialReconcile func() } // Open creates and starts a workspace runtime with native watching enabled. @@ -100,12 +109,16 @@ func Open(root string) (*Runtime, error) { return OpenWithOptions(root, Options{ // OpenWithOptions creates and starts a workspace runtime. Open must only be // called by the process holding the workspace's ownership lock. func OpenWithOptions(root string, opts Options) (*Runtime, error) { - s, err := openStore(root) + index := lsp.NewIndexCoordinator() + reporter := index.Reporter() + // Before the store opens: opening it creates the database, which is + // itself a project marker. + reportRoot(root, reporter) + s, err := openStore(root, reporter) if err != nil { return nil, err } - index := lsp.NewIndexCoordinator() previousStdlibRoot, _ := s.GetStdlibRoot() stdlibRoot := "" if resolved, ok := stdlib.Resolve(s, "", root); ok { @@ -116,11 +129,13 @@ func OpenWithOptions(root string, opts Options) (*Runtime, error) { ManageWorkspace: false, InitialStdlibRoot: stdlibRoot, }) + core.ReportStdlib() if previousStdlibRoot != "" && previousStdlibRoot != stdlibRoot { core.RemoveFilesUnderRoot(previousStdlibRoot) } r := &Runtime{ root: root, + hook: opts.BeforeInitialReconcile, store: s, index: index, core: core, @@ -234,6 +249,22 @@ func newSessionTag() string { return hex.EncodeToString(b[:]) } +// Reporter returns the reporter that tells every attached editor about +// failures, degraded states, and long work in this workspace. +func (r *Runtime) Reporter() *notify.Reporter { return r.index.Reporter() } + +// IndexConditions returns the active conditions that describe the index, such +// as a rebuild or an index that cannot be used. The CLI prints them. +func (r *Runtime) IndexConditions() []notify.Condition { + var out []notify.Condition + for _, c := range r.Reporter().Conditions() { + if strings.HasPrefix(c.Key, lsp.IndexConditionPrefix) { + out = append(out, c) + } + } + return out +} + // Store returns the workspace index. Frontends read through it instead of // opening a second handle, so one writer owns the file. func (r *Runtime) Store() *store.Store { return r.store } @@ -482,6 +513,9 @@ func (r *Runtime) send(ev event) bool { func (r *Runtime) loop() { defer r.loopWG.Done() <-r.watcherReady + if r.hook != nil { + r.hook() + } r.core.ReindexWorkspace() r.publish(Change{Full: true}) close(r.ready) @@ -676,15 +710,19 @@ func (r *Runtime) startNativeWatcher() { for { started := time.Now() watcher, err := startNativeWatch(r.root, WatchCallbacks{ - PathChanged: r.ReconcileFile, - FullReconcile: func() { r.send(event{kind: eventFull}) }, - CoverageChanged: r.watchCoverageChanged, + PathChanged: r.ReconcileFile, + FullReconcile: func() { r.send(event{kind: eventFull}) }, + CoverageChanged: func(degraded bool) { + r.reportCoverage() + r.watchCoverageChanged(degraded) + }, }) if err == nil { r.watcherMu.Lock() r.watcher = watcher r.watcherMu.Unlock() log.Printf("Workspace watcher %s started in %s", watcher.Kind(), time.Since(started).Round(time.Millisecond)) + r.reportWatcherStarted(watcher) if firstAttempt { close(r.watcherReady) } else { @@ -692,7 +730,7 @@ func (r *Runtime) startNativeWatcher() { } return } - log.Printf("Warning: native file watching unavailable for %s: %v", r.root, err) + r.reportWatchUnavailable(err) if firstAttempt { close(r.watcherReady) firstAttempt = false @@ -749,27 +787,96 @@ func (r *Runtime) startGitWatch() { }() } -func openStore(root string) (*store.Store, error) { - s, err := store.Open(root) +// openBusyWait bounds how long openStore waits for another process to release +// a locked index. Each attempt also waits out the store's own busy timeout. A +// variable so tests can shrink it. +var openBusyWait = 30 * time.Second + +// openStore opens the index. It deletes the index for a rebuild only when that +// is safe and useful: when the file is damaged, or when it was written by +// another index version. Each rebuild is a condition that the first +// reconciliation clears. +// +// A locked index is never deleted. Another process, such as `dexter init` or an +// older Dexter release, can hold it in a write transaction, and deleting the +// files under it loses its work in silence. openStore waits for the lock, and +// fails when it stays, so that the editor shows why. Permission, disk-space, +// and similar errors do not delete either: a rebuild cannot fix them. +func openStore(root string, reporter *notify.Reporter) (*store.Store, error) { + s, err := openWaitingForLock(root, reporter) if err != nil { - log.Printf("Failed to open index at %s (%v); rebuilding derived index", root, err) - removeIndexFiles(root) - if s, err = store.Open(root); err != nil { - return nil, fmt.Errorf("opening index at %s: %w", root, err) + switch store.ClassifyOpenError(err) { + case store.OpenFailureDamaged: + reporter.Set(lsp.CondIndexRebuild, notify.Warning, damagedIndexMessage(root, err)) + removeIndexFiles(root) + if s, err = store.Open(root); err != nil { + return nil, openFailed(reporter, otherOpenFailureMessage(root, err), err) + } + case store.OpenFailureBusy: + return nil, openFailed(reporter, lockedIndexMessage(root, err), err) + default: + return nil, openFailed(reporter, otherOpenFailureMessage(root, err), err) } } if stored := s.GetIndexVersion(); stored != version.IndexVersion && !s.IsEmpty() { + reporter.Set(lsp.CondIndexRebuild, notify.Warning, versionMismatchMessage(stored, version.IndexVersion)) if err := s.Close(); err != nil { return nil, fmt.Errorf("closing outdated index: %w", err) } removeIndexFiles(root) if s, err = store.Open(root); err != nil { - return nil, fmt.Errorf("reopening index at %s: %w", root, err) + return nil, openFailed(reporter, otherOpenFailureMessage(root, err), err) } } return s, nil } +// openWaitingForLock opens the store and retries while another process holds +// it locked, up to openBusyWait. +func openWaitingForLock(root string, reporter *notify.Reporter) (*store.Store, error) { + deadline := time.Now().Add(openBusyWait) + backoff := 100 * time.Millisecond + waited := false + for { + s, err := store.Open(root) + if err == nil { + if waited { + reporter.Clear(lsp.CondIndexUnavailable, "Dexter: the other process released the index; Dexter continues.") + } + return s, nil + } + if store.ClassifyOpenError(err) != store.OpenFailureBusy || !time.Now().Before(deadline) { + return nil, err + } + if !waited { + waited = true + reporter.Set(lsp.CondIndexUnavailable, notify.Error, fmt.Sprintf( + "Dexter: another process holds the index at %s locked (%v). Dexter waits up to %s for it and does not change the index.", + store.DBPath(root), err, openBusyWait)) + } + time.Sleep(backoff) + if backoff < time.Second { + backoff *= 2 + } + } +} + +// openIndexError is an index that could not be opened. Its text is the +// message for the user: the daemon exits with it, and a frontend shows the end +// of the daemon log in the editor. +type openIndexError struct { + message string + err error +} + +func (e *openIndexError) Error() string { return strings.TrimPrefix(e.message, "Dexter: ") } +func (e *openIndexError) Unwrap() error { return e.err } + +func openFailed(reporter *notify.Reporter, message string, err error) error { + reporter.Set(lsp.CondIndexUnavailable, notify.Error, message) + return &openIndexError{message: message, err: err} +} + func removeIndexFiles(root string) { dbPath := store.DBPath(root) for _, path := range []string{dbPath, dbPath + "-wal", dbPath + "-shm"} { diff --git a/internal/workspace/watch.go b/internal/workspace/watch.go index 3197dbf..fb335b6 100644 --- a/internal/workspace/watch.go +++ b/internal/workspace/watch.go @@ -42,6 +42,24 @@ func (w *Watcher) Degraded() bool { return w.backend.Degraded() } func (w *Watcher) Kind() string { return w.kind } +// FailedDirectories lists the directories that the watcher cannot watch now, +// sorted. Only a per-directory backend can have them. +func (w *Watcher) FailedDirectories() []string { + if b, ok := w.backend.(interface{ failedDirectories() []string }); ok { + return b.failedDirectories() + } + return nil +} + +// Fallback reports why the preferred backend of the platform could not start, +// or nil when it runs. +func (w *Watcher) Fallback() error { + if b, ok := w.backend.(interface{ fallback() error }); ok { + return b.fallback() + } + return nil +} + func skipWatchDir(name string) bool { switch name { case "_build", ".git", "node_modules", "deps", ".dexter": diff --git a/internal/workspace/watch_fsnotify.go b/internal/workspace/watch_fsnotify.go index f40f670..907b4b2 100644 --- a/internal/workspace/watch_fsnotify.go +++ b/internal/workspace/watch_fsnotify.go @@ -36,8 +36,15 @@ type fsnotifyWatcher struct { mu sync.Mutex failed map[string]struct{} + + // fallbackReason is why the platform's preferred watcher could not start, + // when this one runs in its place. It is set before the watcher is + // returned and not changed after. + fallbackReason error } +func (w *fsnotifyWatcher) fallback() error { return w.fallbackReason } + var watchRetryInterval = 5 * time.Second // Degraded reports whether any directory could not be watched. diff --git a/internal/workspace/watch_platform_darwin.go b/internal/workspace/watch_platform_darwin.go index ad0565b..095b043 100644 --- a/internal/workspace/watch_platform_darwin.go +++ b/internal/workspace/watch_platform_darwin.go @@ -6,7 +6,6 @@ import ( "errors" "fmt" "io/fs" - "log" "os" "path/filepath" "strings" @@ -47,11 +46,14 @@ func startPlatformWatcher(root string, callbacks WatchCallbacks) (watchBackend, if err == nil { return watcher, "fsevents", nil } - log.Printf("Warning: macOS FSEvents unavailable for %s: %v; using fsnotify", root, err) + // The runtime tells the user, through Watcher.Fallback. fallback, fallbackErr := startFSNotifyWatcher(root, callbacks) if fallbackErr != nil { return nil, "", errors.Join(fmt.Errorf("start FSEvents: %w", err), fmt.Errorf("start fsnotify: %w", fallbackErr)) } + if w, ok := fallback.(*fsnotifyWatcher); ok { + w.fallbackReason = fmt.Errorf("macOS FSEvents: %w", err) + } return fallback, "fsnotify", nil } diff --git a/lsp_integration_test.go b/lsp_integration_test.go index 56fad77..2fd9f5e 100644 --- a/lsp_integration_test.go +++ b/lsp_integration_test.go @@ -48,10 +48,10 @@ func TestLSP_ColdStartBuildsInServer(t *testing.T) { // proxy's stderr is included too: if a rebuild ever moves back into the // frontend, the mismatch assertion below still catches it there. logs := stderr.String() + daemonLogs(t, root) - if strings.Contains(logs, "Index version mismatch") { + if strings.Contains(logs, "Rebuilding it now") { t.Errorf("cold LSP startup rebuilt through cmdInit before serving:\n%s", logs) } - if !strings.Contains(logs, "No index found, building from scratch") { + if !strings.Contains(logs, "building the index for the first time") { t.Errorf("cold LSP startup did not use the server's background build:\n%s", logs) } } @@ -76,8 +76,8 @@ func TestLSP_RootFlagServesWorkspaceFromAnotherDirectory(t *testing.T) { // TestLSP_WarnsOnNonProjectRoot covers the editor side of the not-a-project // guard: an editor is authoritative about what the user opened, so the LSP -// warns and serves rather than refusing, and the warning reaches the server log -// an editor collects. +// warns and serves rather than refusing. The warning is shown in the editor, +// not only written to a log that nobody reads. func TestLSP_WarnsOnNonProjectRoot(t *testing.T) { binary := buildDexter(t) root := t.TempDir() @@ -88,15 +88,12 @@ func TestLSP_WarnsOnNonProjectRoot(t *testing.T) { } defer client.Close() - // The warning is written by the child before the handshake completes, but - // the parent's stderr copy goroutine may not have landed it yet when Start - // returns, so wait for it rather than sampling once. - deadline := time.Now().Add(5 * time.Second) - for !strings.Contains(stderr.String(), "does not look like an Elixir project") { - if time.Now().After(deadline) { - t.Fatalf("serving a non-project root logged no warning:\n%s", stderr.String()) - } - time.Sleep(10 * time.Millisecond) + shown, err := client.WaitShown("does not look like an Elixir project", 10*time.Second) + if err != nil { + t.Fatalf("serving a non-project root showed no warning: %v\n%s", err, stderr.String()) + } + if shown.Type != 2 { + t.Errorf("warning has message type %d, want 2 (Warning)", shown.Type) } } From fec9919b50e725d18fe133e7531b6303fb33dc2c Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 19:51:43 -0400 Subject: [PATCH 2/7] Keep the OTP mismatch until the formatter BEAM works When the persistent formatter BEAM failed with an Elixir/OTP mismatch, formatting fell back to `mix format`. A success of that fallback cleared the mismatch condition. The next format then started the BEAM again, which failed again and set the condition again. Each save sent an error and a "formatting works again" message to every editor, and paid for a failed BEAM start. Now: - Only a format by the persistent BEAM clears the OTP condition of its build root. A `mix format` success clears only the report that formatting does not work in that Mix project. - After an OTP mismatch, the build root does not start a BEAM again until the elixir or mix binary or the _build directory changes, or for 10 minutes. It formats through `mix format` in the meantime. - The condition is a Warning that says that formatting still works through the slower `mix format` fallback, and how to fix the mismatch. An OTP mismatch from `mix format` itself is an Error: then formatting does not work. Before the reporting change, a sync.Once showed the mismatch once for each session, but the BEAM still started again on each save. Both are now fixed. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 2 +- docs/architecture.md | 3 +- internal/lsp/formatter.go | 42 ++++--- internal/lsp/otp_mismatch_test.go | 183 ++++++++++++++++++++++++++++++ internal/lsp/report.go | 83 ++++++++++++-- internal/lsp/report_test.go | 10 +- internal/lsp/server.go | 17 ++- 7 files changed, 295 insertions(+), 45 deletions(-) create mode 100644 internal/lsp/otp_mismatch_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 901d384..3c953bb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,7 +6,7 @@ - **Go-to-definition reaches the line that declared a generated function** — a function a macro generated used to resolve to the top of its module. Dexter now reads the line from the compiled module's debug info, which is standard compiler output, so no framework is special-cased. A generator that expands each function at the line of the call that declared it, or stamps it with `@file {file, line}`, sends definition, call hierarchy, the references declaration, and `dexter lookup` (including `--strict`) to that line. The line is used only when it was compiled from the file being opened; a BEAM older than the source still gives its line, because Dexter cannot compile the project and the last compile's line is closer than the module line; only edits to the declaring file move it, and the next compile makes it exact. A function whose only recorded line is the module line, such as one a `@before_compile` hook made, goes to the call in its module that declares it by name. When several calls spell the name, as an Ash action and the code interface that runs it do, the macro whose calls name the most of the module's generated functions wins, and a tie keeps the module line. A function with a clause per DSL call goes to every clause. A line past the end of the file is never returned. A module compiled without debug info falls back to its Docs chunk annotation, which is often, but not always, the same line. A generated module with no source of its own, such as one `Module.create` made or a Spark DSL entity, goes to the file it was compiled from, rebased onto the project when it was built elsewhere, and so does go-to-definition on its name. A module a macro made with `defmodule` and a name it computed records no line of its own, so its name goes to its first function's line. A bare call to a generated function of an imported module now resolves. Ash code interfaces go to their `define` line with released Ash, and from the recorded line with an Ash release that includes [ash-project/ash#2971](https://github.com/ash-project/ash/pull/2971) ([#108](https://github.com/remoteoss/dexter/issues/108)) -- **Failures and degraded states are shown in the editor** — before, almost every problem went only to the log, so the editor showed a language server that did nothing. Now each condition that stops Dexter from working, or makes it work with less, is a `window/showMessage` in every attached editor: an index written by a newer or older Dexter build, a damaged index that is being rebuilt, an index that another process holds locked or that cannot be opened for another cause, an index that cannot be used, a fast build that fell back to the slow path, files that could not be indexed (one aggregate message), a root that is the home directory or not a project, file watching that is unavailable or does not cover some directories, FSEvents falling back to fsnotify, a workspace with no Elixir standard library, a session with no `mix` (told to that editor only), a Mix project whose formatter cannot run (each project on its own), and a rename that could not change some files. Each message says what happened, what Dexter does about it, and what to do. Conditions that stop say so, and an editor that attaches later receives the conditions that are still active. Cold builds, rebuilds, and large incremental passes show LSP work-done progress where the editor supports it. `lookup`, `references`, and `reindex` state a rebuilding or unusable index on stderr, and `workspace/status` lists every active condition +- **Failures and degraded states are shown in the editor** — before, almost every problem went only to the log, so the editor showed a language server that did nothing. Now each condition that stops Dexter from working, or makes it work with less, is a `window/showMessage` in every attached editor: an index written by a newer or older Dexter build, a damaged index that is being rebuilt, an index that another process holds locked or that cannot be opened for another cause, an index that cannot be used, a fast build that fell back to the slow path, files that could not be indexed (one aggregate message), a root that is the home directory or not a project, file watching that is unavailable or does not cover some directories, FSEvents falling back to fsnotify, a workspace with no Elixir standard library, a session with no `mix` (told to that editor only), a Mix project whose formatter cannot run (each project on its own), an Elixir/OTP mismatch that stops the fast formatter (told once; Dexter then formats through `mix format` and does not start the failing BEAM again on each save), and a rename that could not change some files. Each message says what happened, what Dexter does about it, and what to do. Conditions that stop say so, and an editor that attaches later receives the conditions that are still active. Cold builds, rebuilds, and large incremental passes show LSP work-done progress where the editor supports it. `lookup`, `references`, and `reindex` state a rebuilding or unusable index on stderr, and `workspace/status` lists every active condition - **`dexter lsp` explains why it cannot start** — when the proxy cannot reach a daemon (a daemon from another build, a different spelling of the root, a workspace held by `dexter init`, or a daemon that does not start), it answers the editor's `initialize` request with an error and a `window/showMessage` that carry the full explanation and the fix, instead of printing to stderr and exiting diff --git a/docs/architecture.md b/docs/architecture.md index 57910fb..24e6a28 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -249,7 +249,8 @@ What is reported, and what stays in the log only: | Directories that cannot be watched | `watcher.coverage` | Warning | yes | | The workspace has no Elixir standard library (read from the root that all sessions share, not from what one session found) | `stdlib` | Warning | yes | | `mix` not found for one session | (this editor only) | Warning | — | -| `mix format` cannot run, or Elixir/OTP mismatch, in one Mix project | `formatter:`, `formatter.otp:` | Warning, Error | yes ("formatting works again in ") | +| `mix format` cannot run in one Mix project | `formatter:` | Warning (Error for an OTP mismatch) | yes ("formatting works again in ") | +| The persistent formatter BEAM fails with an Elixir/OTP mismatch; formatting goes on through `mix format` | `formatter.otp:` | Warning | only when the BEAM formats again ("the fast persistent formatter works again"); a `mix format` success does not clear it. The build root does not start a BEAM again until the Elixir or mix binary or `_build` changes, or for 10 minutes | | A rename that could not change some files | (this editor only) | Error | — | A syntax error in the user's code is not a formatter failure: it is a diagnostic. WAL checkpoint warnings, fsnotify transient errors, the per-directory watch errors (they are in the aggregate), BEAM formatter restarts that fall back to `mix format`, and requests that waited for the first build stay in the log. diff --git a/internal/lsp/formatter.go b/internal/lsp/formatter.go index bf0bdfa..b5e0d4b 100644 --- a/internal/lsp/formatter.go +++ b/internal/lsp/formatter.go @@ -691,6 +691,10 @@ func (bp *beamProcess) closeWithReason(reason string) { _ = bp.cmd.process.Kill() } +// startBeam starts the persistent BEAM for a build root. A variable so tests +// can start a fake one. +var startBeam = (*Server).startBeamProcess + // startBeamProcess launches a BEAM process for the given build root and returns // immediately. The returned process may not be ready yet — callers must check // bp.Ready() before sending requests. @@ -753,7 +757,9 @@ func (s *Server) startBeamProcess(buildRoot string) (*beamProcess, error) { if bp.startErr != nil { _ = cmd.Process.Kill() <-done - s.notifyOTPMismatch(buildRoot, stderrBuf.String()) + if isOTPMismatch(stderrBuf.String()) { + s.beamOTPMismatch(buildRoot) + } } case <-time.After(beamStuckTimeout): bp.finishStartup(fmt.Errorf("BEAM startup timed out")) @@ -803,8 +809,14 @@ func (s *Server) getBeamProcess(ctx context.Context, buildRoot string) *beamProc if s.mixBin == "" { return nil } + if s.otpMismatchHolds(buildRoot) { + // The BEAM fails the same way until the Elixir install or the build + // changes. Starting it on each save is a slow, failed spawn; the + // caller falls back to mix format. + return nil + } - bp, err := s.startBeamProcess(buildRoot) + bp, err := startBeam(s, buildRoot) if err != nil { log.Printf("BEAM: failed to start for %s: %v", buildRoot, err) return nil @@ -852,14 +864,14 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin bp := s.getBeamProcess(ctx, buildRoot) if bp == nil { log.Printf("Formatting: BEAM process unavailable, falling back to mix format") - return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, path, content) } if bp.formatterConfigChanged(formatterExs) { s.evictBeam(bp, fmt.Sprintf("formatter config changed: %s", formatterExs)) bp = s.getBeamProcess(ctx, buildRoot) if bp == nil { log.Printf("Formatting: BEAM process unavailable after formatter config change, falling back to mix format") - return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, path, content) } _ = bp.formatterConfigChanged(formatterExs) } @@ -870,7 +882,7 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin if bp.startErr != nil { s.evictBeam(bp, fmt.Sprintf("formatContent: startup finished with error: %v", bp.startErr)) log.Printf("Formatting: BEAM process failed to start, falling back to mix format: %v", bp.startErr) - return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, path, content) } default: // Not ready yet — decide based on how long it's been starting @@ -879,11 +891,11 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin case age > beamStuckTimeout: log.Printf("Formatting: BEAM process stuck (started %s ago), restarting", age.Truncate(time.Second)) s.evictBeam(bp, fmt.Sprintf("formatContent: startup exceeded %s without becoming ready", beamStuckTimeout)) - return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, path, content) case age > beamWaitTimeout: log.Printf("Formatting: BEAM process not ready after %s, falling back to mix format", age.Truncate(time.Millisecond)) - return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, path, content) default: if err := bp.Ready(ctx); err != nil { @@ -892,7 +904,7 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin } s.evictBeam(bp, fmt.Sprintf("formatContent: Ready failed: %v", err)) log.Printf("Formatting: BEAM process failed to start, falling back to mix format: %v", err) - return s.formatWithMixFormat(ctx, mixRoot, buildRoot, path, content) + return s.formatWithMixFormat(ctx, mixRoot, path, content) } } } @@ -917,7 +929,7 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin } log.Printf("Formatting: %s (%s, persistent)", path, time.Since(start)) - s.reportFormatWorks(mixRoot, buildRoot) + s.reportBeamFormatWorks(mixRoot, buildRoot) return result, nil } @@ -946,10 +958,10 @@ func (s *Server) evictBeam(bp *beamProcess, reason string) { bp.closeWithReason("evicted: " + reason) } -// formatWithMixFormat runs `mix format` in mixRoot. buildRoot is the build root -// of the file, whose BEAM formatter can have reported an OTP mismatch; a -// success clears that report too. -func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, buildRoot, path, content string) (string, error) { +// formatWithMixFormat runs `mix format` in mixRoot. It is the fallback when the +// persistent BEAM cannot serve, so its success says nothing about the BEAM: it +// clears only the report that formatting does not work in mixRoot. +func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, path, content string) (string, error) { if s.mixBin == "" { return "", fmt.Errorf("mix binary not found") } @@ -961,13 +973,13 @@ func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, buildRoot, pa cmd.Stderr = &stderr if err := cmd.Run(); err != nil { log.Printf("Formatting: mix format failed for %s (%s): %v\n%s", path, time.Since(start), err, stderr.String()) - if ctx.Err() == nil && !s.notifyOTPMismatch(mixRoot, stderr.String()) { + if ctx.Err() == nil { s.reportFormatFailure(mixRoot, err, stderr.String()) } return "", err } log.Printf("Formatting: %s (%s, mix format)", path, time.Since(start)) - s.reportFormatWorks(mixRoot, buildRoot) + s.reportMixFormatWorks(mixRoot) return stdout.String(), nil } diff --git a/internal/lsp/otp_mismatch_test.go b/internal/lsp/otp_mismatch_test.go new file mode 100644 index 0000000..cd0fc97 --- /dev/null +++ b/internal/lsp/otp_mismatch_test.go @@ -0,0 +1,183 @@ +package lsp + +import ( + "context" + "encoding/binary" + "io" + "os" + "os/exec" + "path/filepath" + "strings" + "testing" + "time" + + "go.lsp.dev/protocol" + + "github.com/remoteoss/dexter/internal/notify/notifytest" +) + +const otpMismatchStderr = "** (UndefinedFunctionError) function :erlang.foo/0 is undefined: requires a more recent Erlang/OTP" + +// otpMismatchProject makes a fake Elixir install whose elixir binary fails +// with an OTP mismatch and counts its starts, and whose mix formats by echoing +// its input. It returns the server, its editor, and the path of the start log. +func otpMismatchProject(t *testing.T) (*Server, *notifytest.Client, string) { + t.Helper() + server, cleanup := setupTestServer(t) + t.Cleanup(cleanup) + bin := t.TempDir() + starts := filepath.Join(bin, "starts") + scripts := map[string]string{ + "elixir": "#!/bin/sh\necho start >> " + starts + "\necho '" + otpMismatchStderr + "' >&2\nexit 1\n", + "mix": "#!/bin/sh\ncat\n", + } + for name, script := range scripts { + if err := os.WriteFile(filepath.Join(bin, name), []byte(script), 0o755); err != nil { + t.Fatal(err) + } + } + server.mixBin = filepath.Join(bin, "mix") + writeTestFile(t, server.projectRoot, "mix.exs", "defmodule MyApp.MixProject do\nend\n") + client := attachFakeEditor(t, server, false) + return server, client, starts +} + +func beamStarts(t *testing.T, starts string) int { + t.Helper() + data, err := os.ReadFile(starts) + if os.IsNotExist(err) { + return 0 + } + if err != nil { + t.Fatal(err) + } + return strings.Count(string(data), "start") +} + +func formatOnce(t *testing.T, server *Server, content string) string { + t.Helper() + path := filepath.Join(server.projectRoot, "lib", "a.ex") + got, err := server.formatContent(context.Background(), server.projectRoot, path, content) + if err != nil { + t.Fatalf("format: %v", err) + } + return got +} + +// A persistent BEAM that fails with an OTP mismatch must be told once. The +// mix format fallback still works, but that does not fix the mismatch: it +// must not say "works again", and the next save must not start the failing +// BEAM again only to report the mismatch again. +func TestOTPMismatchIsShownOnceAndFormatsThroughMix(t *testing.T) { + server, client, starts := otpMismatchProject(t) + + content := "defmodule A do\nend\n" + if got := formatOnce(t, server, content); got != content { + t.Fatalf("first format = %q, want %q", got, content) + } + got := client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Elixir/OTP version mismatch in "+server.projectRoot) + if !strings.Contains(got.Message, "Formatting still works through the slower `mix format` fallback") { + t.Errorf("the message does not say that formatting still works: %q", got.Message) + } + for i := 0; i < 4; i++ { + if got := formatOnce(t, server, content); got != content { + t.Fatalf("format %d = %q, want %q", i+2, got, content) + } + } + + time.Sleep(50 * time.Millisecond) + if n := beamStarts(t, starts); n != 1 { + t.Errorf("the failing BEAM started %d times, want 1", n) + } + if n := countMessages(client, "Elixir/OTP version mismatch"); n != 1 { + t.Errorf("got %d OTP messages, want 1:\n%s", n, client.Dump()) + } + if n := countMessages(client, "works again"); n != 0 { + t.Errorf("a mix format fallback said that formatting works again:\n%s", client.Dump()) + } +} + +// fakeBeam is a persistent formatter that answers every format request with +// its input in upper case, so a test can see that the BEAM formatted. +func fakeBeam(t *testing.T) *beamProcess { + t.Helper() + reqReader, reqWriter := io.Pipe() + respReader, respWriter := io.Pipe() + sleeper := exec.Command("sleep", "60") + if err := sleeper.Start(); err != nil { + t.Fatal(err) + } + done := make(chan struct{}) + go func() { + _ = sleeper.Wait() + close(done) + }() + bp := newTestBeamProcess(reqWriter, respReader, nil) + bp.cmd = &commandHandle{process: sleeper.Process, done: done} + bp.startedAt = time.Now() + go bp.readLoop() + go func() { + for { + if _, err := readByte(reqReader); err != nil { + return + } + reqID, err := readUint32(reqReader) + if err != nil { + return + } + header := make([]byte, 6) + if _, err := io.ReadFull(reqReader, header); err != nil { + return + } + payload := make([]byte, binary.BigEndian.Uint32(header[2:])) + if _, err := io.ReadFull(reqReader, payload); err != nil { + return + } + configLen := int(binary.BigEndian.Uint16(payload)) + rest := payload[2+configLen:] + nameLen := int(binary.BigEndian.Uint16(rest)) + rest = rest[2+nameLen+4:] + writeTestResponseFrame(t, respWriter, reqID, 0, []byte(strings.ToUpper(string(rest)))) + } + }() + t.Cleanup(func() { + bp.closeWithReason("test end") + _ = reqWriter.Close() + _ = respWriter.Close() + }) + return bp +} + +// The OTP mismatch ends when the persistent BEAM starts and formats, which +// Dexter tries when the Elixir install changes. +func TestOTPMismatchClearsWhenTheBeamStarts(t *testing.T) { + server, client, starts := otpMismatchProject(t) + content := "defmodule A do\nend\n" + formatOnce(t, server, content) + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Elixir/OTP version mismatch in "+server.projectRoot) + + previous := startBeam + startBeam = func(*Server, string) (*beamProcess, error) { return fakeBeam(t), nil } + t.Cleanup(func() { startBeam = previous }) + + // Nothing changed yet: the fallback is still used. + if got := formatOnce(t, server, content); got != content { + t.Fatalf("format before the fix = %q, want the mix format output", got) + } + + // The user installs a matching Elixir. + later := time.Now().Add(time.Minute) + if err := os.Chtimes(filepath.Join(filepath.Dir(server.mixBin), "elixir"), later, later); err != nil { + t.Fatal(err) + } + if got := formatOnce(t, server, content); got != strings.ToUpper(content) { + t.Fatalf("format after the fix = %q, want the BEAM output", got) + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: the fast persistent formatter works again in "+server.projectRoot+".") + if server.index.reporter.Active(condOTP + ":" + server.projectRoot) { + t.Error("the OTP mismatch is still active after the BEAM formatted") + } + if n := beamStarts(t, starts); n != 1 { + t.Errorf("the failing BEAM started %d times, want 1", n) + } +} diff --git a/internal/lsp/report.go b/internal/lsp/report.go index 70bf8a8..930a022 100644 --- a/internal/lsp/report.go +++ b/internal/lsp/report.go @@ -266,24 +266,78 @@ func (s *Server) ReportStdlib() { // report goes to that editor only. const mixMissingMessage = "Dexter: could not find the `mix` binary, so formatting does not work in this editor. Install the Elixir version of this project (for example `mise install`) or put mix on the PATH of the editor, then restart the editor." -// reportFormatWorks clears the formatter conditions of one Mix project after a -// format succeeded there. The conditions are kept for each project: in an -// umbrella or a monorepo, one project can fail to format while another works, -// and a success in one must not clear, or set again, the report of the other. -func (s *Server) reportFormatWorks(mixRoot, buildRoot string) { - r := s.index.reporter - cleared := r.Clear(condFormatter+":"+mixRoot, "") - if r.Clear(condOTP+":"+mixRoot, "") { - cleared = true +// otpMismatchRetry is how long a build root whose BEAM failed with an OTP +// mismatch uses mix format before Dexter tries the BEAM again, when nothing +// that can fix the mismatch changed first. A variable so tests can shrink it. +var otpMismatchRetry = 10 * time.Minute + +// otpMismatch remembers a BEAM that failed with an OTP mismatch. +type otpMismatch struct { + at time.Time + stamp string +} + +// otpStamp identifies what can fix an OTP mismatch for a build root: the +// Elixir and mix binaries, and the _build directory. +func (s *Server) otpStamp(buildRoot string) string { + elixir := filepath.Join(filepath.Dir(s.mixBin), "elixir") + return fmt.Sprint(statFileStamp(elixir), statFileStamp(s.mixBin), statFileStamp(filepath.Join(buildRoot, "_build"))) +} + +// beamOTPMismatch records that the BEAM of buildRoot failed with an OTP +// mismatch, and tells the user one time. Formatting still works through mix +// format, so it is a degraded state, not a failure. +func (s *Server) beamOTPMismatch(buildRoot string) { + s.beamMu.Lock() + if s.otpMismatches == nil { + s.otpMismatches = make(map[string]otpMismatch) + } + s.otpMismatches[buildRoot] = otpMismatch{at: time.Now(), stamp: s.otpStamp(buildRoot)} + s.beamMu.Unlock() + s.index.reporter.Set(condOTP+":"+buildRoot, notify.Warning, fmt.Sprintf( + "Dexter: Elixir/OTP version mismatch in %s: the Elixir install of this project was compiled for a newer OTP version than the one that runs, so the fast persistent formatter cannot start. Formatting still works through the slower `mix format` fallback. To fix it, update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27). Dexter tries the fast formatter again when the Elixir install or the _build directory changes, or after %s.", + buildRoot, otpMismatchRetry)) +} + +// otpMismatchHolds reports whether the BEAM of buildRoot failed with an OTP +// mismatch that nothing has fixed since. The caller holds beamMu. +func (s *Server) otpMismatchHolds(buildRoot string) bool { + m, ok := s.otpMismatches[buildRoot] + if !ok { + return false + } + if time.Since(m.at) < otpMismatchRetry && m.stamp == s.otpStamp(buildRoot) { + return true } - if buildRoot != mixRoot && r.Clear(condOTP+":"+buildRoot, "") { - cleared = true + delete(s.otpMismatches, buildRoot) + return false +} + +// reportBeamFormatWorks clears the formatter conditions after the persistent +// BEAM formatted a file. Only this ends an OTP mismatch of the build root: a +// mix format fallback works around the mismatch and does not fix it. +// +// Conditions are kept for each project: in an umbrella or a monorepo, one +// project can fail to format while another works, and a success in one must +// not clear, or set again, the report of the other. +func (s *Server) reportBeamFormatWorks(mixRoot, buildRoot string) { + r := s.index.reporter + formatter := r.Clear(condFormatter+":"+mixRoot, "") + if r.Clear(condOTP+":"+buildRoot, "") { + r.Notify(notify.Info, fmt.Sprintf("Dexter: the fast persistent formatter works again in %s.", buildRoot)) + return } - if cleared { + if formatter { r.Notify(notify.Info, fmt.Sprintf("Dexter: formatting works again in %s.", mixRoot)) } } +// reportMixFormatWorks clears the report that formatting does not work in +// mixRoot after a mix format succeeded there. +func (s *Server) reportMixFormatWorks(mixRoot string) { + s.index.reporter.Clear(condFormatter+":"+mixRoot, fmt.Sprintf("Dexter: formatting works again in %s.", mixRoot)) +} + // reportFormatFailure tells the user that formatting cannot run in one Mix // project. A syntax error in the user's code is not a failure of Dexter: it // already shows as a diagnostic, or mix reports it. @@ -291,6 +345,11 @@ func (s *Server) reportFormatFailure(mixRoot string, err error, stderr string) { if isUserCodeFormatError(stderr) { return } + if isOTPMismatch(stderr) { + s.index.reporter.Set(condFormatter+":"+mixRoot, notify.Error, fmt.Sprintf( + "Dexter: formatting does not work in %s: Elixir/OTP version mismatch. The Elixir install of this project was compiled for a newer OTP version than the one that runs. Update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27).", mixRoot)) + return + } detail := err.Error() if line := firstErrorLine(stderr); line != "" { detail = line diff --git a/internal/lsp/report_test.go b/internal/lsp/report_test.go index c3a29d5..b60421c 100644 --- a/internal/lsp/report_test.go +++ b/internal/lsp/report_test.go @@ -320,7 +320,7 @@ func TestFormatterFailuresAreKeptForEachProject(t *testing.T) { } } format := func(mixRoot string) error { - _, err := server.formatWithMixFormat(context.Background(), mixRoot, mixRoot, filepath.Join(mixRoot, "lib", "a.ex"), "x\n") + _, err := server.formatWithMixFormat(context.Background(), mixRoot, filepath.Join(mixRoot, "lib", "a.ex"), "x\n") return err } @@ -348,13 +348,11 @@ func TestFormatterFailuresAreKeptForEachProject(t *testing.T) { } // A later success in the broken project is what clears its report. - server.reportFormatWorks(broken, broken) + server.reportMixFormatWorks(broken) client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: formatting works again in "+broken+".") - if !server.notifyOTPMismatch(good, "** (UndefinedFunctionError) requires a more recent Erlang/OTP") { - t.Fatal("OTP mismatch was not recognized") - } - client.WaitMessage(t, reportWait, protocol.MessageTypeError, "Elixir/OTP version mismatch in "+good) + server.beamOTPMismatch(good) + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Elixir/OTP version mismatch in "+good) other := filepath.Join(server.projectRoot, "apps", "other") if err := os.MkdirAll(other, 0o755); err != nil { t.Fatal(err) diff --git a/internal/lsp/server.go b/internal/lsp/server.go index db38417..1f0385d 100644 --- a/internal/lsp/server.go +++ b/internal/lsp/server.go @@ -160,6 +160,9 @@ type Server struct { beams map[string]*beamProcess // build root → persistent BEAM process beamMu sync.Mutex + // otpMismatches are the build roots whose BEAM failed with an OTP + // mismatch, guarded by beamMu. See otpMismatchHolds. + otpMismatches map[string]otpMismatch erlangBuildRoots map[string]*erlangBuildRootState // build root → runtime resolution state erlangRuntimeCache map[string]*erlangRuntimeCache // runtime key → cached OTP modules/exports @@ -796,16 +799,10 @@ func (s *Server) watchGitHead() { }() } -// notifyOTPMismatch checks stderr output for an OTP version mismatch and, when -// it finds one, makes it a condition of the project at root, so every editor -// shows it once and the user does not have to dig through logs. It reports -// whether it found one. -func (s *Server) notifyOTPMismatch(root, stderr string) bool { - if !strings.Contains(stderr, "requires a more recent Erlang/OTP") { - return false - } - s.index.reporter.Set(condOTP+":"+root, notify.Error, fmt.Sprintf("Dexter: Elixir/OTP version mismatch in %s: the Elixir install for this project was compiled for a newer OTP version than the one that runs, so formatting does not work. Update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27).", root)) - return true +// isOTPMismatch reports whether BEAM or mix output says that the Elixir install +// was compiled for a newer OTP than the one that runs. +func isOTPMismatch(stderr string) bool { + return strings.Contains(stderr, "requires a more recent Erlang/OTP") } // === LSP Lifecycle === From de8a45529ccf4a031bbb4dc3a070667167a47c33 Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 19:58:30 -0400 Subject: [PATCH 3/7] Show one formatter condition when mix also has the OTP mismatch The BEAM OTP mismatch always set a Warning that formatting still works through the slower `mix format` fallback. When the fallback failed with the same mismatch, reportFormatFailure also set an Error that formatting does not work. The two conditions have different keys, so the editor showed both, and they contradict each other. Now a failed BEAM start only records the mismatch for its build root. The formatter decides what to tell the user after the `mix format` fallback ran: - The fallback works: the Warning that formatting is only slower. - The fallback fails with the mismatch: only the Error; the Warning is cleared without a message. - Any other fallback failure, such as a syntax error, changes nothing. When mix format works again, the Error ends ("formatting works again") and the Warning applies, one time. The mismatch is recorded before the fallback runs, so the first save already gets the right condition. A recorded mismatch still stops a BEAM start on each save, and the Warning still clears only when the BEAM formats. Co-Authored-By: Claude Opus 5.5 --- docs/architecture.md | 2 +- internal/lsp/formatter.go | 45 +++++++++++++++++++---- internal/lsp/otp_mismatch_test.go | 59 +++++++++++++++++++++++++++++-- internal/lsp/report.go | 41 +++++++++++++++++---- internal/lsp/report_test.go | 3 +- 5 files changed, 132 insertions(+), 18 deletions(-) diff --git a/docs/architecture.md b/docs/architecture.md index 24e6a28..a53505d 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -250,7 +250,7 @@ What is reported, and what stays in the log only: | The workspace has no Elixir standard library (read from the root that all sessions share, not from what one session found) | `stdlib` | Warning | yes | | `mix` not found for one session | (this editor only) | Warning | — | | `mix format` cannot run in one Mix project | `formatter:` | Warning (Error for an OTP mismatch) | yes ("formatting works again in ") | -| The persistent formatter BEAM fails with an Elixir/OTP mismatch; formatting goes on through `mix format` | `formatter.otp:` | Warning | only when the BEAM formats again ("the fast persistent formatter works again"); a `mix format` success does not clear it. The build root does not start a BEAM again until the Elixir or mix binary or `_build` changes, or for 10 minutes | +| The persistent formatter BEAM fails with an Elixir/OTP mismatch, and the `mix format` fallback works (when the fallback fails with the same mismatch, only the `formatter:` Error shows) | `formatter.otp:` | Warning | only when the BEAM formats again ("the fast persistent formatter works again"); a `mix format` success does not clear it. The build root does not start a BEAM again until the Elixir or mix binary or `_build` changes, or for 10 minutes | | A rename that could not change some files | (this editor only) | Error | — | A syntax error in the user's code is not a formatter failure: it is a diagnostic. WAL checkpoint warnings, fsnotify transient errors, the per-directory watch errors (they are in the aggregate), BEAM formatter restarts that fall back to `mix format`, and requests that waited for the first build stay in the log. diff --git a/internal/lsp/formatter.go b/internal/lsp/formatter.go index b5e0d4b..9740fc5 100644 --- a/internal/lsp/formatter.go +++ b/internal/lsp/formatter.go @@ -758,7 +758,7 @@ func (s *Server) startBeamProcess(buildRoot string) (*beamProcess, error) { _ = cmd.Process.Kill() <-done if isOTPMismatch(stderrBuf.String()) { - s.beamOTPMismatch(buildRoot) + s.rememberOTPMismatch(buildRoot) } } case <-time.After(beamStuckTimeout): @@ -864,14 +864,14 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin bp := s.getBeamProcess(ctx, buildRoot) if bp == nil { log.Printf("Formatting: BEAM process unavailable, falling back to mix format") - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatFallback(ctx, mixRoot, buildRoot, path, content) } if bp.formatterConfigChanged(formatterExs) { s.evictBeam(bp, fmt.Sprintf("formatter config changed: %s", formatterExs)) bp = s.getBeamProcess(ctx, buildRoot) if bp == nil { log.Printf("Formatting: BEAM process unavailable after formatter config change, falling back to mix format") - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatFallback(ctx, mixRoot, buildRoot, path, content) } _ = bp.formatterConfigChanged(formatterExs) } @@ -881,8 +881,9 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin case <-bp.ready: if bp.startErr != nil { s.evictBeam(bp, fmt.Sprintf("formatContent: startup finished with error: %v", bp.startErr)) + s.noteBeamStartFailure(bp, buildRoot) log.Printf("Formatting: BEAM process failed to start, falling back to mix format: %v", bp.startErr) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatFallback(ctx, mixRoot, buildRoot, path, content) } default: // Not ready yet — decide based on how long it's been starting @@ -891,11 +892,11 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin case age > beamStuckTimeout: log.Printf("Formatting: BEAM process stuck (started %s ago), restarting", age.Truncate(time.Second)) s.evictBeam(bp, fmt.Sprintf("formatContent: startup exceeded %s without becoming ready", beamStuckTimeout)) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatFallback(ctx, mixRoot, buildRoot, path, content) case age > beamWaitTimeout: log.Printf("Formatting: BEAM process not ready after %s, falling back to mix format", age.Truncate(time.Millisecond)) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatFallback(ctx, mixRoot, buildRoot, path, content) default: if err := bp.Ready(ctx); err != nil { @@ -903,8 +904,9 @@ func (s *Server) formatContent(ctx context.Context, mixRoot, path, content strin return "", err } s.evictBeam(bp, fmt.Sprintf("formatContent: Ready failed: %v", err)) + s.noteBeamStartFailure(bp, buildRoot) log.Printf("Formatting: BEAM process failed to start, falling back to mix format: %v", err) - return s.formatWithMixFormat(ctx, mixRoot, path, content) + return s.formatFallback(ctx, mixRoot, buildRoot, path, content) } } } @@ -958,6 +960,32 @@ func (s *Server) evictBeam(bp *beamProcess, reason string) { bp.closeWithReason("evicted: " + reason) } +// formatFallback formats with mix format when the persistent BEAM cannot, and +// then decides what an OTP mismatch of the BEAM means for the user. That is +// known only now: when mix format works, formatting is only slower; when mix +// format fails with the same mismatch, formatting does not work, and +// reportFormatFailure already says so. +func (s *Server) formatFallback(ctx context.Context, mixRoot, buildRoot, path, content string) (string, error) { + out, err := s.formatWithMixFormat(ctx, mixRoot, path, content) + if ctx.Err() == nil { + s.reportBeamOTP(buildRoot, err) + } + return out, err +} + +// noteBeamStartFailure records an OTP mismatch of a BEAM that failed to start, +// before the fallback runs, so that the fallback can report it. The process +// was just killed; its stderr is complete when it has exited. +func (s *Server) noteBeamStartFailure(bp *beamProcess, buildRoot string) { + select { + case <-bp.cmd.done: + case <-time.After(2 * time.Second): + } + if bp.stderr != nil && isOTPMismatch(bp.stderr.String()) { + s.rememberOTPMismatch(buildRoot) + } +} + // formatWithMixFormat runs `mix format` in mixRoot. It is the fallback when the // persistent BEAM cannot serve, so its success says nothing about the BEAM: it // clears only the report that formatting does not work in mixRoot. @@ -976,6 +1004,9 @@ func (s *Server) formatWithMixFormat(ctx context.Context, mixRoot, path, content if ctx.Err() == nil { s.reportFormatFailure(mixRoot, err, stderr.String()) } + if isOTPMismatch(stderr.String()) { + return "", fmt.Errorf("%w: %v", errOTPMismatch, err) + } return "", err } log.Printf("Formatting: %s (%s, mix format)", path, time.Since(start)) diff --git a/internal/lsp/otp_mismatch_test.go b/internal/lsp/otp_mismatch_test.go index cd0fc97..3ab311e 100644 --- a/internal/lsp/otp_mismatch_test.go +++ b/internal/lsp/otp_mismatch_test.go @@ -20,7 +20,7 @@ const otpMismatchStderr = "** (UndefinedFunctionError) function :erlang.foo/0 is // otpMismatchProject makes a fake Elixir install whose elixir binary fails // with an OTP mismatch and counts its starts, and whose mix formats by echoing -// its input. It returns the server, its editor, and the path of the start log. +// its input unless a "mixfails" file exists next to it. It returns the server, its editor, and the path of the start log. func otpMismatchProject(t *testing.T) (*Server, *notifytest.Client, string) { t.Helper() server, cleanup := setupTestServer(t) @@ -29,7 +29,8 @@ func otpMismatchProject(t *testing.T) (*Server, *notifytest.Client, string) { starts := filepath.Join(bin, "starts") scripts := map[string]string{ "elixir": "#!/bin/sh\necho start >> " + starts + "\necho '" + otpMismatchStderr + "' >&2\nexit 1\n", - "mix": "#!/bin/sh\ncat\n", + // mix fails with the same mismatch while a "mixfails" file exists. + "mix": "#!/bin/sh\nif [ -e " + filepath.Join(bin, "mixfails") + " ]; then echo '" + otpMismatchStderr + "' >&2; exit 1; fi\ncat\n", } for name, script := range scripts { if err := os.WriteFile(filepath.Join(bin, name), []byte(script), 0o755); err != nil { @@ -181,3 +182,57 @@ func TestOTPMismatchClearsWhenTheBeamStarts(t *testing.T) { t.Errorf("the failing BEAM started %d times, want 1", n) } } + +// When mix format fails with the same mismatch as the BEAM, formatting does not +// work at all. The user must see only that Error, never also the Warning that +// formatting still works through mix format. When mix works again, the Error +// ends and the Warning applies, once. +func TestOTPMismatchInBeamAndMixShowsOnlyTheError(t *testing.T) { + server, client, starts := otpMismatchProject(t) + mixFails := filepath.Join(filepath.Dir(starts), "mixfails") + if err := os.WriteFile(mixFails, nil, 0o644); err != nil { + t.Fatal(err) + } + path := filepath.Join(server.projectRoot, "lib", "a.ex") + content := "defmodule A do\nend\n" + for i := 0; i < 3; i++ { + if _, err := server.formatContent(context.Background(), server.projectRoot, path, content); err == nil { + t.Fatal("formatting worked although mix fails") + } + } + client.WaitMessage(t, reportWait, protocol.MessageTypeError, "formatting does not work in "+server.projectRoot+": Elixir/OTP version mismatch") + time.Sleep(50 * time.Millisecond) + if n := countMessages(client, "still works"); n != 0 { + t.Fatalf("the user was told that formatting still works while it does not:\n%s", client.Dump()) + } + var formatterConditions []string + for _, c := range server.index.reporter.Conditions() { + if strings.HasPrefix(c.Key, condFormatter) { + formatterConditions = append(formatterConditions, c.Key) + } + } + if len(formatterConditions) != 1 || formatterConditions[0] != condFormatter+":"+server.projectRoot { + t.Fatalf("formatter conditions = %v, want only the Error", formatterConditions) + } + + if err := os.Remove(mixFails); err != nil { + t.Fatal(err) + } + for i := 0; i < 3; i++ { + if got := formatOnce(t, server, content); got != content { + t.Fatalf("format = %q, want %q", got, content) + } + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: formatting works again in "+server.projectRoot+".") + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Formatting still works through the slower `mix format` fallback") + time.Sleep(50 * time.Millisecond) + if n := countMessages(client, "still works"); n != 1 { + t.Errorf("got %d Warnings, want 1:\n%s", n, client.Dump()) + } + if server.index.reporter.Active(condFormatter + ":" + server.projectRoot) { + t.Error("the Error is still active after mix format worked") + } + if n := beamStarts(t, starts); n != 1 { + t.Errorf("the failing BEAM started %d times, want 1", n) + } +} diff --git a/internal/lsp/report.go b/internal/lsp/report.go index 930a022..80dc12a 100644 --- a/internal/lsp/report.go +++ b/internal/lsp/report.go @@ -284,19 +284,46 @@ func (s *Server) otpStamp(buildRoot string) string { return fmt.Sprint(statFileStamp(elixir), statFileStamp(s.mixBin), statFileStamp(filepath.Join(buildRoot, "_build"))) } -// beamOTPMismatch records that the BEAM of buildRoot failed with an OTP -// mismatch, and tells the user one time. Formatting still works through mix -// format, so it is a degraded state, not a failure. -func (s *Server) beamOTPMismatch(buildRoot string) { +// errOTPMismatch marks a mix format that failed with an OTP mismatch. +var errOTPMismatch = errors.New("Elixir/OTP version mismatch") + +// rememberOTPMismatch records that the BEAM of buildRoot failed with an OTP +// mismatch, so that it is not started again on each save. It reports nothing: +// what the mismatch means for the user depends on the mix format fallback, +// and reportBeamOTP decides that. +func (s *Server) rememberOTPMismatch(buildRoot string) { s.beamMu.Lock() + defer s.beamMu.Unlock() if s.otpMismatches == nil { s.otpMismatches = make(map[string]otpMismatch) } + if _, ok := s.otpMismatches[buildRoot]; ok { + return + } s.otpMismatches[buildRoot] = otpMismatch{at: time.Now(), stamp: s.otpStamp(buildRoot)} +} + +// reportBeamOTP tells the user about an OTP mismatch of the BEAM of buildRoot +// after a mix format fallback ran with result err. Only one of two +// conditions may show: when the fallback worked, a Warning that formatting is +// only slower; when the fallback failed with the same mismatch, the Error from +// reportFormatFailure alone, so this Warning is cleared without a message. +// Any other fallback failure, such as a syntax error, changes nothing. +func (s *Server) reportBeamOTP(buildRoot string, err error) { + s.beamMu.Lock() + holds := s.otpMismatchHolds(buildRoot) s.beamMu.Unlock() - s.index.reporter.Set(condOTP+":"+buildRoot, notify.Warning, fmt.Sprintf( - "Dexter: Elixir/OTP version mismatch in %s: the Elixir install of this project was compiled for a newer OTP version than the one that runs, so the fast persistent formatter cannot start. Formatting still works through the slower `mix format` fallback. To fix it, update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27). Dexter tries the fast formatter again when the Elixir install or the _build directory changes, or after %s.", - buildRoot, otpMismatchRetry)) + key := condOTP + ":" + buildRoot + switch { + case !holds: + return + case err == nil: + s.index.reporter.Set(key, notify.Warning, fmt.Sprintf( + "Dexter: Elixir/OTP version mismatch in %s: the Elixir install of this project was compiled for a newer OTP version than the one that runs, so the fast persistent formatter cannot start. Formatting still works through the slower `mix format` fallback. To fix it, update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27). Dexter tries the fast formatter again when the Elixir install or the _build directory changes, or after %s.", + buildRoot, otpMismatchRetry)) + case errors.Is(err, errOTPMismatch): + s.index.reporter.Clear(key, "") + } } // otpMismatchHolds reports whether the BEAM of buildRoot failed with an OTP diff --git a/internal/lsp/report_test.go b/internal/lsp/report_test.go index b60421c..f2787d7 100644 --- a/internal/lsp/report_test.go +++ b/internal/lsp/report_test.go @@ -351,7 +351,8 @@ func TestFormatterFailuresAreKeptForEachProject(t *testing.T) { server.reportMixFormatWorks(broken) client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: formatting works again in "+broken+".") - server.beamOTPMismatch(good) + server.rememberOTPMismatch(good) + server.reportBeamOTP(good, nil) client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Elixir/OTP version mismatch in "+good) other := filepath.Join(server.projectRoot, "apps", "other") if err := os.MkdirAll(other, 0o755); err != nil { From 24c67b51fb4691c713315c3482197915660249d4 Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 20:05:31 -0400 Subject: [PATCH 4/7] Keep the umbrella OTP warning stable under alternate saves The Warning that the fast formatter cannot start belongs to a build root, which the Mix projects of an umbrella share. reportBeamOTP cleared it whenever one project's mix format also failed with the OTP mismatch, and set it again when another project's mix format worked. Saves that alternated between two such projects sent the Warning again each time. Now each remembered BEAM mismatch keeps the last fallback outcome of each Mix project on its build root. The Warning is active while at least one project's fallback works. It is cleared, without a message, only when no project's fallback works; each of those projects then has its own Error. A fallback failure for another cause changes nothing, and setting an active Warning sends nothing. The outcomes go away with the remembered mismatch, so the memory is bounded by the number of Mix projects. Co-Authored-By: Claude Opus 5.5 --- docs/architecture.md | 2 +- internal/lsp/formatter.go | 2 +- internal/lsp/otp_mismatch_test.go | 69 +++++++++++++++++++++++++++++++ internal/lsp/report.go | 47 +++++++++++++++------ internal/lsp/report_test.go | 2 +- 5 files changed, 107 insertions(+), 15 deletions(-) diff --git a/docs/architecture.md b/docs/architecture.md index a53505d..2199b7d 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -250,7 +250,7 @@ What is reported, and what stays in the log only: | The workspace has no Elixir standard library (read from the root that all sessions share, not from what one session found) | `stdlib` | Warning | yes | | `mix` not found for one session | (this editor only) | Warning | — | | `mix format` cannot run in one Mix project | `formatter:` | Warning (Error for an OTP mismatch) | yes ("formatting works again in ") | -| The persistent formatter BEAM fails with an Elixir/OTP mismatch, and the `mix format` fallback works (when the fallback fails with the same mismatch, only the `formatter:` Error shows) | `formatter.otp:` | Warning | only when the BEAM formats again ("the fast persistent formatter works again"); a `mix format` success does not clear it. The build root does not start a BEAM again until the Elixir or mix binary or `_build` changes, or for 10 minutes | +| The persistent formatter BEAM fails with an Elixir/OTP mismatch, and the last `mix format` fallback of at least one Mix project on that build root works (when no project's fallback works, only their `formatter:` Errors show) | `formatter.otp:` | Warning | only when the BEAM formats again ("the fast persistent formatter works again"); a `mix format` success does not clear it. The build root does not start a BEAM again until the Elixir or mix binary or `_build` changes, or for 10 minutes | | A rename that could not change some files | (this editor only) | Error | — | A syntax error in the user's code is not a formatter failure: it is a diagnostic. WAL checkpoint warnings, fsnotify transient errors, the per-directory watch errors (they are in the aggregate), BEAM formatter restarts that fall back to `mix format`, and requests that waited for the first build stay in the log. diff --git a/internal/lsp/formatter.go b/internal/lsp/formatter.go index 9740fc5..b735e53 100644 --- a/internal/lsp/formatter.go +++ b/internal/lsp/formatter.go @@ -968,7 +968,7 @@ func (s *Server) evictBeam(bp *beamProcess, reason string) { func (s *Server) formatFallback(ctx context.Context, mixRoot, buildRoot, path, content string) (string, error) { out, err := s.formatWithMixFormat(ctx, mixRoot, path, content) if ctx.Err() == nil { - s.reportBeamOTP(buildRoot, err) + s.reportBeamOTP(buildRoot, mixRoot, err) } return out, err } diff --git a/internal/lsp/otp_mismatch_test.go b/internal/lsp/otp_mismatch_test.go index 3ab311e..3cdd507 100644 --- a/internal/lsp/otp_mismatch_test.go +++ b/internal/lsp/otp_mismatch_test.go @@ -236,3 +236,72 @@ func TestOTPMismatchInBeamAndMixShowsOnlyTheError(t *testing.T) { t.Errorf("the failing BEAM started %d times, want 1", n) } } + +// In an umbrella, the Mix projects share one build root and so one BEAM and +// one Warning. When one project's mix format also fails with the mismatch and +// another's works, saves that alternate between them must not drop and set the +// Warning again each time. +func TestOTPMismatchInUmbrellaIsStableUnderAlternateSaves(t *testing.T) { + server, client, starts := otpMismatchProject(t) + bin := filepath.Dir(starts) + aFails := filepath.Join(bin, "afails") + script := "#!/bin/sh\ncase \"$PWD\" in */apps/a) if [ -e " + aFails + " ]; then echo '" + otpMismatchStderr + "' >&2; exit 1; fi ;; esac\ncat\n" + if err := os.WriteFile(server.mixBin, []byte(script), 0o755); err != nil { + t.Fatal(err) + } + if err := os.WriteFile(aFails, nil, 0o644); err != nil { + t.Fatal(err) + } + appA := filepath.Join(server.projectRoot, "apps", "a") + appB := filepath.Join(server.projectRoot, "apps", "b") + for _, dir := range []string{appA, appB} { + if err := os.MkdirAll(filepath.Join(dir, "lib"), 0o755); err != nil { + t.Fatal(err) + } + } + content := "defmodule A do\nend\n" + save := func(app string) error { + got, err := server.formatContent(context.Background(), app, filepath.Join(app, "lib", "x.ex"), content) + if err == nil && got != content { + t.Fatalf("format in %s = %q, want %q", app, got, content) + } + return err + } + + for i, app := range []string{appA, appB, appA, appB, appA} { + err := save(app) + if app == appA && err == nil { + t.Fatalf("save %d in app a worked although its mix fails", i+1) + } + if app == appB && err != nil { + t.Fatalf("save %d in app b failed: %v", i+1, err) + } + } + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Formatting still works through the slower `mix format` fallback") + client.WaitMessage(t, reportWait, protocol.MessageTypeError, "formatting does not work in "+appA) + time.Sleep(50 * time.Millisecond) + if n := countMessages(client, "still works"); n != 1 { + t.Errorf("alternate saves sent %d Warnings, want 1:\n%s", n, client.Dump()) + } + if n := countMessages(client, "formatting does not work in "+appA); n != 1 { + t.Errorf("got %d Errors for app a, want 1:\n%s", n, client.Dump()) + } + + if err := os.Remove(aFails); err != nil { + t.Fatal(err) + } + if err := save(appA); err != nil { + t.Fatalf("app a did not format after its mix works: %v", err) + } + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: formatting works again in "+appA+".") + time.Sleep(50 * time.Millisecond) + if n := countMessages(client, "still works"); n != 1 { + t.Errorf("the Warning was sent again:\n%s", client.Dump()) + } + if !server.index.reporter.Active(condOTP + ":" + server.projectRoot) { + t.Error("the Warning is not active although the BEAM still cannot start") + } + if n := beamStarts(t, starts); n != 1 { + t.Errorf("the failing BEAM started %d times, want 1", n) + } +} diff --git a/internal/lsp/report.go b/internal/lsp/report.go index 80dc12a..0db4515 100644 --- a/internal/lsp/report.go +++ b/internal/lsp/report.go @@ -275,6 +275,11 @@ var otpMismatchRetry = 10 * time.Minute type otpMismatch struct { at time.Time stamp string + // fallbackWorks is the last mix format outcome of each Mix project that + // uses this build root: true when it formatted, false when it failed with + // the same mismatch. It is bounded by the number of Mix projects, and it + // goes away with the entry. + fallbackWorks map[string]bool } // otpStamp identifies what can fix an OTP mismatch for a build root: the @@ -300,28 +305,46 @@ func (s *Server) rememberOTPMismatch(buildRoot string) { if _, ok := s.otpMismatches[buildRoot]; ok { return } - s.otpMismatches[buildRoot] = otpMismatch{at: time.Now(), stamp: s.otpStamp(buildRoot)} + s.otpMismatches[buildRoot] = otpMismatch{at: time.Now(), stamp: s.otpStamp(buildRoot), fallbackWorks: make(map[string]bool)} } // reportBeamOTP tells the user about an OTP mismatch of the BEAM of buildRoot -// after a mix format fallback ran with result err. Only one of two -// conditions may show: when the fallback worked, a Warning that formatting is -// only slower; when the fallback failed with the same mismatch, the Error from -// reportFormatFailure alone, so this Warning is cleared without a message. -// Any other fallback failure, such as a syntax error, changes nothing. -func (s *Server) reportBeamOTP(buildRoot string, err error) { +// after the mix format fallback of mixRoot ran with result err. +// +// The Warning that formatting is only slower belongs to the build root, which +// the Mix projects of an umbrella share, so it depends on all of them. It is +// active while at least one project's last fallback worked. It is cleared, +// without a message, only when no project's fallback works: each of those +// projects then has its own Error from reportFormatFailure, and the Warning +// would contradict them. A fallback failure for another cause, such as a +// syntax error, changes nothing. Setting an active Warning sends nothing, so +// saves in any order do not repeat it. +func (s *Server) reportBeamOTP(buildRoot, mixRoot string, err error) { s.beamMu.Lock() - holds := s.otpMismatchHolds(buildRoot) + if !s.otpMismatchHolds(buildRoot) { + s.beamMu.Unlock() + return + } + m := s.otpMismatches[buildRoot] + switch { + case err == nil: + m.fallbackWorks[mixRoot] = true + case errors.Is(err, errOTPMismatch): + m.fallbackWorks[mixRoot] = false + } + anyWorks, known := false, len(m.fallbackWorks) > 0 + for _, works := range m.fallbackWorks { + anyWorks = anyWorks || works + } s.beamMu.Unlock() + key := condOTP + ":" + buildRoot switch { - case !holds: - return - case err == nil: + case anyWorks: s.index.reporter.Set(key, notify.Warning, fmt.Sprintf( "Dexter: Elixir/OTP version mismatch in %s: the Elixir install of this project was compiled for a newer OTP version than the one that runs, so the fast persistent formatter cannot start. Formatting still works through the slower `mix format` fallback. To fix it, update Erlang to match, or switch to an Elixir build that targets your current OTP (for example elixir@...-otp-27). Dexter tries the fast formatter again when the Elixir install or the _build directory changes, or after %s.", buildRoot, otpMismatchRetry)) - case errors.Is(err, errOTPMismatch): + case known: s.index.reporter.Clear(key, "") } } diff --git a/internal/lsp/report_test.go b/internal/lsp/report_test.go index f2787d7..7d3231e 100644 --- a/internal/lsp/report_test.go +++ b/internal/lsp/report_test.go @@ -352,7 +352,7 @@ func TestFormatterFailuresAreKeptForEachProject(t *testing.T) { client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: formatting works again in "+broken+".") server.rememberOTPMismatch(good) - server.reportBeamOTP(good, nil) + server.reportBeamOTP(good, good, nil) client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Elixir/OTP version mismatch in "+good) other := filepath.Join(server.projectRoot, "apps", "other") if err := os.MkdirAll(other, 0o755); err != nil { From 2c20607da4b47fc9426059e1efcd738ee22cd050 Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 20:12:21 -0400 Subject: [PATCH 5/7] Apply each OTP warning decision in order reportBeamOTP updated the fallback outcomes of a build root and decided whether the shared OTP Warning applies under beamMu, but did the Set or Clear after it released the lock. A concurrent format could apply a newer decision first; the older one could then clear the Warning although another Mix project's last fallback still worked. The outcomes were also kept for each session, while the Warning is shared by all sessions. Now the outcomes are on the IndexCoordinator, next to the reporter, and one lock covers each update and the Set or Clear that it decides. The reporter's lock is a leaf (it only queues and logs), so this cannot deadlock. A BEAM format drops the outcomes of its build root and clears the Warning under the same lock. reportFormatFailure and the mix format success only set or clear the condition of their own Mix project from their own result, so they have no stale decision to apply. Co-Authored-By: Claude Opus 5.5 --- internal/lsp/otp_mismatch_test.go | 91 +++++++++++++++++++++++++++++++ internal/lsp/report.go | 61 ++++++++++++++++----- internal/lsp/server.go | 1 + 3 files changed, 138 insertions(+), 15 deletions(-) diff --git a/internal/lsp/otp_mismatch_test.go b/internal/lsp/otp_mismatch_test.go index 3cdd507..68b36bd 100644 --- a/internal/lsp/otp_mismatch_test.go +++ b/internal/lsp/otp_mismatch_test.go @@ -3,11 +3,14 @@ package lsp import ( "context" "encoding/binary" + "fmt" "io" "os" "os/exec" "path/filepath" "strings" + "sync" + "sync/atomic" "testing" "time" @@ -305,3 +308,91 @@ func TestOTPMismatchInUmbrellaIsStableUnderAlternateSaves(t *testing.T) { t.Errorf("the failing BEAM started %d times, want 1", n) } } + +// A decision about the shared OTP Warning must not apply after a newer one. +// The hook pauses an older decision (app a failed, nothing works yet: clear) +// while a newer one (app b works: set) runs. The Warning must end active. +func TestOTPDecisionsApplyInOrder(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + server.mixBin = filepath.Join(t.TempDir(), "mix") + buildRoot := server.projectRoot + appA := filepath.Join(buildRoot, "apps", "a") + appB := filepath.Join(buildRoot, "apps", "b") + server.rememberOTPMismatch(buildRoot) + + paused := make(chan struct{}) + resume := make(chan struct{}) + var calls atomic.Int32 + otpApplyHook = func() { + if calls.Add(1) == 1 { + close(paused) + <-resume + } + } + t.Cleanup(func() { otpApplyHook = nil }) + + older := make(chan struct{}) + go func() { + defer close(older) + server.reportBeamOTP(buildRoot, appA, fmt.Errorf("%w: exit status 1", errOTPMismatch)) + }() + <-paused + newer := make(chan struct{}) + go func() { + defer close(newer) + server.reportBeamOTP(buildRoot, appB, nil) + }() + select { + case <-newer: + case <-time.After(100 * time.Millisecond): + } + close(resume) + <-older + <-newer + if !server.index.reporter.Active(condOTP + ":" + buildRoot) { + t.Fatal("an older decision cleared the Warning after a newer one set it, although app b still formats") + } +} + +// Many concurrent formats in two Mix projects on one build root, one whose +// fallback works and one whose fallback fails with the mismatch, must end with +// the Warning active and sent once. +func TestConcurrentFormatsKeepTheOTPWarning(t *testing.T) { + server, client, starts := otpMismatchProject(t) + aFails := filepath.Join(filepath.Dir(starts), "afails") + script := "#!/bin/sh\ncase \"$PWD\" in */apps/a) if [ -e " + aFails + " ]; then echo '" + otpMismatchStderr + "' >&2; exit 1; fi ;; esac\ncat\n" + if err := os.WriteFile(server.mixBin, []byte(script), 0o755); err != nil { + t.Fatal(err) + } + if err := os.WriteFile(aFails, nil, 0o644); err != nil { + t.Fatal(err) + } + apps := []string{filepath.Join(server.projectRoot, "apps", "a"), filepath.Join(server.projectRoot, "apps", "b")} + for _, app := range apps { + if err := os.MkdirAll(filepath.Join(app, "lib"), 0o755); err != nil { + t.Fatal(err) + } + } + // Remember the mismatch first, as the first save does, so that every + // concurrent format below takes the fallback. + _, _ = server.formatContent(context.Background(), apps[1], filepath.Join(apps[1], "lib", "x.ex"), "x\n") + + var wg sync.WaitGroup + for i := 0; i < 40; i++ { + app := apps[i%2] + wg.Add(1) + go func() { + defer wg.Done() + _, _ = server.formatContent(context.Background(), app, filepath.Join(app, "lib", "x.ex"), "x\n") + }() + } + wg.Wait() + if !server.index.reporter.Active(condOTP + ":" + server.projectRoot) { + t.Fatal("the Warning is not active although app b still formats") + } + time.Sleep(50 * time.Millisecond) + if n := countMessages(client, "still works"); n != 1 { + t.Errorf("the Warning was sent %d times, want 1:\n%s", n, client.Dump()) + } +} diff --git a/internal/lsp/report.go b/internal/lsp/report.go index 0db4515..ee7f999 100644 --- a/internal/lsp/report.go +++ b/internal/lsp/report.go @@ -275,13 +275,25 @@ var otpMismatchRetry = 10 * time.Minute type otpMismatch struct { at time.Time stamp string - // fallbackWorks is the last mix format outcome of each Mix project that - // uses this build root: true when it formatted, false when it failed with - // the same mismatch. It is bounded by the number of Mix projects, and it - // goes away with the entry. - fallbackWorks map[string]bool } +// otpOutcomes is the last mix format fallback outcome of each Mix project on a +// build root whose BEAM failed with an OTP mismatch: true when it formatted, +// false when it failed with the same mismatch. It is shared by every session, +// like the reporter, and mu orders each update with the Set or Clear that it +// decides, so an older decision cannot apply after a newer one. mu is taken +// before the reporter's lock, which is a leaf: the reporter only queues. +// Memory is bounded by the build roots and Mix projects of the workspace; a +// build root's outcomes go when its BEAM formats. +type otpOutcomes struct { + mu sync.Mutex + fallbackWorks map[string]map[string]bool // build root → Mix project → works +} + +// otpApplyHook runs between the decision of reportBeamOTP and its Set or Clear. +// Tests use it to force an order of concurrent formats. +var otpApplyHook func() + // otpStamp identifies what can fix an OTP mismatch for a build root: the // Elixir and mix binaries, and the _build directory. func (s *Server) otpStamp(buildRoot string) string { @@ -305,7 +317,7 @@ func (s *Server) rememberOTPMismatch(buildRoot string) { if _, ok := s.otpMismatches[buildRoot]; ok { return } - s.otpMismatches[buildRoot] = otpMismatch{at: time.Now(), stamp: s.otpStamp(buildRoot), fallbackWorks: make(map[string]bool)} + s.otpMismatches[buildRoot] = otpMismatch{at: time.Now(), stamp: s.otpStamp(buildRoot)} } // reportBeamOTP tells the user about an OTP mismatch of the BEAM of buildRoot @@ -321,22 +333,36 @@ func (s *Server) rememberOTPMismatch(buildRoot string) { // saves in any order do not repeat it. func (s *Server) reportBeamOTP(buildRoot, mixRoot string, err error) { s.beamMu.Lock() - if !s.otpMismatchHolds(buildRoot) { - s.beamMu.Unlock() + holds := s.otpMismatchHolds(buildRoot) + s.beamMu.Unlock() + if !holds { return } - m := s.otpMismatches[buildRoot] + + o := &s.index.otp + o.mu.Lock() + defer o.mu.Unlock() + if o.fallbackWorks == nil { + o.fallbackWorks = make(map[string]map[string]bool) + } + outcomes := o.fallbackWorks[buildRoot] + if outcomes == nil { + outcomes = make(map[string]bool) + o.fallbackWorks[buildRoot] = outcomes + } switch { case err == nil: - m.fallbackWorks[mixRoot] = true + outcomes[mixRoot] = true case errors.Is(err, errOTPMismatch): - m.fallbackWorks[mixRoot] = false + outcomes[mixRoot] = false } - anyWorks, known := false, len(m.fallbackWorks) > 0 - for _, works := range m.fallbackWorks { + anyWorks, known := false, len(outcomes) > 0 + for _, works := range outcomes { anyWorks = anyWorks || works } - s.beamMu.Unlock() + if otpApplyHook != nil { + otpApplyHook() + } key := condOTP + ":" + buildRoot switch { @@ -373,7 +399,12 @@ func (s *Server) otpMismatchHolds(buildRoot string) bool { func (s *Server) reportBeamFormatWorks(mixRoot, buildRoot string) { r := s.index.reporter formatter := r.Clear(condFormatter+":"+mixRoot, "") - if r.Clear(condOTP+":"+buildRoot, "") { + o := &s.index.otp + o.mu.Lock() + delete(o.fallbackWorks, buildRoot) + otpCleared := r.Clear(condOTP+":"+buildRoot, "") + o.mu.Unlock() + if otpCleared { r.Notify(notify.Info, fmt.Sprintf("Dexter: the fast persistent formatter works again in %s.", buildRoot)) return } diff --git a/internal/lsp/server.go b/internal/lsp/server.go index 1f0385d..2aa238d 100644 --- a/internal/lsp/server.go +++ b/internal/lsp/server.go @@ -112,6 +112,7 @@ type IndexCoordinator struct { failures fileFailures // firstBuildReported makes the first-build report once per workspace. firstBuildReported atomic.Bool + otp otpOutcomes // see reportBeamOTP } func (c *IndexCoordinator) setStdlibRoot(root string) (string, bool) { From 176d0b9232646d4ec0204618521f94a01d3dfbb7 Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 20:36:52 -0400 Subject: [PATCH 6/7] Make a full build replace the set of failed files A full build recorded the files that it could not read or parse, but it never removed a file from the set. When the only files of a project failed, the index stayed empty, and the next pass was a full build again. That build could index those files, or they could be gone, but the warning that they could not be indexed stayed. A full build sees every file, so its failures are now collected during the build and, when the build succeeds, replace the whole set. A file that was indexed or is gone drops out, and the condition clears with its "indexed now" message. When the build fails, the incremental walk that follows sets each file and drops the ones it did not see, as before. The other paths already keep the set exact: the incremental walk marks each file and keeps only what it saw, a single-file write marks that file, and a removal drops the path and everything below it. Co-Authored-By: Claude Opus 5.5 --- internal/lsp/report.go | 41 ++++++++++++++++++++++++++++++++++++ internal/lsp/report_test.go | 42 +++++++++++++++++++++++++++++++++++++ internal/lsp/server.go | 7 ++++++- 3 files changed, 89 insertions(+), 1 deletion(-) diff --git a/internal/lsp/report.go b/internal/lsp/report.go index ee7f999..5aeb3ea 100644 --- a/internal/lsp/report.go +++ b/internal/lsp/report.go @@ -110,6 +110,47 @@ func (f *fileFailures) removed(path string) { f.count.Store(int32(len(f.paths))) } +// replace makes the set equal to the failures of a full build, which saw +// every file: a file that was indexed, or that is gone, is no longer a failure. +func (f *fileFailures) replace(paths map[string]string) { + if f.count.Load() == 0 && len(paths) == 0 { + return + } + f.mu.Lock() + defer f.mu.Unlock() + if len(paths) != len(f.paths) { + f.changed.Store(true) + } else { + for path := range paths { + if _, ok := f.paths[path]; !ok { + f.changed.Store(true) + break + } + } + } + f.paths = paths + f.count.Store(int32(len(paths))) +} + +// buildFailures collects the files that a full build could not read or parse. +// The parse workers call add concurrently. +type buildFailures struct { + mu sync.Mutex + paths map[string]string +} + +func (b *buildFailures) add(path string, err error) { + if errors.Is(err, fs.ErrNotExist) { + return + } + b.mu.Lock() + defer b.mu.Unlock() + if b.paths == nil { + b.paths = make(map[string]string) + } + b.paths[path] = err.Error() +} + // retain drops failures for files that a full walk did not see: they are gone // or no longer belong to the workspace. func (f *fileFailures) retain(seen map[string]struct{}) { diff --git a/internal/lsp/report_test.go b/internal/lsp/report_test.go index 7d3231e..cfb50b2 100644 --- a/internal/lsp/report_test.go +++ b/internal/lsp/report_test.go @@ -216,6 +216,48 @@ func TestRemovedDirectoryEndsItsFileFailures(t *testing.T) { client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "all files that could not be indexed are indexed now") } +// A full build sees every file, so after it the failures are exactly its own. +// A file that failed in an earlier build and is now indexed, or gone, must end +// the warning. The index stays empty after a build in which the only file +// failed, so the next pass is a full build again. +func TestFullBuildReplacesFileFailures(t *testing.T) { + if os.Geteuid() == 0 { + t.Skip("root can read files without read permission") + } + for _, fix := range []string{"readable", "deleted"} { + t.Run(fix, func(t *testing.T) { + server, cleanup := setupTestServer(t) + defer cleanup() + path := writeTestFile(t, server.projectRoot, "lib/only.ex", "defmodule Only do\nend\n") + if err := os.Chmod(path, 0); err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = os.Chmod(path, 0o644) }) + client := attachFakeEditor(t, server, false) + server.backgroundReindex() + server.index.backgroundWork.Wait() + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "1 file could not be indexed: "+path) + if !server.store.IsEmpty() { + t.Fatal("the index is not empty, so the next pass is not a full build") + } + + if fix == "readable" { + if err := os.Chmod(path, 0o644); err != nil { + t.Fatal(err) + } + } else if err := os.Remove(path); err != nil { + t.Fatal(err) + } + server.backgroundReindex() + server.index.backgroundWork.Wait() + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "all files that could not be indexed are indexed now") + if server.index.reporter.Active(CondIndexFiles) { + t.Error("the warning is still active") + } + }) + } +} + // A file that went away during a walk is not a failure. func TestMissingFileIsNotAFailure(t *testing.T) { var f fileFailures diff --git a/internal/lsp/server.go b/internal/lsp/server.go index 2aa238d..b3713cb 100644 --- a/internal/lsp/server.go +++ b/internal/lsp/server.go @@ -504,17 +504,22 @@ func (s *Server) fullBuild() (stats indexer.Stats, ran bool, err error) { return indexer.Stats{}, false, nil } + var failed buildFailures stats, err = indexer.FullBuild(s.store, s.projectRoot, indexer.Options{ StdlibRoot: s.StdlibRoot(), InProcess: true, Warn: func(format string, args ...interface{}) { log.Printf("Warning: "+format, args...) }, - FileError: s.index.failures.fail, + FileError: failed.add, }) if errors.Is(err, indexer.ErrUnindexed) { s.index.unavailable = true } + if err == nil { + // The build saw every file, so its failures are the whole set. + s.index.failures.replace(failed.paths) + } return stats, true, err } From b6c0e119ba212ea56eca6cbd033c8486ce628e13 Mon Sep 17 00:00:00 2001 From: Jesse Herrick Date: Sat, 3 Oct 2026 21:01:16 -0400 Subject: [PATCH 7/7] Show one progress for a cold build that falls back When the fast cold build fails, the incremental pass indexes the files. The cold build already shows its own progress, and the old walk counted progress only on a warm pass; the move of the reporting hooks into the reconcile pipeline lost that guard, so the fallback could start a second "updating the index" progress for the same work. The pass now gets the progress counter only when it is warm. A test hook makes the fast build fail; TestColdBuildFallbackShowsOneProgress fails without the fix. Co-Authored-By: Claude Opus 5.5 --- internal/lsp/report_test.go | 28 ++++++++++++++++++++++++++++ internal/lsp/server.go | 17 ++++++++++++++++- 2 files changed, 44 insertions(+), 1 deletion(-) diff --git a/internal/lsp/report_test.go b/internal/lsp/report_test.go index 41928da..eab7ddc 100644 --- a/internal/lsp/report_test.go +++ b/internal/lsp/report_test.go @@ -511,3 +511,31 @@ func TestReconcilePathsReportFailuresAndProgress(t *testing.T) { }) } } + +// When the fast cold build fails, the incremental fallback indexes the files. +// The build already shows its own progress, so the fallback must not start a +// second "updating the index" progress for the same work. +func TestColdBuildFallbackShowsOneProgress(t *testing.T) { + oldThreshold := reconcileProgressThreshold + reconcileProgressThreshold = 3 + t.Cleanup(func() { reconcileProgressThreshold = oldThreshold }) + testHookFullBuild = func() error { return errors.New("bulk load failed") } + t.Cleanup(func() { testHookFullBuild = nil }) + + server, cleanup := setupTestServer(t) + defer cleanup() + for i := 0; i < 6; i++ { + writeTestFile(t, server.projectRoot, fmt.Sprintf("lib/gen%d.ex", i), moduleSource(i, 0)) + } + client := attachFakeEditor(t, server, false) + reindexOnce(t, server) + + client.WaitMessage(t, reportWait, protocol.MessageTypeWarning, "Dexter: the fast index build failed") + client.WaitMessage(t, reportWait, protocol.MessageTypeInfo, "Dexter: index built") + if n := countMessages(client, "updating the index"); n != 0 { + t.Errorf("the fallback started a second progress for the cold build:\n%s", client.Dump()) + } + if r, _ := server.store.LookupFunction("MyApp.Gen5", "run_v0"); len(r) != 1 { + t.Error("the fallback did not index the files") + } +} diff --git a/internal/lsp/server.go b/internal/lsp/server.go index 9c0df43..cec6c75 100644 --- a/internal/lsp/server.go +++ b/internal/lsp/server.go @@ -525,12 +525,21 @@ func (s *Server) detachFromReporter() { // reliably or undone on a live pool — leaving WAL needs exclusive access, and // the per-connection ones land on whichever pooled connection happens to serve // them. They were also the smallest part of the win. +// testHookFullBuild, when set by a test, makes the fast full build fail with +// its error, so that the incremental fallback runs. +var testHookFullBuild func() error + func (s *Server) fullBuild() (stats indexer.Stats, ran bool, err error) { s.index.writes.Lock() defer s.index.writes.Unlock() if !s.store.IsEmpty() { return indexer.Stats{}, false, nil } + if testHookFullBuild != nil { + if err := testHookFullBuild(); err != nil { + return indexer.Stats{}, true, err + } + } var failed buildFailures stats, err = indexer.FullBuild(s.store, s.projectRoot, indexer.Options{ @@ -655,7 +664,13 @@ func (s *Server) startBackgroundReindex() <-chan struct{} { // prune lives in the same branch and so cannot run without the walk // that fills `seen`. if !fullBuilt { - seen, n, ok := s.reconcileChangedFiles(&progress) + // A cold build that fell back to this pass already shows its + // own progress; the pass counts its files only when it is warm. + var passProgress *reconcileProgress + if !coldStart { + passProgress = &progress + } + seen, n, ok := s.reconcileChangedFiles(passProgress) reindexed += n if ok { s.pruneMissingFiles(seen)