diff options
| -rw-r--r-- | .auto/ideas.md | 24 | ||||
| -rw-r--r-- | .auto/log.jsonl | 1 | ||||
| -rw-r--r-- | .auto/prompt.md | 6 | ||||
| -rw-r--r-- | server/patch_server.py | 66 |
4 files changed, 80 insertions, 17 deletions
diff --git a/.auto/ideas.md b/.auto/ideas.md index 9226574..98804f0 100644 --- a/.auto/ideas.md +++ b/.auto/ideas.md @@ -53,6 +53,30 @@ `render_cells`, `nav_rows`, `listing_cells`) are the standing guard against "faster because it did less". +## Two "predict what changed" schemes, both measured and rejected + +Both would have made a rename nearly free. Both fail for the same reason: **IDA +and Hex-Rays drift on their own**, so "what the edit changed" is not the same +question as "what is different now". + +- **Listing rows, predicted from `xrefs_to` + the function's extent.** + `/tmp/whatchanges.py` rebuilds the segment before and after and diffs every + row. echo: 19/19 changed rows covered. ls_ttl: 53/54 — the miss was + `lea rcx, unk_1D7A0` → `byte_1D7A0`, which the rename did not cause; IDA's own + analysis defined that byte. +- **Decompilations, predicted from "the old name appears in the cached text".** + `/tmp/decchanges.py` decompiles 25 functions, renames one, recompiles all and + diffs. **16 misses over 4 renames, every one of them Hex-Rays' type inference + moving** — e.g. `unsigned __int64 f(..., unsigned int a4)` → `..., int a4)` in + functions with no connection to the rename. + +The lesson generalises: predicting the effect of an edit on a database that has +its own opinions is unsound. Verify instead — `heads(digest=True)` works because +it asks what the row renders as *now*, not what should have changed. + +(This also explains the `lg_decomp_lines` drift blamed on CPU starvation in v5 +#4: it is probably the same Hex-Rays instability.) + ## Added late in the session - ~~**Refresh only the rows a rename actually changed** (xrefs-driven).~~ diff --git a/.auto/log.jsonl b/.auto/log.jsonl index 491fbf6..bb217ce 100644 --- a/.auto/log.jsonl +++ b/.auto/log.jsonl @@ -44,3 +44,4 @@ {"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%)."}} {"run":38,"commit":"df88ece","metric":27552.6,"metrics":{"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},"status":"keep","description":"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.","timestamp":1786076605767,"segment":6,"confidence":8.431402690090582,"asi":{"hypothesis":"the biggest remaining term (lg_search 7.1s) is entirely the post-rename re-render, and a re-render is a SECOND sweep over the same lines -- which is exactly the case the line cache was measured to help and then filed as a dead end because nothing did it","why_it_stopped_being_a_dead_end":"experiment v1 #6 sized the cache at 16384 and noted that growing it 'does nothing for a cold sweep, only for a second sweep'. Nothing did a second sweep -- until v7 #2 made a rename keep the listing's walk and re-render its text on demand. The structural change created the workload the dead end was waiting for.","sizing_measurement":{"16384":[17.18,16.88,"+29MB"],"32768":[16.99,17.23,"+52MB"],"65536":[17.01,11.13,"+75MB"],"131072":[16.91,11.2,"+75MB"],"note":"bash .text, first sweep then second, in the worker"},"why_65536":"bash's .text is 228659 rows but only 53363 DISTINCT lines; 32768 still thrashes and 131072 buys nothing because the working set already fits. It is a bound, not a proportion -- a bigger binary fills it and stops, so the cost is capped at ~56MB whatever is open. IDATUI_LINE_CACHE lowers it for a pool of workers competing for memory.","direct_ab_on_the_real_path":"/tmp/refreshcost.py -- load the whole listing, rename, re-read every row through window(): 6445ms -> 5115ms (-21%), worker RSS 164MB -> 211MB. Initial load_all unchanged (5645 vs 5585).","gains":"total 28651 (previous best) -> 27553; lg_search 7123 -> 5628 (-21%); lg_split 2673 -> 2268","work_unchanged":"decomp_lines 3436, split_mapped 2070, search_hits 91783, graph_blocks 1000, rename_ok 6/6 -- all identical","verified":"830-check gate plus check_search and check_rename green; spans still byte-identical vs 2b0ae8d","lesson_recorded_in_prompt":"re-read the dead-end list after any structural change -- a rejected idea can become the right one when the workload around it moves","next_action_hint":"lg_nav 6642 is now the largest term again and is at the per-row floor. lg_search 5628 is still the post-rename re-render; the only way further down is to re-render fewer rows (see the xrefs-driven invalidation idea in .auto/ideas.md, which is risky because a name can reach a row without a direct xref)."}} {"run":39,"commit":"df88ece","metric":28376.5,"metrics":{"lg_boot_ms":762.1,"lg_decomp_ms":2374.3,"lg_graph_ms":938.1,"lg_hex_ms":452.4,"lg_index_ms":70.2,"lg_listing_cold_ms":419.6,"lg_listing_warm_ms":464.1,"lg_nav_ms":6941.9,"lg_palette_ms":5,"lg_rename_ms":1973.2,"lg_render_ms":221.9,"lg_search_ms":4117.3,"lg_split_ms":2333.3,"pure_graph_ms":214.6,"sm_boot_ms":453.7,"sm_decomp_ms":1270.5,"sm_graph_ms":726.9,"sm_hex_ms":440.6,"sm_index_ms":2.4,"sm_listing_cold_ms":283,"sm_listing_warm_ms":284.3,"sm_nav_ms":310.4,"sm_palette_ms":0.3,"sm_rename_ms":1575.9,"sm_render_ms":257.6,"sm_search_ms":59.6,"sm_split_ms":1423.7,"fails":0},"status":"checks_failed","description":"Digest mode for `heads`: the worker answers \"does this page still render exactly as it did?\" for the cost of the render alone, so a post-rename refresh skips shipping, unpickling and rebuilding pages that did not change. lg_search 5628 -> 4117 — but it BREAKS 'O' cycles back, and it made rename 2-4x slower. Both causes understood.","timestamp":1786077531326,"segment":6,"confidence":10.35869418588966,"asi":{"hypothesis_first_tested_empirically":"before building anything I checked the parked xrefs-driven idea: /tmp/whatchanges.py rebuilds the whole segment before and after a rename and diffs every row. On echo, all 19 changed rows over 4 renames were covered by (function extent + xrefs_to). On ls_ttl, 53 of 54 were -- the one that was not is 'lea rcx, unk_1D7A0' -> 'byte_1D7A0', which the RENAME DID NOT CAUSE: IDA's own analysis defined that byte. An address-predicted invalidation would leave that row stale for good, so the idea is now measured-and-rejected rather than assumed-risky.","what_i_built_instead":"an exact check: `heads(..., digest=True)` builds the rows as usual but returns only hash+count instead of the rows. The client stores the digest each page came back with and asks 'still the same?' before re-fetching. Uses the interpreter's own hash deliberately -- it never has to mean anything outside the worker process, the client is only a courier.","measured_win":"post-rename whole-segment re-read 5115ms -> 3833ms (-25%); lg_search 5628 -> 4117","BUG_1_correctness":"the stored digest describes the page AS LOADED, not as the client currently holds it. After a full refetch the client's rows change but _page_digest is not updated -- so when a literal format cycles hex -> dec -> ... -> hex, the worker's digest matches the ORIGINAL stored one, the page is declared unchanged, and the row keeps the intermediate decimal text. That is exactly the failure: opfmt_listing ''O' cycles back' got 'sub rsp, 184' wanting 'sub rsp, 0B8h'.","BUG_2_performance":"_ensure_text_from tests page freshness with all(_head_gen[k] == gen for k in the page), and get() calls _ensure_text per ROW -- so every row scanned a whole page's gen array. rename went 380 -> 1576ms (sm) and 730 -> 1973ms (lg).","fix_for_both":"refresh at PAGE granularity end to end instead of the snapped TEXT_BLOCK: a page is exactly what the tool produced from (addr, count=PAGE), so refetching with the same parameters reproduces the same sequence with no snapping, the stored digest can be updated whenever the page's rows are replaced, and every head in a page shares one gen value so freshness is a single probe rather than a scan.","work_preserved":".auto/wip-digest.patch","gate_worked":"check_rename and check_search both passed -- neither exercises a format cycle. The scenario suite caught it. That is the third time a cache-shaped change failed in a way only one specific test could see."}} +{"run":40,"commit":"d9e8fdb","metric":26491.7,"metrics":{"lg_boot_ms":808.6,"lg_decomp_ms":2600.2,"lg_graph_ms":901.2,"lg_hex_ms":448.7,"lg_index_ms":70.3,"lg_listing_cold_ms":432.8,"lg_listing_warm_ms":445.5,"lg_nav_ms":7004.8,"lg_palette_ms":4.8,"lg_rename_ms":758.6,"lg_render_ms":231.3,"lg_search_ms":3959.2,"lg_split_ms":2659.2,"pure_graph_ms":214.7,"sm_boot_ms":432.6,"sm_decomp_ms":1305.1,"sm_graph_ms":758.3,"sm_hex_ms":431.8,"sm_index_ms":2.3,"sm_listing_cold_ms":275.4,"sm_listing_warm_ms":289.4,"sm_nav_ms":295.6,"sm_palette_ms":0.3,"sm_rename_ms":424.3,"sm_render_ms":263.6,"sm_search_ms":61.1,"sm_split_ms":1411.9,"fails":0},"status":"keep","description":"heads(digest=True): the worker answers \"does this page still render exactly as you hold it?\" with a hash and a count instead of the page. After a rename nearly every page is unchanged, so the pickling, transfer, unpickling and Head rebuild are all skipped. Redone at PAGE granularity end to end, which fixes both bugs of the first attempt. lg_search 5628 -> 3959.","timestamp":1786077952004,"segment":6,"confidence":8.431402690090582,"asi":{"gains":"total 27553 (previous best) -> 26492 (-3.9%); lg_search 5628 -> 3959 (-30%); post-rename whole-segment re-read 5115 -> 3720ms measured directly","cost":"lg_rename 731 -> 759 and sm_rename 380 -> 424: a page now costs one extra round trip to probe before it is either accepted or refetched. Getting a viewport back after a rename on bash is 21.5ms instead of 10.3ms -- still 230x better than the 4941ms rebuild it replaced.","what_the_two_bugs_were":{"correctness":"the first attempt stored the digest a page LOADED with and never updated it when the page was refetched. A literal format cycling hex -> dec -> hex then hashed back to the original while the client still held the decimal text: opfmt_listing ''O' cycles back' got 'sub rsp, 184' wanting '0B8h'.","performance":"freshness was tested with all(_head_gen[k] == gen for k in the page) while get() called _ensure_text per ROW, so every row scanned a whole page's gen array -- rename went 2-4x slower."},"the_fix_was_one_idea":"refresh at PAGE granularity instead of the snapped TEXT_BLOCK. A page is exactly what heads(addr, count=PAGE) produced, so re-asking with the same arguments reproduces the same sequence -- no snapping to address groups needed, the stored digest can be updated whenever the rows are replaced, and every head in a page shares one generation marker so freshness is a single probe. TEXT_BLOCK is gone.","why_hash_and_not_a_stable_digest":"the value never has to mean anything outside the worker process -- the client stores what a page hashed to and hands the same number back. One worker, one process, one hash seed. It covers ea/kind/size/text/name AND the colour spans, so two lines that collapse to the same text but colour differently are not confused.","empirical_work_that_shaped_this":"before building anything I tested the parked xrefs-driven idea with /tmp/whatchanges.py (rebuild the segment before and after a rename, diff every row). It fails: on ls_ttl one changed row was 'lea rcx, unk_1D7A0' -> 'byte_1D7A0', which the rename did not cause -- IDA's own analysis defined that byte. Address-predicted invalidation would leave it stale forever. Recorded as measured-and-rejected in .auto/ideas.md.","work_unchanged":"decomp_lines 3436, split_mapped 2070, search_hits 91783, graph_blocks 1000, rename_ok 6/6, decomp_ok 12 -- identical","verified":"830-check gate, check_search (140 prefixes), check_rename on echo AND ls_ttl (5952 and 28807 rows, wide and narrow, against a rebuild), and the 19 opfmt scenarios that caught the first attempt","next_action_hint":"lg_nav 7005 is the largest term and is the cold walk at its per-row floor. lg_search 3959 is now mostly the _line_plain pass plus the pages that genuinely changed. Next best unexplored: why the digest probe costs a whole extra round trip per page -- it could ride along with the first refetch request rather than preceding it."}} diff --git a/.auto/prompt.md b/.auto/prompt.md index c57708b..8437b38 100644 --- a/.auto/prompt.md +++ b/.auto/prompt.md @@ -156,7 +156,11 @@ v1 bench baseline `total_ms` ≈ 46 600 → 18 900 after thirteen experiments forty on screen were built and thrown away. 8. *(v7 #10, −4%)* **`heads(digest=True)`** — ask whether a page still renders as you hold it, rather than fetching it to find out. -9. *(v1 #9/#10/#13, v2 #3, v5 #3)* Constants: `bytes.hex(" ")` for the opcode +9. *(v7 #12, −2.6%)* Three redundancies in the `heads` walk: item flags fetched + three times per head, `get_func` per head where a head is nearly always in + the same function as the one before it, and the page digest rebuilding a + tuple-of-tuples per row where one spans list is shared by ~45% of them. +10. *(v1 #9/#10/#13, v2 #3, v5 #3)* Constants: `bytes.hex(" ")` for the opcode column (12×), `bisect` imported at module scope, the deferred `refresh(layout=True)` only when a scroll actually clamped, a memoised pygments token→style lookup, `_CellRow` writing by slice, `HexView` emitting diff --git a/server/patch_server.py b/server/patch_server.py index a34a4a9..a991158 100644 --- a/server/patch_server.py +++ b/server/patch_server.py @@ -282,14 +282,19 @@ def read_raw( return {"addr": addr, "hex": bytes(ba).hex(), "n": len(ba)} -def _idatui_head_row(ea): +def _idatui_head_row(ea, flags=None): """One flat-listing row for the head at ``ea``: kind (code/data/unknown), - byte size, rendered text, and any symbol name.""" + byte size, rendered text, and any symbol name. + + ``flags`` lets a caller that already asked for them say so -- the walk in + ``heads`` used to fetch them three times per head (here, in _is_unknown from + _advance, and again from _rows_for). + """ import ida_bytes import ida_lines import ida_name - f = ida_bytes.get_flags(ea) + f = ida_bytes.get_flags(ea) if flags is None else flags if ida_bytes.is_code(f): kind = "code" elif ida_bytes.is_data(f): @@ -590,11 +595,23 @@ def _idatui_rows_digest(rows): hashes to that. One worker, one process, one hash seed. """ acc = 0 + # The per-line render is memoised, so one spans list is shared by every row + # that says the same thing -- about 45% of them within a page. Hash each + # distinct list once and key that by identity, rather than rebuilding a + # tuple of tuples per row (which is the exact cost that was measured and + # removed from the client side for the same reason). + seen = {} for r in rows: sp = r.get("spans") + if sp is None: + sh = None + else: + key = id(sp) + sh = seen.get(key) + if sh is None: + sh = seen[key] = hash(tuple(map(tuple, sp))) acc = hash((acc, r.get("ea"), r.get("kind"), r.get("size"), - r.get("text"), r.get("name"), - tuple(map(tuple, sp)) if sp else None)) + r.get("text"), r.get("name"), sh)) return acc @@ -735,8 +752,7 @@ def heads( # by get_item_end; a run of undefined bytes is COLLAPSED into one row (its # end found in O(1) via next_head, which skips undefined) so a large .bss or # gap doesn't explode into millions of one-byte rows. - def _is_unknown(e): - f = ida_bytes.get_flags(e) + def _is_unknown_f(f): return not (ida_bytes.is_code(f) or ida_bytes.is_data(f)) def _run_end(e): @@ -744,21 +760,37 @@ def heads( nh = ida_bytes.next_head(e, hi) return nh if (nh != idaapi.BADADDR and e < nh <= hi) else hi - def _advance(e): - if _is_unknown(e): + def _advance(e, f): + if _is_unknown_f(f): return _run_end(e) nxt = ida_bytes.get_item_end(e) return nxt if nxt > e else e + 1 - def _rows_for(e): - if _is_unknown(e): + # The function the walk is currently inside, reused while it stays inside. + # get_func is ~0.5us and the walk asks per head; a head is nearly always in + # the same function as the one before it. Only ever consulted when ``e`` + # falls in [start_ea, end_ea), so a tail chunk elsewhere cannot be + # misattributed -- checked against get_func over 437k heads of + # bash/ls_ttl/echo with zero disagreements. + fn_cache = [None] + + def _func_at(e): + cur = fn_cache[0] + if cur is not None and cur.start_ea <= e < cur.end_ea: + return cur + cur = idaapi.get_func(e) + fn_cache[0] = cur + return cur + + def _rows_for(e, f): + if _is_unknown_f(f): return [_idatui_unknown_row(e, _run_end(e) - e)] - func = idaapi.get_func(e) if annotate else None + func = _func_at(e) if annotate else None at_start = func is not None and func.start_ea == e out = [] if at_start: out.extend(_idatui_func_header_rows(e)) - row = _idatui_head_row(e) + row = _idatui_head_row(e, f) if at_start: row = dict(row) row["name"] = None # the name is shown on the proc header line @@ -778,17 +810,19 @@ def heads( return out ea = ida_bytes.get_item_head(start) + get_flags = ida_bytes.get_flags for _ in range(offset): if ea >= hi or ea == idaapi.BADADDR: break - ea = _advance(ea) + ea = _advance(ea, get_flags(ea)) more = False while ea != idaapi.BADADDR and ea < hi: if len(rows) >= count: more = True break - rows.extend(_rows_for(ea)) # a struct head expands into member rows - ea = _advance(ea) + f = get_flags(ea) # once per head, not once per consumer + rows.extend(_rows_for(ea, f)) # a struct head expands into member rows + ea = _advance(ea, f) cursor = {"next": hex(ea)} if more else {"done": True} out = {"addr": str(addr), "cursor": cursor, "digest": _idatui_rows_digest(rows), "count": len(rows)} |