Skip to content

Add a NameRes autocomplete log-analysis notebook and replayable Solr benchmark - #107

Draft
gaurav wants to merge 15 commits into
mainfrom
nameres-log-analysis
Draft

Add a NameRes autocomplete log-analysis notebook and replayable Solr benchmark#107
gaurav wants to merge 15 commits into
mainfrom
nameres-log-analysis

Conversation

@gaurav

@gaurav gaurav commented Jul 6, 2026

Copy link
Copy Markdown
Collaborator

NameRes autocomplete queries are a small slice of traffic — ~3% of lookups — and by far the worst-behaved slice. In a mixed 16,461-row CloudWatch export, autocomplete p95 Solr wait was 2,803 ms against 43 ms for exact-match lookups, with a p99 of 264 seconds. They are also the most latency-sensitive requests NameRes serves, because a user is waiting on them between keystrokes.

This PR adds a marimo notebook that characterizes that workload from production logs and distils it into a benchmark we can replay against a Solr backend and an ElasticSearch one, so the two can be compared on real queries rather than synthetic ones. It also moves the existing NodeNorm notebook into log-analysis/nodenorm/ and writes down how to work on marimo notebooks in this repo.

What's here

log-analysis/nameres/analyze_nameres_logs.py — a marimo notebook, autocomplete-only. It loads every data/log-analysis/nameres-autocomplete-only-*.json export, parses each Solr lookup log line into a QueryLogEntry, and reports latency by result limit and query-length bucket, slow-query rates, the slowest individual lookups, and inferred typing chains. It emits two artifacts: a replayable JSON benchmark (one case per unique query+params, carrying the observed Solr baseline) and a per-lookup CSV.

Multi-export loading with an overlap guard. Logs Insights exports are plain time-window dumps with no per-record ID, so two exports covering the same window would silently double-count the same lookups and bias every statistic with no visible symptom. The loader computes each file's span from the raw @timestamp values in a first pass and refuses to proceed if two spans intersect, naming the offending pairs and their windows. Spans are treated as closed intervals, so exports that merely touch at an endpoint are also rejected.

Autocomplete-only, by deliberate choice. The notebook started out analysing all lookups. Mixing the two modes made every aggregate a weighted average of two populations that behave nothing alike, so exact-match analysis was split out (#139) and the filter moved upstream into the CloudWatch query itself:

SOURCE "[application logs]" START=-10w END=now
| fields @timestamp, @message, @logStream, @log
| filter @message like /Lookup query to Solr.*autocomplete=True/
| sort @timestamp desc
| limit 10000

That filter is selective enough that a 10-week window returns 607 rows — well under the 10,000-row cap — so unlike the general exports, this is the complete autocomplete population for its window rather than a sample of it. The loader's glob is correspondingly narrow (nameres-autocomplete-only-*), because the general exports share a directory and would both dilute the analysis and trip the overlap guard.

Typing chains. An autocomplete log line is one keystroke's worth of a query, so diab alone says little. Consecutive lookups are joined into a chain when they share a request shape (limit plus every filter), one query is a case-insensitive prefix of the other, and they fall within a tunable gap — reconstructing diabdiabediabetes type 2. The logs carry no session or user ID, so this is a heuristic, and it is documented as one: it merges concurrent identical requests from different callers, and splits a user who pauses. The result is not sensitive to the threshold — between a 30 s and a 60 s gap the chain count moves under 3%, because the median gap between prefix-compatible queries is ~2 s.

Two "final term" columns are emitted because they answer different questions and disagree whenever a user backspaces at the end: final_query (chronologically last — what they were left looking at) and longest_query (the fullest term they ever typed). On the real data, salis → salisylic → … → salic gives salic and salisylic respectively.

What it produces

From the current 607-row export (2026-08-03 → 2026-09-01, 399 inferred chains):

  • log-analysis/nameres/output/nameres_autocomplete_terms_<span>.csv — one row per lookup: query, time, solr_wait_ms, final_query, longest_query, plus chain position and request parameters.
  • log-analysis/nameres/benchmark/nameres_autocomplete_solr_benchmark_<span>.json — 416 replayable cases, each with baseline_solr percentiles observed in production. Nothing consumes it yet; the replay harness is Build the Solr-vs-ElasticSearch replay harness for the NameRes benchmark #141.

Both are gitignored, along with exports/. Generated artifacts are named after the log window they cover so two runs over different exports cannot overwrite each other.

One finding worth surfacing on its own: the six slowest lookups in the whole export were the same query, vitamin a, issued 35 ms apart — concurrent, not sequential — each blocking on Solr for 4.4 to 5.4 minutes at limit=100 with a single Biolink type filter. That is 6 of the only 7 lookups exceeding 60 s, against a median of 48.5 ms. Filed upstream as NCATSTranslator/NameResolution#306.

Supporting changes

  • Tests (tests/log_analysis/, 30 tests, marked unit). marimo notebooks are not importable as modules — the directory name has a hyphen and cells are @app.cell functions — but they load by path, and Cell.run() executes a cell plus its ancestors and hands back its definitions. The notebook's pure helpers live in their own data-free cells (parser, span_helpers, chain_helpers) specifically so this works without the uncommitted log exports. Covers field extraction, SLOW QUERY detection, loud failure on unparseable lookup lines, filter normalization, span computation, all four overlap shapes, and chain assignment including backspacing, case-insensitivity, gap splits, request-shape isolation and index alignment.
  • log-analysis/CLAUDE.md — how to drive a live marimo notebook via marimo._code_mode, the graph rules, cm.get_context() gotchas, path handling, how to test notebook logic, and how to export for sharing.
  • NodeNorm notebook moved to log-analysis/nodenorm/, so the two services sit side by side.
  • pandas/numpy added as dependencies; marimo[recommended] as a dev dependency.

Decisions a reader would otherwise have to reverse-engineer

  • Paths anchor on mo.notebook_dir(), never the process cwd. marimo inherits the cwd of whatever launched it, so a cwd-relative Path("benchmark") resolves next to the notebook when opened from its own directory and at the repo root when opened from there — which is how generated artifacts ended up outside the .gitignore written to catch them, silently, because both spellings appear to work.
  • pod_name and image_tag are parsed but kept off df. df is the one frame rendered whole, so it is the only place a parsed field reaches the shared HTML export; every other displayed table names its columns explicitly. Nothing here analyses either field. They stay on entries for a future notebook comparing NameRes releases (Report NameRes latency per typing chain, not just per lookup #142).
  • Exports are shared out of band, not through this repo. marimo export html produces a self-contained file that opens with nothing installed and cannot be forked by accident, which is why it is preferred over .ipynb. Its rendered outputs embed every query string real users typed, so exports/ is gitignored.
  • The root .gitignore needs both data/ and data — the first matches a directory, the second also matches a worktree's symlink to a shared one.

What this deliberately does not do

Follow-on issues

Before merging

  • This branch is 138 commits behind main. Merge or rebase before landing — main has since added pytest-xdist, the github_issues test source and a reworked tests.yaml, none of which this branch has seen. The pyproject.toml [tool.pytest.ini_options] block is touched on both sides and will want attention.
  • pandas and numpy are in [project] dependencies, but nothing in src/babel_validation/ imports either — only the notebook and its tests do. They probably belong in the dev dependency group alongside marimo[recommended], so installing the package doesn't drag in pandas for nothing.

TODO: size NameRes's bulk-lookup concurrency limit

Not addressed by this PR — it needs /bulk-lookup request logs, which this notebook does not read. Worth splitting into its own issue if it isn't going to happen here.

NCATSTranslator/NameResolution#273 makes /bulk-lookup run its per-string lookups against Solr concurrently instead of one at a time, bounded by SOLR_MAX_CONCURRENT_LOOKUPS, currently defaulted to 100. That number is a guess: it was picked to be high enough to help large requests while still capping the fan-out, without knowing what NameRes is actually asked to do.

The bound applies per request, so what Solr sees at peak is roughly SOLR_MAX_CONCURRENT_LOOKUPS × (concurrent /bulk-lookup requests). At 100, ten simultaneous bulk lookups is already ~1,000 queries in flight. That is the product this log analysis needs to pin down.

  • From the NameRes logs, establish (a) the peak number of /bulk-lookup requests in flight at once, and (b) the distribution of strings lengths per request, particularly the tail. Together those give the peak concurrent Solr query count implied by any given limit, and show whether the limit binds on real traffic at all — if the p99 request carries 20 strings, a limit of 100 never engages and the value doesn't matter. Then set SOLR_MAX_CONCURRENT_LOOKUPS in NameResolution accordingly (it is settable by environment variable, so it can be tuned per deployment without a code change).

TODO: make chain inference cheap enough for a wider log window

  • assign_chains walks the frame with iterrows() and rebuilds a request_shape tuple from the list-valued filter columns on every row. Imperceptible at 607 rows, but the chain gap is a mo.ui.slider, so every drag re-runs the chain build and the CSV export downstream of it. Before widening the export window, precompute the shape column once and iterate over itertuples/NumPy arrays. If the slider still lags at ~10k rows, debounce it or move the chain build behind an mo.ui.run_button.
How this PR got here — kept for anyone tracing why a particular line looks the way it does; the durable conclusions are above and in the code.
  • The notebook was first built against a single hard-coded log file (logs/nameres-log-analytics-results-2026-07-06.json) that did not exist in the worktree. It then grew multi-file loading over data/log-analysis/nameres-*, and only afterwards was narrowed to autocomplete-only — which is why the overlap guard, written for the general case, is what now forces the autocomplete exports into their own glob.
  • Analysis was originally split by mode (autocomplete vs exact) throughout. Every one of those splits became a no-op when exact lookups left, and was replaced by a split on result limit and query-length bucket. box_by_mode became box_by_qlen.
  • Generated artifacts initially landed in benchmark/ and output/ at the repo root, because the paths were cwd-relative and marimo had been launched from there — past log-analysis/nameres/.gitignore, which existed to catch exactly those files. Fixed by anchoring on mo.notebook_dir(); the trap is recorded in log-analysis/CLAUDE.md.
  • The first read of the vitamin a chain described it as ~29 minutes of Solr wait "across the chain", by summing six waits. Checking the timestamps showed the six requests were 35 ms apart and therefore concurrent, so the sum is of overlapping intervals and the elapsed time is ~5 minutes, not 29. The upstream issue describes the concurrent reading.
  • The export was generated once with pod_name and image_tag still in df, embedding the Kubernetes pod name and image tag in a file meant to be shared outside the project. Dropped from df and re-exported; the .gitignore and CLAUDE.md notes that had justified gitignoring exports/ because of those fields were corrected, since a stale reason is worse than none — someone could read it and conclude the export is now safe to commit.
  • The test file was added without pytestmark = pytest.mark.unit. main's only pytest job is pytest -m unit, so all 30 tests would have been silently deselected on merge — the same failure Publish a daily cross-repository Babel milestones page as part of the dashboard site #112 shipped. Marker added, and unit registered in pyproject.toml verbatim from main so the two merge cleanly.

gaurav and others added 8 commits July 6, 2026 18:39
Start a marimo notebook (analyze_nameres_logs.py) that parses NameRes Solr
lookup logs into a QueryLogEntry dataclass and pandas DataFrame, mirroring the
NodeNorm log analysis notebook. This first commit covers loading only: the
dataclass, a regex parser for both INFO and "SLOW QUERY" WARNING log lines, and
DataFrame construction with derived columns (filter flags, app overhead, mode).

- Add pandas/numpy as project dependencies (needed by the notebook).
- gitignore the raw log JSON exports and marimo's __marimo__ session cache.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Headline metrics (request counts, time span, filter usage) plus a latency
percentile table (mean/p50/p90/p95/p99/max) for total time, Solr wait, and app
overhead, broken down by query mode. Surfaces that autocomplete queries are far
slower than exact lookups and that Solr wait dominates total latency.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
marimo-native Altair charts characterizing query performance:

- Reactive latency histogram (metric/scale/range controls)
- Total latency by query mode (box plot, log scale)
- Solr wait by result limit and mode
- Median Solr wait vs query length
- Query length distribution
- Temporal coverage of the export (with sampling caveat)
- Slow-query rate by limit and mode, plus a table of the slowest lookups

The charts confirm autocomplete + high-limit + very short queries are the
pathological cases (single-character autocomplete lookups take minutes on Solr).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Deduplicate the log to one case per unique (query, params) combination and
attach each case's observed Solr baseline latency (n, p50/p95 Solr wait, p50
took, ever_slow, first/last seen). Write the set to benchmark/ as JSON and offer
an in-notebook download button. Replaying these cases against an ElasticSearch
backend and comparing to baseline_solr yields an apples-to-apples latency
comparison on real production queries.

The generated benchmark/ artifact is gitignored (regenerated from the
uncommitted logs), consistent with keeping raw logs out of the repo.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Add a "Next steps" section spelling out the follow-up work to turn this
Solr-log characterization into a Solr-vs-ElasticSearch comparison: a replay
harness over the exported benchmark, latency comparison against baseline_solr,
result-quality parity (not just speed), pulling a more representative log
sample, extra breakdowns (filters, pod/image), and a CSV export variant.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Document lessons from pair-programming the NameRes notebook: use uv (not
.venv/pip), the running kernel is source of truth (drive via marimo._code_mode),
the cm.get_context() rollback gotcha (never reference a just-created cell inside
the same block), verifying cells without Playwright screenshots, marimo graph
rules, Altair row-limit/interactivity notes, and git hygiene for logs and
generated artifacts.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Adds a new log-analysis/ workflow for analyzing NameRes production query logs and exporting a replayable benchmark dataset, aligning with the existing NodeNorm log-analysis efforts.

Changes:

  • Add a marimo-based NameRes log analysis notebook that parses CloudWatch exports, computes summary stats, and exports benchmark cases.
  • Add log-analysis documentation and .gitignore rules to keep raw logs and generated artifacts out of git.
  • Update Python dependencies to support the notebook tooling (marimo/Altair + pandas/numpy).

Reviewed changes

Copilot reviewed 5 out of 8 changed files in this pull request and generated 4 comments.

Show a summary per file
File Description
pyproject.toml Adds data/analysis dependencies and a dependency-groups.dev section for marimo tooling.
log-analysis/nodenorm/logs/README.md Documents how to export NodeNorm logs from CloudWatch Logs Insights.
log-analysis/nameres/logs/.gitignore Ignores raw NameRes log exports (*.json).
log-analysis/nameres/analyze_nameres_logs.py New marimo notebook for parsing NameRes lookup logs, visualizing latency, and exporting a benchmark JSON.
log-analysis/nameres/.gitignore Ignores marimo cache and generated benchmark artifacts.
log-analysis/CLAUDE.md Adds contributor guidance for working on the log-analysis notebooks and dependency management via uv.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread pyproject.toml
Comment on lines 14 to 18
"pytest>=8.4.2",
"pytest-timeout>=2.4.0",
"pandas>=3.0.3",
"numpy>=2.4.6",
]
Comment thread pyproject.toml
Comment on lines +39 to +41
dev = [
"marimo[recommended]>=0.23.13",
]
Comment thread pyproject.toml
Comment on lines +16 to +17
"pandas>=3.0.3",
"numpy>=2.4.6",
Comment on lines +123 to +126
message = record.get("@message")
line = message["log"] if isinstance(message, dict) else message
if not line or "Lookup query to Solr" not in line:
return None
gaurav added a commit to NCATSTranslator/NameResolution that referenced this pull request Aug 31, 2026
10 was a conservative first guess. Solr can take considerably more strain than
that, and large bulk requests -- the ones the limit actually binds on -- are
exactly the case the parallelization was meant to speed up.

