Stop two tests failing for reasons that are not about this client

Both have been red on main since the Rust 1.98 build change, which
changed no code and is a coincidence of timing rather than a cause.

The first is the appender against INSERT. It wants inserting to take
more than five times what appending takes, which is the number that
says the appender is still batching rather than doing a commit per row.
It read three on a hosted runner and failed, and it fails on some jobs
of a run and not others, which is what a threshold sitting in the
middle of the measurement looks like.

The row count was the problem. What an INSERT costs is what a commit
costs, and that is a property of the disk rather than of the engine:
24 ms a row on a server with a real disk under contention, 80 us a row
on a hosted runner where the commit is plainly not reaching a platter.
Three hundred times apart from the same build. Two hundred rows is
therefore four seconds of INSERT on the first machine and sixteen
milliseconds on the second, and sixteen milliseconds is not enough work
for the appender's one commit to have amortised, so the second machine
was measuring what the appender costs to start rather than what it
costs to run.

So the row count is worked out on the machine instead of written down.
Forty INSERTs say what one costs here, and the count is whatever spends
about a second and a half on the INSERT side, floored at two hundred so
the appender always has rows to amortise over and capped at forty
thousand for memory. Measured on a real disk the ratio is 44 at two
hundred rows, 81 at a thousand and 659 at five thousand, so the gate
stays at five: the number that says the appender is batching, not the
number any machine hits.

The second is the test that counts how far the main thread gets while
another one is inside the engine, which is how the released GIL is
checked. It reads no clock, so it was not marked timing, so the
sanitizer job runs it, and valgrind runs one thread at a time by
design. The count is zero there whatever the binding does, and the test
reports a held GIL that is not held. There is nothing to fix in the
binding for that, so it takes the timing marker like the tests that
read a clock, and the marker's description now covers both.

Author: tamnd

pyproject.toml

@@ -89,7 +89,16 @@ pythonpath = ["tools", "."]
 # slower by a factor nobody controls and the two sides of a ratio
 # slower by different ones. The jobs that run under one deselect them
 # by this marker and the ordinary jobs run them all.
-markers = ["timing: asserts on elapsed time, so a sanitizer run has to skip it"]
+#
+# The marker covers one thing that reads no clock at all: counting how
+# far the main thread gets while another one is inside the engine, which
+# is how the GIL is checked to be released. Valgrind runs one thread at
+# a time, so that count is zero there no matter what the binding does.
+# It is the same problem for the same reason and it wants the same
+# marker.
+markers = [
+  "timing: asserts on how fast or how concurrently something ran, so a sanitizer run has to skip it"
+]
 
 [tool.ruff]
 target-version = "py311"

tests/test_appender.py

@@ -425,41 +425,80 @@ def run() -> None:
     assert ticks > 1000, f"the main thread only got {ticks} turns"
 
 
-#: Rows for the comparison against `INSERT`, and few enough that the
-#: `INSERT` half finishes in a few seconds. It is the slow half by three
-#: orders of magnitude, and it gets slower as the table grows, because
-#: every row of it is a commit and a fold.
-COMPARED = 200
+#: What the `INSERT` half of the comparison is allowed to spend, and
+#: the row count is worked out from it rather than written down. A fixed
+#: row count cannot serve both kinds of machine this runs on, because
+#: what an `INSERT` costs is what a commit costs and that is a property
+#: of the disk and not of the engine. Measured per row: 24 ms on a
+#: server with a real disk under contention, 80 us on a hosted CI runner
+#: where a commit is not reaching a platter at all. Three hundred times
+#: apart, from the same engine. Two hundred rows is four seconds on the
+#: first and sixteen milliseconds on the second.
+BUDGET = 1.5
+
+#: How many `INSERT`s are timed to learn what one costs here. Enough to
+#: average over, few enough to be quick on the slow machine, where this
+#: alone is a second.
+CALIBRATE = 40
+
+#: The row count never goes outside this, whatever the calibration says.
+#: The floor is where the appender has enough rows to have amortised the
+#: one commit it does. The ceiling is memory and patience.
+FEWEST = 200
+MOST = 40_000
+
+
+def _rows(count: int) -> list[tuple[int, str]]:
+    return [(uid, f"p{uid}") for uid in range(1, count)]
+
+
+def _time_inserting(conn: zudb.Connection, rows: list[tuple[int, str]]) -> float:
+    started = time.perf_counter()
+    for uid, name in rows:
+        conn.execute("INSERT (p:person {uid: $u, name: $n})", {"u": uid, "n": name})
+    return time.perf_counter() - started
 
 
 @pytest.mark.timing
 def test_appending_beats_inserting_by_the_margin_that_makes_it_worth_having(
     tmp_path: Path,
 ) -> None:
-    rows = [(uid, f"p{uid}") for uid in range(1, COMPARED)]
+    # What one INSERT costs here, asked rather than assumed.
+    with zudb.connect(tmp_path / "calibration.zu1") as conn:
+        conn.execute("INSERT (p:person {uid: 0, name: 'seed'})")
+        each = _time_inserting(conn, _rows(CALIBRATE)) / (CALIBRATE - 1)
+
+    compared = min(MOST, max(FEWEST, int(BUDGET / each)))
+    rows = _rows(compared)
 
     with zudb.connect(tmp_path / "inserted.zu1") as conn:
         conn.execute("INSERT (p:person {uid: 0, name: 'seed'})")
-        started = time.perf_counter()
-        for uid, name in rows:
-            conn.execute("INSERT (p:person {uid: $u, name: $n})", {"u": uid, "n": name})
-        inserting = time.perf_counter() - started
+        inserting = _time_inserting(conn, rows)
 
     with zudb.connect(tmp_path / "appended.zu1") as conn:
         conn.execute("INSERT (p:person {uid: 0, name: 'seed'})")
         started = time.perf_counter()
         with conn.appender("person") as app:
             app.append_rows(rows)
         appending = time.perf_counter() - started
-        assert conn.execute("MATCH (p:person) RETURN count(p) AS n").fetchone() == (COMPARED,)
-
-    # Measured at about 150 times on this machine at this row count and
-    # rising with it, since one commit is one commit however many rows
-    # it carries. It is 18 on a shared CI runner, where a commit costs
-    # 25 ms of somebody else's disk and the appender's single one is
-    # most of what it spends, so the gate is 5: the number that says the
-    # appender is still batching rather than the number either machine
-    # hits.
+        assert conn.execute("MATCH (p:person) RETURN count(p) AS n").fetchone() == (compared,)
+
+    # The appender does one commit however many rows it carries, so its
+    # cost is nearly all fixed and the ratio grows with the row count.
+    # That is the property being tested and it is why the row count is
+    # chosen instead of fixed: at two hundred rows on a machine where a
+    # commit is free, the appender is measured almost entirely on what
+    # it costs to start, the ratio sits around three, and it passes or
+    # fails on which way the runner was leaning that morning. It did
+    # both. Spending the same wall clock on the INSERT side everywhere
+    # puts enough rows on the appender for the answer to be about the
+    # engine.
+    #
+    # Measured at 44 with 200 rows, 81 with 1000 and 659 with 5000 on a
+    # server with a real disk. The gate is 5 because it is the number
+    # that says the appender is still batching, not the number any
+    # machine hits.
     assert inserting > 5 * appending, (
-        f"{COMPARED} rows: {inserting * 1000:.0f} ms inserted, {appending * 1000:.0f} ms appended"
+        f"{compared} rows at {each * 1e6:.0f} us an INSERT: "
+        f"{inserting * 1000:.0f} ms inserted, {appending * 1000:.0f} ms appended"
     )

tests/test_threads.py

@@ -12,6 +12,7 @@
 import threading
 from pathlib import Path
 
+import pytest
 import zudb
 
 # Every pair of people, filtered, which is a statement that runs for
@@ -62,6 +63,14 @@ def run() -> None:
     assert answers == [("ada",)] * 4
 
 
+# Marked timing not because it reads a clock but because it counts how
+# far the main thread got while another one worked, and that number is
+# only meaningful on a real scheduler. Valgrind runs one thread at a
+# time by design, so the loop below gets zero turns there and the test
+# reports a held GIL that is not held. There is nothing to fix in the
+# binding for that, so the sanitizer run skips it the same way it skips
+# the ones that read a clock.
+@pytest.mark.timing
 def test_python_keeps_running_while_a_statement_does(crowd: zudb.Connection) -> None:
     ticks = 0
     done = threading.Event()