While characterizing NameRes autocomplete traffic from CloudWatch (translator-eks-ci-blue-cluster application logs), the six slowest lookups in a 29-day window were all the same query, issued within 180 ms of each other.
2026-08-07 19:17:26.612 "vitamin a" 321253.90 ms waiting for Solr
2026-08-07 19:17:26.647 "Vitamin A " 268760.21 ms
2026-08-07 19:17:26.682 "vitamin A" 313424.73 ms
2026-08-07 19:17:26.719 "Vitamin A" 264460.04 ms
2026-08-07 19:17:26.756 "Vitamin A" 275157.98 ms
2026-08-07 19:17:26.791 "vitamin A" 308571.10 ms
All six: autocomplete=True, highlighting=False, offset=0, limit=100, biolink_types=['SmallMolecule'], only_prefixes=, exclude_prefixes=, only_taxa=None, pod name-lookup-web-server-dep-648d67989c-288dr, image translator-name-lookup:v1.5.2. All six logged SLOW QUERY.
Two things stand out:
- The absolute latency. 4.4 to 5.4 minutes of Solr wait for a two-word common query with a single Biolink type filter.
took exceeds the Solr wait by only ~25 ms in every case, so essentially all of it is Solr, not the NameRes app layer.
- The arrival pattern. These are ~35 ms apart, so they were in flight concurrently rather than issued one after another — a caller firing six near-identical requests in under 200 ms, differing only in capitalization and a trailing space. Whether that is a retry loop, a type-ahead widget without debouncing, or six real users is not something the logs can distinguish (there is no session or request ID). But six concurrent
limit=100 autocomplete queries appear to be enough to put Solr into a state where each takes minutes.
For scale: this is 6 of the 7 lookups in the whole 607-row autocomplete export that exceeded 60 s of Solr wait. Median autocomplete Solr wait in the same export is 48.5 ms. So this is not a slow tail — it is a distinct failure mode that only appears under a concurrent burst.
Worth investigating whether short-ish autocomplete queries at limit=100 with a biolink_types filter have a pathological Solr plan that only bites under concurrency, and whether NameRes should be collapsing or bounding identical in-flight lookups. Possibly related to the per-request concurrency bound discussed in #273.
Happy to share the parsed log export or the analysis notebook if useful — it lives in TranslatorSRI/babel-validation#107.
While characterizing NameRes autocomplete traffic from CloudWatch (
translator-eks-ci-blue-clusterapplication logs), the six slowest lookups in a 29-day window were all the same query, issued within 180 ms of each other.All six:
autocomplete=True, highlighting=False, offset=0, limit=100, biolink_types=['SmallMolecule'], only_prefixes=, exclude_prefixes=, only_taxa=None, podname-lookup-web-server-dep-648d67989c-288dr, imagetranslator-name-lookup:v1.5.2. All six loggedSLOW QUERY.Two things stand out:
tookexceeds the Solr wait by only ~25 ms in every case, so essentially all of it is Solr, not the NameRes app layer.limit=100autocomplete queries appear to be enough to put Solr into a state where each takes minutes.For scale: this is 6 of the 7 lookups in the whole 607-row autocomplete export that exceeded 60 s of Solr wait. Median autocomplete Solr wait in the same export is 48.5 ms. So this is not a slow tail — it is a distinct failure mode that only appears under a concurrent burst.
Worth investigating whether short-ish autocomplete queries at
limit=100with abiolink_typesfilter have a pathological Solr plan that only bites under concurrency, and whether NameRes should be collapsing or bounding identical in-flight lookups. Possibly related to the per-request concurrency bound discussed in #273.Happy to share the parsed log export or the analysis notebook if useful — it lives in TranslatorSRI/babel-validation#107.