Note that the bound is per request, not per process, so the queries in flight
against Solr is this multiplied by the number of concurrent bulk lookups being
served. Whether 100 is the right number therefore depends on the real request
rate, which is being measured in TranslatorSRI/babel-validation#107.

The concurrency test can no longer exceed the limit by sending real strings,
since the test data has only 66 distinct labels, so it now patches the limit down
instead. That works because bulk_lookup() builds its semaphore per request rather
than at import.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
gaurav added a commit to NCATSTranslator/NameResolution that referenced this pull request Aug 31, 2026
…s in parallel (#273)

Adds an `exact` parameter to `/lookup` and `/bulk-lookup`, so that
callers who already know the string they are looking for can ask for
whole-string matching instead of the default tokenized search, and sends
the individual lookups behind `/bulk-lookup` concurrently instead of one
at a time. The motivating case is named entity recognition pipelines,
which resolve large numbers of exact strings in bulk and pay for
relevance ranking they never use.

Closes #258.

## What's here

**Exact matching.** When `exact` is set, the eDisMax query is bypassed
entirely in favour of a Solr filter query against the `*_exactish`
fields. Those are indexed with a keyword tokenizer and a lowercase
filter, so the whole string must match, case-insensitively — `parkinson`
does not match the label `parkinsonian disorder`, but `Parkinsonian
Disorder` does.

| `exact`     | Matches against                                      |
| ----------- | ---------------------------------------------------- |
| `label`     | The preferred name only (`preferred_name_exactish`)  |
| `synonyms`  | The synonyms only (`names_exactish`)                 |
| `any`       | Either                                               |
| _(omitted)_ | Nothing changes — the usual tokenized eDisMax search |

`label` and `synonyms` can genuinely disagree, because a concept's
preferred name is not necessarily one of its synonyms — HP:0001300 is
`preferred_name="parkinsonian disorder"` with `names=["Parkinsonian
disease"]`, and neither string appears in the other field. That is why
the two modes are separate rather than one boolean, and it is also a
data problem in its own right:
[NCATSTranslator/Babel#1073](NCATSTranslator/Babel#1073)
proposes putting each clique's preferred name into its synonyms.

**Interaction with the other parameters.** Three of them behaved badly
with `exact`, all silently, and all now do something defensible:

- `autocomplete=true` was ignored. It treats the final word as an
incomplete prefix, which contradicts matching the whole string, so the
combination is now a `400` rather than a request that quietly does
something else. The rejection lives in `lookup()`, so it applies to
`/bulk-lookup` too.
- The smart-quote rewrite (#176) was applied to the exact query. The
`*_exactish` fields do no punctuation folding, so the indexed value
keeps whichever quote characters Babel emitted; folding the query
searched for a string the caller had not typed, and put any label
containing a typographic quote out of reach. Exact mode no longer folds.
The default path is unaffected, because StandardTokenizer discards the
punctuation anyway.
- `highlighting=true` returned empty arrays, because the query is `*:*`
and the exactish fields are not stored, so Solr had nothing to mark up.
Since every exact match is a whole-value match, the highlighting is now
synthesized from the returned document — the entire matching name, in
its own capitalisation, wrapped in the same `<strong>` tags the default
path asks Solr for. Callers no longer have to care which mode produced
the field.

**Parallel bulk lookup.** `bulk_lookup()` issues its Solr queries with
`asyncio.gather()` rather than awaiting them one at a time, bounded by a
semaphore of `SOLR_MAX_CONCURRENT_LOOKUPS` (default 100). The bound is
not optional: `NameResQuery.strings` has no upper limit, so an unbounded
gather would open one socket per string and could exhaust the process's
file descriptors and stampede Solr. Sequential execution used to make
that impossible, so the parallelization is what introduces the hazard
and the semaphore is what contains it.

The limit applies per request rather than per process, so the queries in
flight against Solr is that number multiplied by the number of bulk
lookups being served at once. 100 is set deliberately high on the
assumption that Solr can take the strain; sizing it against real traffic
is being worked out in
[TranslatorSRI/babel-validation#107](TranslatorSRI/babel-validation#107),
and it is an environment variable so it can be retuned per deployment
without a code change.

Two hazards that parallelism sharpened are closed off with it. The limit
is clamped to at least 1, since `SOLR_MAX_CONCURRENT_LOOKUPS=0` would
build a semaphore nobody can acquire and hang every bulk request with no
error and no log line. And Solr queries now have a timeout
(`SOLR_TIMEOUT_SECONDS`, default 60) instead of `timeout=None`:
sequentially a stalled connection held up one query, but concurrently it
can pin an otherwise-complete bulk request indefinitely while holding a
semaphore slot.

**The default search is not "fuzzy".** Documentation and parameter
descriptions called it that; it never was. `LowerTextField` is a
`StandardTokenizer` and a `LowerCaseFilter` with no stemming, stopwords,
synonyms or ngrams, and `lookup()` escapes Solr's `~` operator out of
the query string, so no caller can request edit-distance matching
either. The default search is _tokenized_: it matches the query's tokens
in any order, rewarding order and adjacency with score rather than
requiring them, and treats the final token as a prefix when
`autocomplete=true`. Calling it fuzzy invited callers to expect typo
tolerance the service has never had.

**Documentation.** `documentation/API.md` gained an "Exact matching"
section, the `exact` parameter and the notes above — that file
enumerates every `/lookup` parameter and shows a complete `/bulk-lookup`
body, so omitting `exact` would have made it wrong rather than merely
incomplete. `documentation/Deployment.md` gained the two new environment
variables, the OpenAPI service blurb now mentions exact mode alongside
autocomplete, and `CLAUDE.md` gained a Gotchas section for the three
things here that a reader cannot infer from the code.

## What it produces

Exact matching is cheaper than the equivalent tokenized search because
there is nothing to score: no eDisMax parsing, no phrase or field
boosts, just a term lookup against a field holding each name as a single
token. Bulk requests of ordinary size now complete in roughly the time
of their slowest lookup rather than the sum of all of them.

The exactish filter is marked `{!cache=false}` on purpose. Solr's
filterCache is bounded by entry count (512 in `solrconfig.xml`), and
what it holds are the shared, reusable filters — `types:`, `taxa:`,
`curie:` — that nearly every search benefits from. An exactish clause is
one distinct entry per distinct search string, so caching it would let a
single bulk NER request evict the whole cache and slow down the
_ordinary_ search path as collateral damage, for a hit rate near zero on
its own entries. Repeated identical exact lookups are still served from
the queryResultCache, which caches the whole result and is bounded by
RAM.

Because there is no relevance score to rank by in exact mode, results
are sorted by `clique_identifier_count DESC, curie_suffix ASC` instead
of the usual `score DESC, …`. The `score` field is still present in each
result but carries no ranking information.

## What it deliberately does not do

- **No stemming, normalisation, or punctuation folding beyond
lowercasing.** Exact means exact; a caller who wants looser matching
already has the default search.
- **No cap on `strings`.** The semaphore throttles a large bulk request
rather than rejecting it, so existing clients sending long lists keep
working and simply queue.
- **No change to which cliques the default search returns.** With
`exact` omitted the generated Solr query is what it was before; the only
behavioural difference anywhere is the Solr client's timeout, which used
to be unbounded.

## Tests

44, all against a live Solr in CI. Beyond the exact-match modes
themselves, several encode promises that a change elsewhere could
quietly break: that the default search ignores word order but does not
tolerate misspellings, that the exactish filter still reaches Solr
marked uncached, that exact matching composes with the `biolink_type`
and prefix filters, that the `autocomplete`/`exact` rejection survives
being raised inside `asyncio.gather()`, and that a bulk lookup carrying
more strings than the concurrency limit still returns every one of them
correctly keyed.

The exact-match cases live in `tests/test_exact_mode.py`, following the
repository's existing habit of splitting tests by topic;
`tests/test_service.py` keeps the ones that are about the default search
or about bulk lookup generally.

## Before merging

Nothing blocking.

Two things to pick up afterwards, both tracked outside this PR because
neither can be settled from inside it:

-
[TranslatorSRI/babel-validation#107](TranslatorSRI/babel-validation#107)
— confirm `SOLR_MAX_CONCURRENT_LOOKUPS = 100` against the real request
rate, specifically the peak number of concurrent `/bulk-lookup` requests
and the tail of the `strings`-length distribution, whose product is what
Solr actually sees. Needs log analysis, and the value is an environment
variable, so it does not gate this.
-
[NCATSTranslator/Babel#1073](NCATSTranslator/Babel#1073)
— put each clique's preferred name into its synonyms. If that lands,
`exact=synonyms` and `exact=any` converge for most cliques, and the
three-way split is worth revisiting _then_ rather than pre-emptively
now.
gaurav and others added 4 commits September 1, 2026 15:55
The notebook read a single hard-coded CloudWatch dump
(logs/nameres-log-analytics-results-2026-07-06.json) that does not exist in
this worktree. It now globs data/log-analysis/nameres-*.json and concatenates
every export, so widening the analysis window is a matter of dropping another
dump into the directory.

Logs Insights exports are plain time-window dumps with no per-record ID, so two
exports covering the same window would silently double-count the same lookups
and bias every statistic downstream. The loader therefore computes each file's
span from the raw @timestamp values in a first pass and raises before any
parsing if two spans overlap, naming the offending pairs and their windows.
De-duplicating overlapping exports is left as future work (noted in the
next-steps cell).

Each QueryLogEntry now carries a source_file for provenance, and the loader
renders a per-file summary table (records, lookups, span).

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
`data/` matches a real directory but not a symlink named `data`, which is how
the worktrees reach the shared log-export directory — so the symlink showed up
as untracked in every `git status`. Ignore both spellings.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Autocomplete is ~3% of NameRes traffic and behaves nothing like the rest of it:
in a mixed export, autocomplete p95 Solr wait was ~2.8s against ~43ms for exact
lookups, with a p99 of several minutes. Mixing the two made every aggregate a
weighted average of two unrelated populations, so this notebook now analyses
autocomplete alone; exact-match analysis will get its own notebook over the
general `nameres-*` exports, reusing this parser.

The loader globs `nameres-autocomplete-only-*.json` — deliberately narrower than
`nameres-*`, because the general exports share the directory and would both
dilute the analysis and trip the overlapping-span check. The autocomplete filter
is applied at CloudWatch query time (`@message like
/Lookup query to Solr.*autocomplete=True/`), which is selective enough that a
10-week window lands under the 10,000-row cap: the export is the complete
autocomplete population for its window, not a sample of it. Every by-mode split
was replaced with a split by result limit and query-length bucket.

New: inferred typing chains. The logs carry no session or user ID, so
consecutive lookups are joined when they share a request shape (limit plus all
filters), one query is a case-insensitive prefix of the other (so backspacing
also extends a chain), and they fall within a tunable gap. That reconstructs
`diab` -> `diabe` -> `diabetes type 2`, giving each keystroke a final search
term. The result is insensitive to the threshold: between a 30s and 60s gap the
chain count moves under 3%, since the median gap between prefix-compatible
queries is ~2s. Both `final_query` (chronologically last) and `longest_query`
(survives trailing backspaces) are emitted, because they disagree whenever a
user deletes at the end. Exported as CSV alongside the replay benchmark.

Paths are now anchored on `mo.notebook_dir()` rather than the process cwd.
marimo inherits the cwd of whatever launched it, so `Path("benchmark")` was
writing to the repo root when the notebook was opened from there — past the
`log-analysis/nameres/.gitignore` that exists to catch exactly those artifacts.

The pure helpers (`log_file_span`, `assert_no_overlapping_spans`,
`request_shape`, `assign_chains`) moved into their own cells so they can be unit
tested without a log export on disk.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
marimo notebooks are not importable as modules — the `log-analysis` directory
has a hyphen and cells are `@app.cell` functions — but they load by path, and
`Cell.run()` executes a cell plus its ancestors and returns its definitions.
That covers the notebook's pure logic without needing the (uncommitted) log
exports, which is why those helpers live in data-free cells.

30 tests over `parse_record` (field extraction, SLOW QUERY detection, loud
failure on an unparseable lookup line, filter-list normalization),
`log_file_span`, `assert_no_overlapping_spans` (partial, contained, identical
and endpoint-touching overlaps; every clashing pair reported) and
`assign_chains` (forward typing, backspacing, case-insensitivity, gap splits,
request-shape isolation, interleaved shapes, index alignment).

Both techniques are recorded in log-analysis/CLAUDE.md, along with the
cwd-relative path trap that sent generated artifacts to the repo root.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
gaurav and others added 3 commits September 2, 2026 02:49
The notebook is shared as a generated single-file HTML export under
`log-analysis/nameres/exports/`, with a `.generated.` infix so the filename
itself says not to edit it. HTML is the default rather than `.ipynb`: it opens
with nothing installed and cannot be forked by accident, whereas an `.ipynb`
invites edits that are then lost work. Records the `--sort top-down` flag for
the ipynb case, since the default topological sort moves the title cell.

`exports/` is gitignored. The rendered outputs embed Kubernetes pod names and
container image tags lifted from the log records, and the logs may carry other
internal detail, so exports are shared out of band rather than through this
repo.

Follow-up work on making that provenance visible to someone handed the export
directly is tracked in #143.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
`df` is the one frame this notebook renders whole, so it is the only place a
parsed field reaches the generated HTML export — every other displayed table
names its columns explicitly. That put the Kubernetes pod name and container
image tag into a file meant to be handed to people outside the project, for no
analytical benefit: nothing here reads either column.

Both are still parsed onto every QueryLogEntry, so `entries` keeps them for a
future notebook comparing NameRes releases (v1.5.2 against v1.7.0, say) or Solr
instances — see #142. They are dropped only on the way into `df`.

Re-exported and grepped to confirm: no pod name, image tag, EC2 hostname, pod
IP, ECR registry or image digest survives. What the export does still contain is
every query string users typed, which is the analysis itself and the real reason
`exports/` stays gitignored — the docs now say that rather than naming the
infrastructure fields.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The only pytest job on main is `uv run pytest -m unit -v`, so an unmarked test
file is silently deselected: 30 tests that look like coverage and execute never.
This has already happened once in this repo (#112 merged six tests that had
never run), which is why the root CLAUDE.md calls it out.

This branch predates the marker's introduction on main, so register `unit` in
pyproject.toml too — verbatim from main, so the two merge cleanly. Verified:
`pytest -m unit` now selects 30 and deselects 25.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@gaurav gaurav changed the title Nameres log analysis Add a NameRes autocomplete log-analysis notebook and replayable Solr benchmark Sep 2, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants