From 60f0d70b81510d9dd58d4cc7992f33663f5aca88 Mon Sep 17 00:00:00 2001 From: user Date: Fri, 7 Aug 2026 02:35:07 +0200 Subject: Two independent constants: memoise the pygments token -> Rich style lookup (a decompilation uses ~18 distinct token types but each token walked up to nine 'token in ttype' hierarchy checks), and hold the worker-connect poll at 5ms for the first 5s instead of backing off geometrically from the first probe. Result: {"status":"keep","total_ms":18856.8,"lg_boot_ms":689.7,"lg_decomp_ms":2484.2,"lg_graph_ms":1120,"lg_hex_ms":700.1,"lg_index_ms":96.5,"lg_listing_cold_ms":425.6,"lg_listing_warm_ms":511.5,"lg_nav_ms":6590.7,"lg_palette_ms":4.8,"lg_render_ms":215.1,"lg_search_ms":2195.5,"pure_graph_ms":238.1,"sm_boot_ms":431.5,"sm_decomp_ms":667.2,"sm_graph_ms":686.9,"sm_hex_ms":569.8,"sm_index_ms":0,"sm_listing_cold_ms":258.1,"sm_listing_warm_ms":283.2,"sm_nav_ms":365.2,"sm_palette_ms":0.3,"sm_render_ms":243.7,"sm_search_ms":79,"fails":0} --- .auto/log.jsonl | 1 + idatui/highlight.py | 24 ++++++++++++++++++++---- idatui/worker_client.py | 13 ++++++++++++- 3 files changed, 33 insertions(+), 5 deletions(-) diff --git a/.auto/log.jsonl b/.auto/log.jsonl index be20455..9168c26 100644 --- a/.auto/log.jsonl +++ b/.auto/log.jsonl @@ -11,3 +11,4 @@ {"run":10,"commit":"f8fb9b7","metric":19005.8,"metrics":{"lg_boot_ms":788.9,"lg_decomp_ms":2752.5,"lg_graph_ms":899,"lg_hex_ms":565.2,"lg_index_ms":71.9,"lg_listing_cold_ms":416.1,"lg_listing_warm_ms":402.3,"lg_nav_ms":6756.3,"lg_palette_ms":4.7,"lg_render_ms":217.1,"lg_search_ms":2335.8,"pure_graph_ms":235.3,"sm_boot_ms":537.4,"sm_decomp_ms":600.9,"sm_graph_ms":693.1,"sm_hex_ms":549.9,"sm_index_ms":0,"sm_listing_cold_ms":280.9,"sm_listing_warm_ms":261.2,"sm_nav_ms":309,"sm_palette_ms":0.3,"sm_render_ms":249.3,"sm_search_ms":78.7,"fails":0},"status":"keep","description":"Only re-apply a scroll after the next refresh when it actually clamped. Both _apply_scroll implementations unconditionally scheduled a deferred scroll_to + refresh(layout=True) — a whole-screen re-arrange on every scroll — as a workaround for scrolling before the view's size is computed. Now the deferred pass runs only when scroll_offset didn't reach the target.","timestamp":1786061776694,"segment":0,"confidence":8.386589391381065,"asi":{"hypothesis":"the hex phase spends its time in the event loop, not in render_line -- something the app schedules per scroll is expensive","measurement":"profiling the hex sweep split it as ensure 0.1ms / scroll 6.7ms / pilot.pause 700ms / paint 106ms over 60 frames. The cost was in what the pause had to process.","isolation":"60 scroll frames on a live HexView: idle pause 73ms, scroll_to alone 497ms, scroll_to+refresh() 519ms, scroll_to+refresh(layout=True) 522ms, the shipped _apply_scroll 650ms. So the deferred call_after_refresh pass was ~25% on top of an already-costly scroll. After the fix: 453ms.","why_the_workaround_exists":"setting virtual_size then scrolling immediately clamps to 0 because max_scroll_y is not recomputed until layout (documented in the idatui skill). Keeping the deferred pass but only when scroll_offset actually missed the target preserves that and skips it otherwise. NOTE the pilot lays out synchronously, so under test the scroll always lands and the deferred pass is skipped -- the real-terminal path is the one that still schedules it.","gains":"total 19476 -> 19006 (-2.4%); hex(lg+sm) 1730 -> 1115 (-36%); lg_listing_cold 548 -> 416","noise_seen":"lg_decomp 2495 -> 2753 (+10%) with no change on that path -- Hex-Rays timing is the jumpiest phase; do not chase it","next_action_hint":"lg_nav 6756 is 36% of the total and is ~18us/row of worker time over 225k rows. Its parts: generate_disasm_line 5.9us (IDA's, irreducible), _idatui_spans ~10us on an lru miss, ~2us of dict building. Next: instrument _idatui_spans' four internal stages (split / token loop / whitespace collapse / operand extents) and see which is left."}} {"type":"config","name":"ida-tui performance (v2 bench: graph opens are now measured cold)","metricName":"total_ms","metricUnit":"ms","bestDirection":"lower"} {"run":11,"commit":"26fa14c","metric":27912.9,"metrics":{"lg_boot_ms":742.8,"lg_decomp_ms":2595.7,"lg_graph_ms":9561.4,"lg_hex_ms":554.4,"lg_index_ms":77.6,"lg_listing_cold_ms":548.6,"lg_listing_warm_ms":405.5,"lg_nav_ms":6552.9,"lg_palette_ms":4.9,"lg_render_ms":216.1,"lg_search_ms":2218,"pure_graph_ms":507.6,"sm_boot_ms":535.6,"sm_decomp_ms":620.2,"sm_graph_ms":962,"sm_hex_ms":587.4,"sm_index_ms":0,"sm_listing_cold_ms":261.8,"sm_listing_warm_ms":261.7,"sm_nav_ms":368.8,"sm_palette_ms":0.3,"sm_render_ms":252.4,"sm_search_ms":77.1,"fails":0},"status":"keep","description":"RE-BASELINE on a corrected benchmark. phase_graph was measuring a cache hit: the fixture picker called Program.flowchart (which caches per function), so the timed Space press only did a dict lookup. Fixtures now use the raw flowchart tool and the graph cache is cleared before the phase. Cold graph opens cost lg_graph 9561ms — 34% of the total, previously invisible.","timestamp":1786062344258,"segment":1,"confidence":null,"asi":{"hypothesis":"the graph phase looked suspiciously cheap; check whether it was measuring real work","bench_flaw_found":"run_target picked its 12 fixture functions by calling app.program.flowchart(f.addr) to count blocks. Program.flowchart caches per (function, name generation) AND fetches every listing row in the function's extent, so the fixture loop paid the whole cost and phase_graph then timed a cache hit. Fixed: fixtures use client.call('flowchart') directly, and phase_graph clears program._flowcharts first.","carried_forward_from_v1":"experiments 1-10 took total_ms from 46572 to 19006 (-59%) on the old bench; that history is in the archived log and summarised in .auto/prompt.md","bug_this_exposed":"Program.flowchart does rows = _heads_between(min(block.start), max(block.end)) -- the CONVEX HULL of the blocks. IDA function chunks put tail blocks hundreds of KB from the entry, so a 1384-byte function (jobs_builtin) fetches 128000 listing rows and takes 2961ms to graph. Measured on bash: 4 of the 12 fixtures have spans of 280KB-680KB and cost 258-2961ms each; the other 8 have span == size and cost 7-32ms. Then b.rows = [h for h in rows if ...] is O(blocks x rows) on top -- 541ms for the set.","fix_planned":"fetch the MERGED BLOCK INTERVALS instead of the hull (adjacent blocks coalesce, so a normal function is still one call), and assign rows to blocks by bisect instead of a full scan per block","next_action_hint":"apply that fix; it should take lg_graph from 9561 to well under 1000"}} +{"run":12,"commit":"870f89e","metric":19062.1,"metrics":{"lg_boot_ms":751.3,"lg_decomp_ms":2605.7,"lg_graph_ms":1022,"lg_hex_ms":554.5,"lg_index_ms":103.9,"lg_listing_cold_ms":545,"lg_listing_warm_ms":405.6,"lg_nav_ms":6636.8,"lg_palette_ms":4.7,"lg_render_ms":212.2,"lg_search_ms":2269,"pure_graph_ms":239.9,"sm_boot_ms":538.5,"sm_decomp_ms":688.4,"sm_graph_ms":712.7,"sm_hex_ms":557.5,"sm_index_ms":0,"sm_listing_cold_ms":259.9,"sm_listing_warm_ms":260.2,"sm_nav_ms":363.8,"sm_palette_ms":0.3,"sm_render_ms":252.7,"sm_search_ms":77.5,"fails":0},"status":"keep","description":"Fetch a graph's listing rows from the blocks' MERGED EXTENTS, not their convex hull, and assign them per block by bisect. IDA puts a function's cold/tail chunks far from its entry, so the hull of a 1.4KB function could be 680KB wide: it fetched 128k rows, took 3s, and still came back EMPTY for the far blocks because the pager's 64-page bound ran out first. lg_graph 9561 -> 1022.","timestamp":1786062629380,"segment":1,"confidence":null,"asi":{"hypothesis":"Program.flowchart fetches the convex hull of the basic blocks, which is enormous for a function with IDA chunks","gains":"total 27913 -> 19062 (-31.7%); lg_graph 9561 -> 1022 (-89%); sm_graph 962 -> 713","correctness_is_BETTER_not_equal":"differential over the 80 largest functions of bash: 1201 blocks differ, and EVERY one of them is a block the old code returned ZERO rows for. _heads_between is bounded to 64 pages x 2000 heads = 128k, and a 680KB hull exhausted that before reaching the tail chunk -- so far blocks drew as empty boxes. No block lost a row. targets/echo: 0 differences at all (no chunked functions).","scale":"80 bash functions: hull 44.4s / 1,864,814 rows fetched -> intervals 1.4s / 77,221 rows. 24x less data, 31x faster.","design":"blocks are sorted and merged with a 256-byte tolerance so alignment padding does not split an interval; an ordinary contiguous function is still exactly ONE heads call, as before. Row->block assignment is now bisect on the address list instead of a full scan per block (541ms -> ~0 for the 12-function set).","verify_script":"/tmp/fceq.py (kept the pattern in .auto/ideas.md): rebuild the blocks twice, fetch both ways, compare per-block row lists","next_action_hint":"lg_nav 6637 is now 35% of the total and sits at the per-row floor (~16.5us worker + ~7us client). decomp lg+sm 3294 is next: 1370ms of Hex-Rays, 240ms of pygments highlight_c, ~600ms of Textual loading-cover churn. Also unmeasured by the bench: domain.decomp_map costs 280ms per function on the split-view path."}} diff --git a/idatui/highlight.py b/idatui/highlight.py index 5f504bf..a19f86a 100644 --- a/idatui/highlight.py +++ b/idatui/highlight.py @@ -41,11 +41,24 @@ _DEFAULT = Style(color="#c3cad3") # 11.0:1 body _lexer = CLexer(stripnl=False, ensurenl=False) +#: Resolved styles by token type. Pygments token types are interned singletons +#: and a whole decompilation only ever uses about eighteen of them, but +#: ``token in ttype`` is a hierarchy walk and _STYLES is scanned in order -- so +#: without this every token in the body pays up to nine of those walks. It was a +#: quarter of the time spent highlighting a function. +_STYLE_CACHE: dict[object, Style] = {} + + def _style_for(token) -> Style: - for ttype, style in _STYLES: - if token in ttype: - return style - return _DEFAULT + style = _STYLE_CACHE.get(token) + if style is None: + style = _DEFAULT + for ttype, candidate in _STYLES: + if token in ttype: + style = candidate + break + _STYLE_CACHE[token] = style + return style def highlight_c(code: str) -> list[list[Segment]]: @@ -55,6 +68,9 @@ def highlight_c(code: str) -> list[list[Segment]]: if not value: continue style = _style_for(token) + if "\n" not in value: # the common case: a token inside one line + lines[-1].append(Segment(value, style)) + continue parts = value.split("\n") for i, part in enumerate(parts): if i > 0: diff --git a/idatui/worker_client.py b/idatui/worker_client.py index 59c62a1..4f90700 100644 --- a/idatui/worker_client.py +++ b/idatui/worker_client.py @@ -116,7 +116,17 @@ class WorkerClient: # fifth of a second even when the worker was ready in milliseconds # (a small binary, or a seeded .i64), which is most of the time in # the tests and noticeable on a re-open. + # + # Backing off geometrically from the first probe was still too eager: + # a seeded database is ready at ~250ms, by which point the delay has + # grown to 134ms, so every open waited ~350ms whatever the binary -- + # the same number for a 47KB `echo` and a 1.2MB `bash`, which is what + # gives a polling artefact away. Hold the fast rate for the first few + # seconds (a connect attempt on an absent socket is microseconds) and + # only slow down for a genuine cold auto-analysis, which runs for + # minutes and does not care about 200ms. delay = 0.005 + fast_until = t0 + 5.0 while time.time() < deadline: try: s = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) @@ -132,7 +142,8 @@ class WorkerClient: progress(f"auto-analyzing {os.path.basename(self._bin)}… " f"({int(time.time() - t0)}s)") time.sleep(delay) - delay = min(delay * 1.6, 0.2) + if time.time() > fast_until: + delay = min(delay * 1.6, 0.2) raise IDAConnectionError("worker did not become ready in time") @property -- cgit v1.3.1-sl0p