Skip to content

--drill takes ~14 minutes on Hamlet.xml — the cost is document shape, not size #2

Description

@MarcelInTO

Summary

--drill takes about 14 minutes on Hamlet.xml (335,801 bytes), against well under a
second for --dump on the same file. It completes and passes — this is cost, not a
correctness bug — but it makes a real-shaped fixture impractical to drill routinely, and it is
slow enough to look like a hang.

Re-measured 2026-08-29 on main @ 9b6ec30 (432 checks, PASS). The original framing —
"scales with document size" — is contradicted by the numbers below and has been replaced.

Where the fixture went

src/Application/Samples/Hamlet.xml no longer exists in this repo. It was pruned with the
rest of the WinForms tree in 1ad7cf6 (2026-08-09). It survives on the upstream-master
mirror, so to reproduce:

git show upstream-master:src/Application/Samples/Hamlet.xml > /tmp/Hamlet.xml
make drill FILE=/tmp/Hamlet.xml

Evidence

Document KB Tree rows Drill (wall clock)
sandbox/testdata/emp.xml 1 19 8s
sandbox/testdata/robin-hood.xml 119 1,403 13s
robin-hood's divisions repeated x3 352 4,191 51s
Hamlet.xml (from upstream-master) 327 6,665 834s (13m 54s)

Size is not the driver. The synthesized fixture is larger than Hamlet — 352 KB against
327 KB — and drills 16x faster.

Row count is not the driver either, at least not linearly. 1,403 -> 4,191 rows costs
13s -> 51s, roughly proportional. 4,191 -> 6,665 rows — only 1.6x more — costs 51s -> 834s.
That is a cliff, not a curve.

It is not I/O. --drill copies the document to $TMPDIR/fux-drill before doing anything,
so both the 51s and the 834s runs read from the same directory on the same internal APFS
volume (/dev/disk3s5); a 330 KB read from it measures 0.1 ms, and the only network mounts on
the machine are Time Machine SMB, which nothing here touches. --dump parses either document
in well under a second.

Cause

Not established — this needs instrumentation, not more black-box timing. What is
established is only that the cost tracks something structural rather than volume.

Theory, not executed. The one structural difference visible so far between the 51s fixture
and the 834s one: Hamlet's widest run of same-depth siblings is 62 nodes against robin-hood's
9, and it is one level deeper (5 vs 4). If some per-check work is quadratic in sibling count —
a linear scan per row inside a per-row loop — that shape would produce exactly this cliff while
leaving a wide-but-shallow document cheap. Nothing has been profiled to support that, and it
should not be read as a finding.

Possible directions

  • Profile one section to find where the time actually goes before changing anything. Per-section
    elapsed timings in the drill's own report would localise it for free.
  • Most sections call app.LayoutAndDraw(true), and several trigger revalidation; redraw only
    where a check actually reads the screen.
  • If the cost turns out to be inherent, print elapsed time per section so a long run visibly
    progresses instead of appearing wedged — the failure mode that cost 11 minutes of watching a
    healthy run and reporting it as hung.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions