summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authoruser <user@clank>2026-08-07 06:23:25 +0200
committeruser <user@clank>2026-08-07 06:23:25 +0200
commitdf88eceec9e7975f681fa0177300a4406afe36f1 (patch)
tree3858c5b8e0d2dd2f678c52aa0e5303627fa9094a
parentautoresearch: record the trace-memory scaling finding (diff)
downloadida-tui-df88eceec9e7975f681fa0177300a4406afe36f1.tar.gz
ida-tui-df88eceec9e7975f681fa0177300a4406afe36f1.tar.xz
ida-tui-df88eceec9e7975f681fa0177300a4406afe36f1.zip
Size the worker's per-line render cache to hold a segment's DISTINCT lines (16384 -> 65536, overridable with IDATUI_LINE_CACHE). This was a recorded dead end — it does nothing for a cold sweep — but the rename fix created a second-sweep workload, and re-rendering after a rename is now 21% cheaper. lg_search 7123 -> 5628.
Result: {"status":"keep","total_ms":27552.6,"lg_boot_ms":759.2,"lg_decomp_ms":2754.1,"lg_graph_ms":1207.2,"lg_hex_ms":448,"lg_index_ms":69.6,"lg_listing_cold_ms":434.5,"lg_listing_warm_ms":442.9,"lg_nav_ms":6642.3,"lg_palette_ms":4.7,"lg_rename_ms":730.6,"lg_render_ms":223.6,"lg_search_ms":5627.5,"lg_split_ms":2268,"pure_graph_ms":218.7,"sm_boot_ms":465,"sm_decomp_ms":1290.8,"sm_graph_ms":720.7,"sm_hex_ms":436.1,"sm_index_ms":2.4,"sm_listing_cold_ms":267.2,"sm_listing_warm_ms":266.5,"sm_nav_ms":292.9,"sm_palette_ms":0.3,"sm_rename_ms":380.1,"sm_render_ms":255.5,"sm_search_ms":68.1,"sm_split_ms":1276.3,"fails":0}
-rw-r--r--.auto/log.jsonl1
-rw-r--r--.auto/prompt.md9
-rw-r--r--server/patch_server.py20
3 files changed, 27 insertions, 3 deletions
diff --git a/.auto/log.jsonl b/.auto/log.jsonl
index 271d99d..defe5a4 100644
--- a/.auto/log.jsonl
+++ b/.auto/log.jsonl
@@ -41,3 +41,4 @@
{"run":34,"commit":"3ca9e1e","metric":28651.3,"metrics":{"lg_boot_ms":720.6,"lg_decomp_ms":2427.4,"lg_graph_ms":1222.4,"lg_hex_ms":440.9,"lg_index_ms":72.6,"lg_listing_cold_ms":433.6,"lg_listing_warm_ms":465.9,"lg_nav_ms":6809.7,"lg_palette_ms":4.7,"lg_rename_ms":710.1,"lg_render_ms":228.7,"lg_search_ms":6891.2,"lg_split_ms":2259.2,"pure_graph_ms":214.5,"sm_boot_ms":457.7,"sm_decomp_ms":1303.6,"sm_graph_ms":700.2,"sm_hex_ms":445.4,"sm_index_ms":2.4,"sm_listing_cold_ms":271.4,"sm_listing_warm_ms":270.9,"sm_nav_ms":309.2,"sm_palette_ms":0.3,"sm_rename_ms":386.6,"sm_render_ms":265.8,"sm_search_ms":70.1,"sm_split_ms":1266.2,"fails":0},"status":"keep","description":"CORRECTNESS FIX, kept despite a worse metric. The un-chunked refresh was showing STALE NAMES on any wide read: one heads call for a search-sized window overflows the tool's 2000-row cap, the short response fails the sequence check, and the block is left with its old text. Refresh is now done a block at a time. Adds .auto/check_rename.py to the gate, which fails hard on the previous code and passes on this one.","timestamp":1786074769473,"segment":6,"confidence":4.974025132789222,"asi":{"the_bug_the_metric_was_rewarding":"/tmp/stalewindow.py renames a function, then reads the segment through window() the way the search body does. On the previous commit: 0 rows show the new name, the old one is still there, stale_structure=True. The 25564ms reading was FASTER because it was skipping the refresh -- the bench only failed to notice because phase_rename undoes its renames, so the stale text happened to be right again by the time anything compared it.","why_it_happened":"_ensure_text issued ONE heads call for the whole requested range. The tool caps a response at 2000 rows; a 4096-row search window came back short, page[:len(want)] != want, and the code took its 'the walk moved' branch -- marking the block fresh and leaving the old text.","fix":"refresh a TEXT_BLOCK (500 heads) at a time, looping. The sequence check then only ever fires for a real structural change.","cost":"total 25564 -> 28651. A wholesale re-read after a rename is ~10% dearer than a rebuild would be (6.6s vs 6.0s measured directly), and this bench does exactly that -- six renames then a split-view pass and a whole-segment search. The user-facing trade is: a rename is 566x faster (10.3ms vs 5660ms to get the listing back on bash), and a full-segment search immediately after one is ~10% slower.","counter_drift_resolved":"the 3233/1990/92733 counters in experiment #33 were NOT caused by the change -- both configurations reproduce 3436/2070/91783 twice each. That run was CPU-starved (the box is at load 1.6 and the 60s tool deadline can truncate a big decompile). Watch decomp_lines as a starvation signal.","gate_extended":".auto/check_rename.py: narrow read (painting), wide read (search body), and the whole model against a rebuild. Verified it FAILS on the previous commit with 4 problems and passes on this one.","principle":"the second time this session that the honest number is worse than the dishonest one. A benchmark rewards whatever it can see; the guard has to be a check that fails, not a number that improves."}}
{"run":35,"commit":"6ec4bd8","metric":29392.6,"metrics":{"lg_boot_ms":711.9,"lg_decomp_ms":2406.4,"lg_graph_ms":1271.9,"lg_hex_ms":445.3,"lg_index_ms":71.9,"lg_listing_cold_ms":748.5,"lg_listing_warm_ms":403.8,"lg_nav_ms":6596.2,"lg_palette_ms":4.8,"lg_rename_ms":715.8,"lg_render_ms":219.3,"lg_search_ms":7055.2,"lg_split_ms":2629.8,"pure_graph_ms":212.8,"sm_boot_ms":445.6,"sm_decomp_ms":1281,"sm_graph_ms":775,"sm_hex_ms":442.3,"sm_index_ms":2.3,"sm_listing_cold_ms":265.6,"sm_listing_warm_ms":266.7,"sm_nav_ms":302.9,"sm_palette_ms":0.3,"sm_rename_ms":380.8,"sm_render_ms":255.1,"sm_search_ms":67,"sm_split_ms":1414.2,"fails":0},"status":"discard","description":"Documentation-only commit (playbook + ideas). Re-measured to confirm the post-fix state: 28651 -> 29393 is within the spread on this now-loaded box, and lg_search holds at ~7.0s, confirming that a whole-segment read after renames costs a whole-segment re-render.","timestamp":1786075083972,"segment":6,"confidence":7.108776152564333,"asi":{"state":"v7 baseline 33243 -> 29393 (-11.6%). rename 10055 -> 716 is the headline; the cost of re-rendering after a rename did not disappear, it moved to whoever reads the rows (lg_search 775 -> ~7000, because this bench reads the entire segment right after renaming). For a user reading a viewport the rename is 566x faster and nothing else changes.","why_there_is_no_more_free_win_here":"after a rename, the rows you read have to be re-rendered; re-rendering N heads costs what loading N heads costs. Refreshing only the rows that ACTUALLY changed would need xrefs_to(renamed_ea) to enumerate them, and a name can reach a row without a direct xref (a comment, a struct field in an operand) -- miss one and you are back to showing a stale name, which is the bug just fixed. Logged in .auto/ideas.md rather than attempted.","highest_yield_activity_this_session":"asking what the benchmark does NOT measure. Three of the five bench corrections found an invisible cost, and two of those (split view, rename) were among the biggest wins of the whole session.","next_action_hint":"keep probing uncovered features with the /tmp/featprobe.py shape: xrefs (x), the strings browser (\"), literal formats (o), make-code/data edits, history, traces, RPC. Domain-level probes already say xrefs/strings/structs/resolve are fast, so drive them through the UI instead."}}
{"run":36,"commit":"1e9f47b","metric":28842.1,"metrics":{"lg_boot_ms":712.2,"lg_decomp_ms":2366.9,"lg_graph_ms":907.8,"lg_hex_ms":447.2,"lg_index_ms":72.2,"lg_listing_cold_ms":443.7,"lg_listing_warm_ms":453.7,"lg_nav_ms":6610.2,"lg_palette_ms":4.8,"lg_rename_ms":735.3,"lg_render_ms":228.4,"lg_search_ms":7122.8,"lg_split_ms":2609.7,"pure_graph_ms":212.3,"sm_boot_ms":438.7,"sm_decomp_ms":1279.7,"sm_graph_ms":783.2,"sm_hex_ms":447.3,"sm_index_ms":2.5,"sm_listing_cold_ms":267.7,"sm_listing_warm_ms":263.1,"sm_nav_ms":309.7,"sm_palette_ms":0.3,"sm_rename_ms":383.9,"sm_render_ms":255,"sm_search_ms":66.3,"sm_split_ms":1417.6,"fails":0},"status":"discard","description":"Tried and reverted: throttling the background listing streamer's UI reports by time, and adding a token so only the newest streamer survives a re-prime. Both measured WORSE on a direct responsiveness probe (xrefs dialog while streaming: 1314ms baseline, 1436ms throttled, 2038ms with the token). Reverted; the finding is recorded in .auto/ideas.md. This run confirms the committed state at 28842.","timestamp":1786075786983,"segment":6,"confidence":8.431402690090582,"asi":{"real_finding_worth_keeping":"the app is several times slower while a big segment streams in the background: an xrefs dialog is 691ms during the ~7s stream and 105ms after it. Two confirmed mechanisms -- Textual's @work(exclusive=True) does NOT stop a thread worker that is already running, and navigating inside the same segment re-primes against the SAME model, so every jump leaves another streamer behind; and each streamer reports growth to the UI every four pages (thread hop + virtual_size change + full repaint).","what_failed":"a 10/s time throttle made it worse (237 reports vs 112) because the count is per streamer and there are several. Adding a _grow_token so only the newest streamer survives did NOT reduce the report count either -- so the retirement is not happening where it looks like it should, and I do not understand the mechanism well enough to ship a fix.","why_i_stopped":"the probe navigates repeatedly, which is itself what spawns the extra streamers, so it measures the thing it perturbs. A clean probe would drive UI work from a SINGLE navigation while one streamer runs. Recorded in .auto/ideas.md with the reproduction.","also_found":"a PRE-EXISTING crash: StringsPalette.on_mount calls query_one(OptionList) before compose's children are mounted (NoMatches). Reproduces 3/3 on bash AND 3/3 on the pre-autoresearch commit 2b0ae8d, so it is not from this work. ProjectPalette has the same shape.","xrefs_is_fine":"the xrefs path is not a decomp_map-class problem: xrefs_to is 38ms for 12 functions, item building 2.6ms, and the whole 'x'-to-dialog cycle is ~105ms once the listing has finished streaming. Most of that is two modal screen mounts.","state":"v7 baseline 33243 -> 28842 (-13.2%)."}}
+{"run":37,"commit":"6882eea","metric":29365.3,"metrics":{"lg_boot_ms":738.3,"lg_decomp_ms":2438.1,"lg_graph_ms":1287.6,"lg_hex_ms":462.1,"lg_index_ms":72.1,"lg_listing_cold_ms":438.6,"lg_listing_warm_ms":460.3,"lg_nav_ms":6762.3,"lg_palette_ms":4.8,"lg_rename_ms":719.1,"lg_render_ms":224.7,"lg_search_ms":7055.7,"lg_split_ms":2672.5,"pure_graph_ms":217.4,"sm_boot_ms":435.3,"sm_decomp_ms":1269.6,"sm_graph_ms":721,"sm_hex_ms":437.5,"sm_index_ms":2.5,"sm_listing_cold_ms":281.1,"sm_listing_warm_ms":264.8,"sm_nav_ms":316.9,"sm_palette_ms":0.3,"sm_rename_ms":390,"sm_render_ms":257.4,"sm_search_ms":67.8,"sm_split_ms":1367.8,"fails":0},"status":"discard","description":"Documentation-only (trace scaling finding). Probed idatui/trace.py: loading is exactly linear, register_state is O(1), but Trace.memory() is linear in TRACE LENGTH per call. Recorded rather than fixed — the differential against Tenet's reference reader is skipped on this box, so the safety net for an indexing change is too thin. Run confirms the committed state.","timestamp":1786076140273,"segment":6,"confidence":13.948955495004537,"asi":{"trace_measurements":"load 36.6/73.3/143.9/280.7 ms for 20k/40k/80k/160k rows (x1.95 per doubling -- linear, correct). register_state x200: ~1.1ms at every size -- O(1). memory() x200: 16.3/31.7/63.4/125.8 ms -- LINEAR IN TRACE LENGTH per call.","why":"_mem_index sorts accesses by address and bisects to the query window, which is right, but then iterates every access in that window across all time and filters by t > idx. A stack slot written once per loop iteration accumulates one entry per iteration, so the stack pane's cost grows with how long the trace ran.","why_not_fixed":"tests/test_trace_vs_tenet.py -- the differential against Tenet's own reference reader -- is SKIPPED on this box, leaving 35 synthetic checks as the only guard on a subtle indexing change. Recorded in .auto/ideas.md with the probe (/tmp/traceprof.py) and the precondition.","session_state":"v7 baseline 33243 -> best 28651 kept. Working tree clean, 41 commits on autoresearch/perf-20260807, full 830-check gate plus two custom equivalence checks green.","next_action_hint":"remaining ideas, in .auto/ideas.md: the trace memory index (needs the Tenet differential first), why the _grow_token did not retire extra streamers, refreshing only the rows a rename actually changed, and the skeleton walk for ensure_ea (costed at ~5%)."}}
diff --git a/.auto/prompt.md b/.auto/prompt.md
index 0f03092..68bc46f 100644
--- a/.auto/prompt.md
+++ b/.auto/prompt.md
@@ -173,8 +173,13 @@ v1 bench baseline `total_ms` ≈ 46 600 → 18 900 after thirteen experiments
- A page-scoped identity memo for the spans→tuple conversion never hits: the
repeats are spread across the segment, not within a 500-row page. A
model-scoped one is unsafe (`id()` is reused once the page dicts die).
-- Growing the line cache past 16 384 does nothing for a *cold* sweep (16.5
- µs/row at both 16 k and 64 k); it only helps a second sweep (10.6 vs 16.4).
+- Growing the line cache past 16 384 does nothing for a *cold* sweep (17.0
+ µs/row at 16 k, 32 k, 64 k and 128 k alike). It only helps a *second* sweep —
+ which was a dead end until the rename fix created one, and then it was worth
+ 21%. **Re-read the dead ends after a structural change: this one stopped being
+ one.** Sized at 65 536 now (bash's .text has 53 363 distinct lines; 32 768
+ still thrashes). Costs +47 MB of worker RSS, and it is a bound rather than a
+ proportion — a bigger binary fills it and stops.
- Merging same-kind adjacent spans in `_idatui_spans`: only 2.5% fewer spans on
20 k real lines. Not worth a wire-format change.
- Applying an already-decompiled function inline instead of via a `@work`
diff --git a/server/patch_server.py b/server/patch_server.py
index b8f5453..f3cbe35 100644
--- a/server/patch_server.py
+++ b/server/patch_server.py
@@ -318,9 +318,27 @@ def _idatui_head_row(ea):
import functools as _idatui_functools
+import os as _idatui_os
+#: Entries in the per-line render cache. Sized to hold a whole segment's
+#: DISTINCT lines rather than a working set, because the listing gets rendered
+#: TWICE: once when it is first walked, and again after a rename, which restates
+#: every row's text. bash's .text is 228 659 rows but only 53 363 distinct
+#: lines, and the difference between thrashing and not is the whole win:
+#:
+#: maxsize first sweep second sweep worker RSS
+#: 16 384 17.2 us/row 16.9 us/row +29 MB
+#: 32 768 17.0 17.2 +52 MB
+#: 65 536 17.0 11.1 +75 MB
+#: 131 072 16.9 11.2 +75 MB (working set fits)
+#:
+#: It is a bound, not a proportion: a bigger binary fills it and stops, so the
+#: cost is capped at ~56 MB whatever is open. Lower it with IDATUI_LINE_CACHE if
+#: a pool of workers is competing for memory.
+_IDATUI_LINE_CACHE = int(_idatui_os.environ.get("IDATUI_LINE_CACHE") or 65536)
-@_idatui_functools.lru_cache(maxsize=16384)
+
+@_idatui_functools.lru_cache(maxsize=_IDATUI_LINE_CACHE)
def _idatui_line_parts(line):
"""``(text, spans, ops)`` for one tagged disassembly line -- memoised.