| | 6 | ``` |
| | 7 | """Check and benchmark the local post-commit callback change without Git writes.""" |
| | 8 | |
| | 9 | from __future__ import annotations |
| | 10 | |
| | 11 | import argparse |
| | 12 | import ast |
| | 13 | import gc |
| | 14 | import hashlib |
| | 15 | import importlib.metadata |
| | 16 | import json |
| | 17 | import logging |
| | 18 | import math |
| | 19 | import os |
| | 20 | import platform |
| | 21 | import runpy |
| | 22 | import statistics |
| | 23 | import subprocess |
| | 24 | import sys |
| | 25 | import time |
| | 26 | import tracemalloc |
| | 27 | import types |
| | 28 | import unittest |
| | 29 | from pathlib import Path |
| | 30 | |
| | 31 | if not __debug__: |
| | 32 | raise RuntimeError( |
| | 33 | "Run these checks without -O or PYTHONOPTIMIZE; assertions must be enabled." |
| | 34 | ) |
| | 35 | |
| | 36 | HERE = Path(__file__).resolve().parent |
| | 37 | REPO = Path( |
| | 38 | os.environ.get("DJANGO_REVIEW_REPO", HERE.parent / "django-current") |
| | 39 | ).resolve() |
| | 40 | BASE = "d430084791a61b31cecec132bce3dca19194f7f2" |
| | 41 | FILES = ("django/db/backends/base/base.py", "tests/transaction_hooks/tests.py") |
| | 42 | REPEATS = 5 |
| | 43 | COUNTS = (0, 1, 2, 10, 100, 500, 1000, 2000, 5000, 10000) |
| | 44 | WORKLOADS = [(count, 0) for count in COUNTS] + [(100, 65536), (1000, 1024)] |
| | 45 | |
| | 46 | CPU_HELPER = HERE / "benchmark_cpu.py" |
| | 47 | if not CPU_HELPER.exists(): |
| | 48 | CPU_HELPER = HERE.parent / "benchmarks/benchmark_cpu.py" |
| | 49 | sys.path.insert(0, str(CPU_HELPER.parent)) |
| | 50 | from benchmark_cpu import RotatingCores |
| | 51 | |
| | 52 | sys.path.insert(0, str(REPO)) |
| | 53 | from django.db.backends.base import base as base_module |
| | 54 | |
| | 55 | if Path(base_module.__file__).resolve() != REPO / FILES[0]: |
| | 56 | raise RuntimeError("The wrong Django checkout was imported") |
| | 57 | |
| | 58 | |
| | 59 | def digest(path): |
| | 60 | return hashlib.sha256(path.read_bytes()).hexdigest() |
| | 61 | |
| | 62 | |
| | 63 | def metadata(): |
| | 64 | return { |
| | 65 | "base_commit": BASE, |
| | 66 | "python": platform.python_version(), |
| | 67 | "platform": platform.platform(), |
| | 68 | "source_hashes": {name: digest(REPO / name) for name in FILES}, |
| | 69 | "runner_sha256": digest(Path(__file__)), |
| | 70 | "affinity_helper_sha256": digest(CPU_HELPER), |
| | 71 | "dependencies": { |
| | 72 | name: importlib.metadata.version(name) |
| | 73 | for name in ("Django", "asgiref", "sqlparse", "tzdata") |
| | 74 | }, |
| | 75 | } |
| | 76 | |
| | 77 | |
| | 78 | def methods(): |
| | 79 | source = subprocess.check_output( |
| | 80 | ["git", "show", f"{BASE}:{FILES[0]}"], |
| | 81 | cwd=REPO, |
| | 82 | text=True, |
| | 83 | encoding="utf-8", |
| | 84 | ) |
| | 85 | cls = next( |
| | 86 | node |
| | 87 | for node in ast.parse(source).body |
| | 88 | if isinstance(node, ast.ClassDef) and node.name == "BaseDatabaseWrapper" |
| | 89 | ) |
| | 90 | node = next( |
| | 91 | node |
| | 92 | for node in cls.body |
| | 93 | if isinstance(node, ast.FunctionDef) |
| | 94 | and node.name == "run_and_clear_commit_hooks" |
| | 95 | ) |
| | 96 | namespace = dict(vars(base_module)) |
| | 97 | exec( |
| | 98 | compile( |
| | 99 | ast.Module(body=[node], type_ignores=[]), |
| | 100 | "<pinned upstream callback dispatch>", |
| | 101 | "exec", |
| | 102 | ), |
| | 103 | namespace, |
| | 104 | ) |
| | 105 | compiled = namespace[node.name] |
| | 106 | original = types.FunctionType( |
| | 107 | compiled.__code__, vars(base_module), compiled.__name__, compiled.__defaults__ |
| | 108 | ) |
| | 109 | return { |
| | 110 | "base": original, |
| | 111 | "pr": base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks, |
| | 112 | } |
| | 113 | |
| | 114 | |
| | 115 | def save(name, value): |
| | 116 | (HERE / name).write_text(json.dumps(value, indent=2), encoding="utf-8") |
| | 117 | |
| | 118 | |
| | 119 | def run_tests(version, cores): |
| | 120 | choices = methods() |
| | 121 | base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks = choices[version] |
| | 122 | report = { |
| | 123 | **metadata(), |
| | 124 | "version": version, |
| | 125 | "backend": "SQLite", |
| | 126 | "parallel_workers": 1, |
| | 127 | } |
| | 128 | original_start = unittest.TestResult.startTest |
| | 129 | original_run = unittest.TextTestRunner.run |
| | 130 | count = 0 |
| | 131 | |
| | 132 | def start_test(result, test): |
| | 133 | nonlocal count |
| | 134 | if count % 50 == 0: |
| | 135 | cores.rotate() |
| | 136 | count += 1 |
| | 137 | return original_start(result, test) |
| | 138 | |
| | 139 | def run_suite(runner, suite): |
| | 140 | result = original_run(runner, suite) |
| | 141 | report.update( |
| | 142 | tests_run=result.testsRun, |
| | 143 | failures=[test.id() for test, _ in result.failures], |
| | 144 | errors=[test.id() for test, _ in result.errors], |
| | 145 | skipped=[test.id() for test, _ in result.skipped], |
| | 146 | expected_failures=len(result.expectedFailures), |
| | 147 | unexpected_successes=[test.id() for test in result.unexpectedSuccesses], |
| | 148 | ) |
| | 149 | return result |
| | 150 | |
| | 151 | unittest.TestResult.startTest = start_test |
| | 152 | unittest.TextTestRunner.run = run_suite |
| | 153 | os.chdir(REPO / "tests") |
| | 154 | sys.path.insert(0, str(REPO / "tests")) |
| | 155 | sys.argv = [ |
| | 156 | "runtests.py", |
| | 157 | "transaction_hooks", |
| | 158 | "transactions", |
| | 159 | "backends.base", |
| | 160 | "--settings=test_sqlite", |
| | 161 | "--parallel=1", |
| | 162 | "--verbosity=1", |
| | 163 | ] |
| | 164 | try: |
| | 165 | try: |
| | 166 | runpy.run_path(str(REPO / "tests/runtests.py"), run_name="__main__") |
| | 167 | code = 0 |
| | 168 | except SystemExit as error: |
| | 169 | code = error.code or 0 |
| | 170 | finally: |
| | 171 | unittest.TestResult.startTest = original_start |
| | 172 | unittest.TextTestRunner.run = original_run |
| | 173 | base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks = choices["pr"] |
| | 174 | report["exit_code"] = code |
| | 175 | save(f"tests_{version}.json", report) |
| | 176 | return code |
| | 177 | |
| | 178 | |
| | 179 | def setup(): |
| | 180 | from django.conf import settings |
| | 181 | |
| | 182 | settings.configure( |
| | 183 | DATABASES={ |
| | 184 | "default": {"ENGINE": "django.db.backends.sqlite3", "NAME": ":memory:"} |
| | 185 | }, |
| | 186 | INSTALLED_APPS=[], |
| | 187 | SECRET_KEY="local-callback-check", |
| | 188 | USE_TZ=True, |
| | 189 | ) |
| | 190 | import django |
| | 191 | |
| | 192 | django.setup() |
| | 193 | from django.db import connection |
| | 194 | |
| | 195 | connection.ensure_connection() |
| | 196 | |
| | 197 | |
| | 198 | class CallbackAbort(BaseException): |
| | 199 | pass |
| | 200 | |
| | 201 | |
| | 202 | def outcome(method, count, failure_at, robust_mode, nested_mode, exception_class): |
| | 203 | from django.db import connection, transaction |
| | 204 | |
| | 205 | previous = base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks |
| | 206 | base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks = method |
| | 207 | events, errors = [], [] |
| | 208 | |
| | 209 | class Capture(logging.Handler): |
| | 210 | def emit(self, record): |
| | 211 | errors.append( |
| | 212 | ( |
| | 213 | record.getMessage(), |
| | 214 | type(record.exc_info[1]).__name__, |
| | 215 | str(record.exc_info[1]), |
| | 216 | ) |
| | 217 | ) |
| | 218 | |
| | 219 | handler = Capture() |
| | 220 | logger = base_module.logger |
| | 221 | logger.addHandler(handler) |
| | 222 | old_propagate = logger.propagate |
| | 223 | logger.propagate = False |
| | 224 | error = None |
| | 225 | |
| | 226 | def callback(index): |
| | 227 | events.append(("callback", index)) |
| | 228 | if index == failure_at: |
| | 229 | raise exception_class("callback failed") |
| | 230 | if nested_mode != "none" and index % 3 == 0: |
| | 231 | if nested_mode == "transaction": |
| | 232 | with transaction.atomic(): |
| | 233 | transaction.on_commit(lambda: events.append(("nested", index))) |
| | 234 | else: |
| | 235 | transaction.on_commit(lambda: events.append(("nested", index))) |
| | 236 | |
| | 237 | try: |
| | 238 | try: |
| | 239 | with transaction.atomic(): |
| | 240 | for index in range(count): |
| | 241 | robust = robust_mode == "all" or ( |
| | 242 | robust_mode == "alternating" and index % 2 == 0 |
| | 243 | ) |
| | 244 | transaction.on_commit( |
| | 245 | lambda index=index: callback(index), robust=robust |
| | 246 | ) |
| | 247 | except BaseException as caught: |
| | 248 | error = type(caught).__name__, str(caught) |
| | 249 | return ( |
| | 250 | events, |
| | 251 | error, |
| | 252 | errors, |
| | 253 | len(connection.run_on_commit), |
| | 254 | connection.in_atomic_block, |
| | 255 | connection.get_autocommit(), |
| | 256 | ) |
| | 257 | finally: |
| | 258 | logger.removeHandler(handler) |
| | 259 | logger.propagate = old_propagate |
| | 260 | base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks = previous |
| | 261 | |
| | 262 | |
| | 263 | def verify(choices, cores): |
| | 264 | comparisons = 0 |
| | 265 | for count in (0, 1, 2, 3, 10, 30, 100, 250): |
| | 266 | cores.rotate() |
| | 267 | positions = ( |
| | 268 | list(dict.fromkeys((None, 0, count // 2, count - 1))) if count else [None] |
| | 269 | ) |
| | 270 | for failure_at in positions: |
| | 271 | for robust in ("none", "all", "alternating"): |
| | 272 | for nested in ("none", "immediate", "transaction"): |
| | 273 | for exception in (ValueError, CallbackAbort): |
| | 274 | old = outcome( |
| | 275 | choices["base"], |
| | 276 | count, |
| | 277 | failure_at, |
| | 278 | robust, |
| | 279 | nested, |
| | 280 | exception, |
| | 281 | ) |
| | 282 | new = outcome( |
| | 283 | choices["pr"], count, failure_at, robust, nested, exception |
| | 284 | ) |
| | 285 | if old != new: |
| | 286 | raise AssertionError( |
| | 287 | (count, failure_at, robust, nested, exception, old, new) |
| | 288 | ) |
| | 289 | comparisons += 1 |
| | 290 | print(f"Differential checks: {comparisons} matched", flush=True) |
| | 291 | result = {**metadata(), "comparisons": comparisons, "differences": []} |
| | 292 | save("differential.json", result) |
| | 293 | return result |
| | 294 | |
| | 295 | |
| | 296 | def workflow(method, count, payload_size): |
| | 297 | from django.db import connection, transaction |
| | 298 | |
| | 299 | previous = base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks |
| | 300 | base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks = method |
| | 301 | updates = {} |
| | 302 | try: |
| | 303 | with transaction.atomic(): |
| | 304 | for index in range(count): |
| | 305 | if payload_size: |
| | 306 | transaction.on_commit( |
| | 307 | lambda index=index, payload=bytearray( |
| | 308 | payload_size |
| | 309 | ): updates.__setitem__(f"record:{index}", index + len(payload)) |
| | 310 | ) |
| | 311 | else: |
| | 312 | transaction.on_commit( |
| | 313 | lambda index=index: updates.__setitem__( |
| | 314 | f"record:{index}", index |
| | 315 | ) |
| | 316 | ) |
| | 317 | if connection.run_on_commit: |
| | 318 | raise AssertionError("Pending callbacks after commit") |
| | 319 | return list(updates.items()) |
| | 320 | finally: |
| | 321 | base_module.BaseDatabaseWrapper.run_and_clear_commit_hooks = previous |
| | 322 | |
| | 323 | |
| | 324 | def write_report(report): |
| | 325 | save("benchmark_results.json", report) |
| | 326 | lines = [ |
| | 327 | "# Post-commit callback benchmark", |
| | 328 | "", |
| | 329 | "Final slot-clearing implementation, not the earlier plain-loop prototype.", |
| | 330 | "", |
| | 331 | f"Python {report['python']}, Windows, SQLite. Five paired timing samples and five separate tracemalloc peaks per version, workload and fixed CPU pair. Short calls are batched. GC is enabled. Only two physical cores are allowed at once; pairs rotate between rows. One process, not parallel workers. Different CPU pairs are not pooled.", |
| | 332 | "", |
| | 333 | "The complete workflow includes transaction begin/commit, callback registration and callbacks updating a dictionary. Payload cases give each callback a separate bytearray of the stated size. No model writes, network or task broker. Large queues are stress cases, not typical requests. Peak memory is newly traced Python allocations, not total process RAM. All measured rows, including losses, are shown.", |
| | 334 | "", |
| | 335 | "| Callbacks | Captured payload/callback | CPU mask | Base time | Changed time | Speed | Base peak | Changed peak | Memory |", |
| | 336 | "|---:|---:|---|---:|---:|---|---:|---:|---|", |
| | 337 | ] |
| | 338 | for row in report["results"]: |
| | 339 | old, new = (statistics.median(row[v]["seconds"]) for v in ("base", "pr")) |
| | 340 | old_peak, new_peak = ( |
| | 341 | statistics.median(row[v]["peak_bytes"]) for v in ("base", "pr") |
| | 342 | ) |
| | 343 | speed = f"{old / new:.3f}x faster" if new < old else f"{new / old:.3f}x slower" |
| | 344 | memory = ( |
| | 345 | "same" |
| | 346 | if old_peak == new_peak |
| | 347 | else ( |
| | 348 | f"{new_peak / old_peak:.6f}x more" |
| | 349 | if new_peak > old_peak |
| | 350 | else f"{old_peak / new_peak:.6f}x less" |
| | 351 | ) |
| | 352 | ) |
| | 353 | lines.append( |
| | 354 | f"| {row['callbacks']:,} | {row['payload_bytes']:,} B | {row['mask']} | {old * 1000:.4f} ms | {new * 1000:.4f} ms | {speed} | {old_peak / 1024:.3f} KiB | {new_peak / 1024:.3f} KiB | {memory} |" |
| | 355 | ) |
| | 356 | lines += [ |
| | 357 | "", |
| | 358 | f"Completed {len(report['results'])}/{report['planned_rows']} rows. Complete: {report['complete']}.", |
| | 359 | "", |
| | 360 | "Raw samples and source, runner and helper hashes are in benchmark_results.json.", |
| | 361 | "", |
| | 362 | ] |
| | 363 | (HERE / "benchmark_results.md").write_text("\n".join(lines), encoding="utf-8") |
| | 364 | |
| | 365 | |
| | 366 | def benchmark(choices, cores): |
| | 367 | report = { |
| | 368 | **metadata(), |
| | 369 | "repeats": REPEATS, |
| | 370 | "planned_rows": len(WORKLOADS) * len(cores.pairs), |
| | 371 | "cpu_pairs": [hex(mask) for mask in cores.pairs], |
| | 372 | "complete": False, |
| | 373 | "results": [], |
| | 374 | } |
| | 375 | write_report(report) |
| | 376 | for count, payload in WORKLOADS: |
| | 377 | for _ in cores.pairs: |
| | 378 | mask = cores.rotate() |
| | 379 | expected = workflow(choices["base"], count, payload) |
| | 380 | assert workflow(choices["pr"], count, payload) == expected |
| | 381 | start = time.perf_counter() |
| | 382 | workflow(choices["base"], count, payload) |
| | 383 | batch = max( |
| | 384 | 1, min(1000, math.ceil(0.05 / max(time.perf_counter() - start, 1e-9))) |
| | 385 | ) |
| | 386 | row = { |
| | 387 | "callbacks": count, |
| | 388 | "payload_bytes": payload, |
| | 389 | "mask": mask, |
| | 390 | "batch_size": batch, |
| | 391 | "outputs_matched": True, |
| | 392 | "base": {"seconds": [], "peak_bytes": []}, |
| | 393 | "pr": {"seconds": [], "peak_bytes": []}, |
| | 394 | } |
| | 395 | for repeat in range(REPEATS): |
| | 396 | for version in (("base", "pr") if repeat % 2 == 0 else ("pr", "base")): |
| | 397 | gc.collect() |
| | 398 | start = time.perf_counter() |
| | 399 | for _ in range(batch): |
| | 400 | output = workflow(choices[version], count, payload) |
| | 401 | elapsed = (time.perf_counter() - start) / batch |
| | 402 | assert output == expected |
| | 403 | row[version]["seconds"].append(elapsed) |
| | 404 | progress = ( |
| | 405 | (len(report["results"]) + (repeat + 1) / REPEATS) |
| | 406 | / report["planned_rows"] |
| | 407 | * 100 |
| | 408 | ) |
| | 409 | print( |
| | 410 | f"{count} callbacks, {payload} B, {mask}: base + changed {repeat + 1}/5; overall {progress:.1f}%", |
| | 411 | flush=True, |
| | 412 | ) |
| | 413 | for repeat in range(REPEATS): |
| | 414 | for version in (("base", "pr") if repeat % 2 == 0 else ("pr", "base")): |
| | 415 | gc.collect() |
| | 416 | tracemalloc.start() |
| | 417 | try: |
| | 418 | output = workflow(choices[version], count, payload) |
| | 419 | peak = tracemalloc.get_traced_memory()[1] |
| | 420 | finally: |
| | 421 | tracemalloc.stop() |
| | 422 | assert output == expected |
| | 423 | row[version]["peak_bytes"].append(peak) |
| | 424 | report["results"].append(row) |
| | 425 | write_report(report) |
| | 426 | print( |
| | 427 | f"Saved row {len(report['results'])}/{report['planned_rows']}", |
| | 428 | flush=True, |
| | 429 | ) |
| | 430 | report["complete"] = True |
| | 431 | write_report(report) |
| | 432 | |
| | 433 | |
| | 434 | def validate(): |
| | 435 | current = metadata() |
| | 436 | for name in ( |
| | 437 | "tests_base.json", |
| | 438 | "tests_pr.json", |
| | 439 | "differential.json", |
| | 440 | "benchmark_results.json", |
| | 441 | ): |
| | 442 | result = json.loads((HERE / name).read_text(encoding="utf-8")) |
| | 443 | for key in ( |
| | 444 | "base_commit", |
| | 445 | "python", |
| | 446 | "source_hashes", |
| | 447 | "runner_sha256", |
| | 448 | "affinity_helper_sha256", |
| | 449 | "dependencies", |
| | 450 | ): |
| | 451 | if result[key] != current[key]: |
| | 452 | raise RuntimeError(f"Stale {name}: {key} changed; run -Check again") |
| | 453 | if name.startswith("tests_"): |
| | 454 | assert result["exit_code"] == 0 and result["tests_run"] > 0 |
| | 455 | assert ( |
| | 456 | not result["failures"] |
| | 457 | and not result["errors"] |
| | 458 | and not result["unexpected_successes"] |
| | 459 | ) |
| | 460 | elif name == "differential.json": |
| | 461 | assert result["comparisons"] >= 300 and not result["differences"] |
| | 462 | else: |
| | 463 | assert ( |
| | 464 | result["complete"] and len(result["results"]) == result["planned_rows"] |
| | 465 | ) |
| | 466 | assert result["planned_rows"] == len(WORKLOADS) * len(result["cpu_pairs"]) |
| | 467 | seen = set() |
| | 468 | for row in result["results"]: |
| | 469 | key = row["callbacks"], row["payload_bytes"], row["mask"] |
| | 470 | assert key not in seen and row["outputs_matched"] |
| | 471 | seen.add(key) |
| | 472 | for version in ("base", "pr"): |
| | 473 | assert ( |
| | 474 | len(row[version]["seconds"]) |
| | 475 | == len(row[version]["peak_bytes"]) |
| | 476 | == REPEATS |
| | 477 | ) |
| | 478 | write_report(result) |
| | 479 | print( |
| | 480 | "Source hashes, tests, differential checks and complete raw benchmarks validated." |
| | 481 | ) |
| | 482 | |
| | 483 | |
| | 484 | def main(): |
| | 485 | parser = argparse.ArgumentParser(description=__doc__) |
| | 486 | group = parser.add_mutually_exclusive_group(required=True) |
| | 487 | group.add_argument("--tests", choices=("base", "pr")) |
| | 488 | group.add_argument("--verify", action="store_true") |
| | 489 | group.add_argument("--benchmark", action="store_true") |
| | 490 | group.add_argument("--validate", action="store_true") |
| | 491 | args = parser.parse_args() |
| | 492 | if args.validate: |
| | 493 | validate() |
| | 494 | return 0 |
| | 495 | cores = RotatingCores() |
| | 496 | try: |
| | 497 | if args.tests: |
| | 498 | return run_tests(args.tests, cores) |
| | 499 | setup() |
| | 500 | choices = methods() |
| | 501 | if args.verify: |
| | 502 | verify(choices, cores) |
| | 503 | else: |
| | 504 | benchmark(choices, cores) |
| | 505 | return 0 |
| | 506 | finally: |
| | 507 | cores.restore() |
| | 508 | |
| | 509 | |
| | 510 | if __name__ == "__main__": |
| | 511 | raise SystemExit(main()) |
| | 512 | ``` |
| | 513 | |