Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 10 additions & 1 deletion pyproject.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down
13 changes: 12 additions & 1 deletion tests/test_aio.py
Original file line number Diff line number Diff line change
Expand Up @@ -444,11 +444,18 @@ async def test_the_loop_runs_while_a_stream_waits_for_a_batch(tmp_path: Path) ->
conn = await crowded(tmp_path / "free.zu1", LONG)
ticks = 0

# Yielding with no delay rather than with a small one, so that a
# tick is one turn of the loop and not one turn of the system
# clock. Asking for a millisecond gets a millisecond on Linux and
# macOS and about fifteen on Windows, which is what that platform's
# timer can resolve, and fifty milliseconds of waiting below then
# buys three ticks instead of fifty. This read 9 against a gate of
# 10 there and it was the clock it was measuring, not the loop.
async def tick() -> None:
nonlocal ticks
while True:
ticks += 1
await asyncio.sleep(0.001)
await asyncio.sleep(0)

async with conn:
counting = asyncio.create_task(tick())
Expand All @@ -457,6 +464,10 @@ async def tick() -> None:
await asyncio.sleep(0.05)
counting.cancel()

# A loop held for the length of a batch would leave this task the
# gaps between batches, which is a handful of turns. A free one
# gives it thousands, so the gate is nowhere near either answer and
# does not care how fast the machine is.
assert ticks > 10


Expand Down
79 changes: 59 additions & 20 deletions tests/test_appender.py
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)
9 changes: 9 additions & 0 deletions tests/test_threads.py
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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()
Expand Down
Loading