diff --git a/.evergreen/.evg.yml b/.evergreen/.evg.yml index 202d751c7db..85745246c53 100644 --- a/.evergreen/.evg.yml +++ b/.evergreen/.evg.yml @@ -806,6 +806,17 @@ functions: ${PREPARE_SHELL} PROJECT_DIRECTORY=${PROJECT_DIRECTORY} .evergreen/run-perf-tests.sh + "run-otel-perf-tests": + - command: shell.exec + type: "test" + params: + working_dir: "src" + env: + OTEL_BENCH_REPS: ${OTEL_BENCH_REPS} + script: | + ${PREPARE_SHELL} + PROJECT_DIRECTORY=${PROJECT_DIRECTORY} .evergreen/run-otel-perf-tests.sh + "run-graalvm-native-image-app": - command: shell.exec type: "test" @@ -1590,6 +1601,25 @@ tasks: PROVIDER: "Netty" - func: "send-dashboard-data" + # OpenTelemetry overhead benchmark (DRIVERS-3620): off / api-only / sdk-ratio / sdk-always, + # interleaved. Do not rename this task – renaming resets the performance time series. + - name: "perf-otel-task" + tags: [ "perf" ] + # On rhel90-dbx-perf-large each configuration takes ~10 min (the per-task 300 s ceiling applies, not the + # 100-iteration cap), so one repetition of 4 configurations is ~40 min plus ~15 min of setup. + exec_timeout_secs: 14400 + commands: + - func: "start-mongo-orchestration" + vars: + VERSION: "v8.0-perf" + TOPOLOGY: "server" + SSL: "nossl" + AUTH: "noauth" + - func: "run-otel-perf-tests" + vars: + OTEL_BENCH_REPS: "3" + - func: "send-dashboard-data" + - name: "aws-lambda-deployed-task" commands: - command: ec2.assume_role @@ -2277,6 +2307,7 @@ buildvariants: tasks: - name: "perf-task" - name: "perf-netty-task" + - name: "perf-otel-task" - name: plain-auth-test display_name: "PLAIN (LDAP) Auth test" diff --git a/.evergreen/run-otel-perf-tests.sh b/.evergreen/run-otel-perf-tests.sh new file mode 100755 index 00000000000..b3dc65ba25e --- /dev/null +++ b/.evergreen/run-otel-perf-tests.sh @@ -0,0 +1,37 @@ +#!/bin/bash + +# Runs the OpenTelemetry overhead benchmark (DRIVERS-3620) under every tracing +# configuration, interleaved and rotated, and writes results.json in the shape +# that "send-dashboard-data" uploads to the performance dashboard. +# +# Env: OTEL_BENCH_REPS (default 3), OTEL_BENCH_MIN_TIME (default 60), OTEL_BENCH_ITERATIONS (default 100) + +set -o xtrace +set -o errexit + +rm -rf driver-performance-test-data +git clone https://github.com/mongodb-labs/driver-performance-test-data.git +cd driver-performance-test-data +tar xf extended_bson.tgz +tar xf single_and_multi_document.tgz +cd .. + +RELATIVE_DIR_PATH="$(dirname "${BASH_SOURCE:-$0}")" +. "${RELATIVE_DIR_PATH}/setup-env.bash" + +export TEST_PATH="${PROJECT_DIRECTORY}/driver-performance-test-data" +export OUTPUT_DIR="${PROJECT_DIRECTORY}/otel-bench-results" +export OUTPUT_FILE="${PROJECT_DIRECTORY}/results.json" + +start_time=$(date +%s) +python3 -I driver-benchmarks/otel-bench.py \ + --data "${TEST_PATH}" \ + --out "${OUTPUT_DIR}" \ + --reps "${OTEL_BENCH_REPS:-3}" \ + --min-time "${OTEL_BENCH_MIN_TIME:-60}" \ + --iterations "${OTEL_BENCH_ITERATIONS:-100}" \ + --configs off,api-only,sdk-ratio,sdk-always \ + --dashboard "${OUTPUT_FILE}" +end_time=$(date +%s) +echo "otel benchmark elapsed: $((end_time-start_time))s" +cat "${OUTPUT_DIR}/REPORT.md" diff --git a/driver-benchmarks/build.gradle.kts b/driver-benchmarks/build.gradle.kts index 6387de8d058..7168859e0a2 100644 --- a/driver-benchmarks/build.gradle.kts +++ b/driver-benchmarks/build.gradle.kts @@ -36,8 +36,20 @@ sourceSets { dependencies { api(project(":driver-sync")) + api(project(":driver-reactive-streams")) api(project(":mongodb-crypt")) + // OpenTelemetry overhead suite (com.mongodb.benchmark.benchmarks.otel): the harness, not the driver, + // installs the OpenTelemetry SDK and sampler, as required by the OpenTelemetry spec's Benchmarking section. + implementation(platform(libs.micrometer.observation.bom)) + implementation(libs.micrometer.observation) + implementation(platform(libs.micrometer.tracing.integration.test.bom)) + implementation(libs.micrometer.tracing.bridge.otel) + implementation(platform(libs.opentelemetry.bom)) + implementation(libs.opentelemetry.sdk.trace) + implementation(platform(libs.project.reactor.bom)) + implementation(libs.project.reactor.core) + implementation(platform(libs.netty.bom)) implementation(libs.bundles.netty) @@ -62,6 +74,17 @@ tasks.register("runNetty") { jvmArgs = application.applicationDefaultJvmArgs.toList() } +tasks.register("runOtel") { + group = "benchmark" + description = "Run the OpenTelemetry overhead suite (DRIVERS-3620) for one tracing configuration." + mainClass.set("com.mongodb.benchmark.benchmarks.otel.OtelBenchmarkSuite") + classpath = sourceSets["main"].runtimeClasspath + jvmArgs = application.applicationDefaultJvmArgs.toList() + + (System.getProperty("org.mongodb.benchmarks.jvmArgs")?.split(" ")?.filter { it.isNotBlank() } ?: emptyList()) + systemProperties(System.getProperties().filterKeys { it.toString().startsWith("org.mongodb.benchmarks.") } + .mapKeys { it.key.toString() }) +} + tasks.withType().configureEach { enabled = false } diff --git a/driver-benchmarks/otel-bench.py b/driver-benchmarks/otel-bench.py new file mode 100755 index 00000000000..0ed3ed762c9 --- /dev/null +++ b/driver-benchmarks/otel-bench.py @@ -0,0 +1,206 @@ +#!/usr/bin/env python3 +"""Run the OpenTelemetry overhead benchmark (DRIVERS-3620) for the Java driver. + +Each configuration runs in its own JVM via ``:driver-benchmarks:runOtel``. The whole set of +configurations is run REPS times, interleaved, with the order rotated by one position each +repetition, as the OpenTelemetry spec's Benchmarking section requires. The ``pre-otel`` +configuration runs the same tasks from a worktree checked out at the commit before tracing +support was added (the spec's one-time comparison of the default configuration). + +Usage: + otel-bench.py --data DIR --out DIR [--reps 5] [--pre-otel-worktree PATH] + [--configs off,api-only,sdk-ratio,sdk-always,pre-otel] + [--iterations 100] [--min-time 60] [--report-only] +""" +import argparse +import json +import os +import statistics +import subprocess +import sys +import time +from collections import deque +from pathlib import Path + +ROOT = Path(__file__).resolve().parent.parent +TASKS = [("sync", "Small doc insertOne"), ("sync", "Find one by ID"), + ("async", "Small doc insertOne"), ("async", "Find one by ID")] +ALL = ["off", "api-only", "sdk-ratio", "sdk-always", "pre-otel"] +METRICS = ["megabytes_per_sec", "wall_us_per_op", "cpu_us_per_op", "gc_us_per_op", "cpu_ex_gc_us_per_op"] + + +def run_one(config, rep, args): + out = args.out / f"{config}-rep{rep:02d}.json" + log = out.with_suffix(".log") + if out.exists() and args.resume: + return out + cwd = args.pre_otel_worktree if config == "pre-otel" else ROOT + cmd = ["./gradlew", "-q", ":driver-benchmarks:runOtel", + f"-Dorg.mongodb.benchmarks.data={args.data}/", + f"-Dorg.mongodb.benchmarks.output={out}", + f"-Dorg.mongodb.benchmarks.otel.config={config}", + f"-Dorg.mongodb.benchmarks.otel.iterations={args.iterations}", + f"-Dorg.mongodb.benchmarks.otel.minTimeSeconds={args.min_time}"] + if config == "pre-otel": + cmd += ["-x", ":mongodb-crypt:downloadJava", "-x", ":mongodb-crypt:unzipJava"] + env = {k: v for k, v in os.environ.items() if not k.startswith("OTEL_")} + start = time.monotonic() + with open(log, "w") as fh: + proc = subprocess.run(cmd, cwd=cwd, env=env, stdout=fh, stderr=subprocess.STDOUT) + if proc.returncode != 0: + print(f"FAILED {config} rep {rep}: see {log}", file=sys.stderr) + print(log.read_text()[-3000:], file=sys.stderr) + sys.exit(1) + print(f" {config:<10} rep {rep} done in {time.monotonic() - start:.0f}s", flush=True) + return out + + +def load(args, configs): + samples = {} # (config, api, task) -> metric -> [values] + for f in sorted(args.out.glob("*-rep*.json")): + config = f.name.rsplit("-rep", 1)[0] + if config not in configs: + continue + for r in json.loads(f.read_text())["results"]: + d = samples.setdefault((config, r["api"], r["test_name"]), {m: [] for m in METRICS}) + for m in METRICS: + d[m].append(r[m]) + return samples + + +def med(xs): + return statistics.median(xs) if xs else float("nan") + + +def report(args, configs): + samples = load(args, configs) + reps = max((len(v["megabytes_per_sec"]) for v in samples.values()), default=0) + lines = [f"# Java driver OpenTelemetry overhead (DRIVERS-3620), {reps} repetitions, medians\n"] + lines.append("## Throughput (median MB/s; loss vs `off`)\n") + lines.append("| API | Task | " + " | ".join(c for c in configs) + " |") + lines.append("|---|---|" + "---|" * len(configs)) + for api, task in TASKS: + base = med(samples.get(("off", api, task), {}).get("megabytes_per_sec", [])) + cells = [] + for c in configs: + v = med(samples.get((c, api, task), {}).get("megabytes_per_sec", [])) + if c == "off": + cells.append(f"{v:.3f} (baseline)") + else: + loss = (1 - v / base) * 100 if base == base else float("nan") + cells.append(f"{v:.3f} ({loss:+.1f}%)") + lines.append(f"| {api} | {task} | " + " | ".join(cells) + " |") + lines.append("\nA negative loss means the configuration measured faster than `off`. " + "For `pre-otel` the percentage is the cost of the `off` configuration relative to the pre-tracing commit.\n") + + lines.append("## CPU time per operation, excluding GC (median µs/op; delta vs `off`)\n") + lines.append("| API | Task | " + " | ".join(configs) + " |") + lines.append("|---|---|" + "---|" * len(configs)) + for api, task in TASKS: + base = med(samples.get(("off", api, task), {}).get("cpu_ex_gc_us_per_op", [])) + cells = [] + for c in configs: + v = med(samples.get((c, api, task), {}).get("cpu_ex_gc_us_per_op", [])) + if c == "off": + cells.append(f"{v:.1f} (baseline)") + else: + cells.append(f"{v:.1f} ({v - base:+.1f}, {(v / base - 1) * 100:+.1f}%)") + lines.append(f"| {api} | {task} | " + " | ".join(cells) + " |") + + lines.append("\n## Wall time per operation (median µs/op)\n") + lines.append("| API | Task | " + " | ".join(configs) + " |") + lines.append("|---|---|" + "---|" * len(configs)) + for api, task in TASKS: + cells = [f"{med(samples.get((c, api, task), {}).get('wall_us_per_op', [])):.1f}" for c in configs] + lines.append(f"| {api} | {task} | " + " | ".join(cells) + " |") + + lines.append("\n## Throughput spread across repetitions (min–max MB/s)\n") + lines.append("| API | Task | " + " | ".join(configs) + " |") + lines.append("|---|---|" + "---|" * len(configs)) + for api, task in TASKS: + cells = [] + for c in configs: + xs = samples.get((c, api, task), {}).get("megabytes_per_sec", []) + cells.append(f"{min(xs):.3f}–{max(xs):.3f}" if xs else "n/a") + lines.append(f"| {api} | {task} | " + " | ".join(cells) + " |") + + text = "\n".join(lines) + "\n" + (args.out / "REPORT.md").write_text(text) + summary = {f"{c}/{api}/{task}": {m: {"median": med(v[m]), "values": v[m]} for m in METRICS} + for (c, api, task), v in samples.items()} + (args.out / "summary.json").write_text(json.dumps(summary, indent=2)) + return text + + +def write_dashboard(args, configs, out): + """Evergreen performance-dashboard shape (see EvergreenBenchmarkResultWriter and send-dashboard-data). + + One entry per (configuration, api, task) with the absolute MB/s and CPU/op, plus, for every + non-baseline configuration, the overhead relative to `off` as metrics of their own, which is what + the OpenTelemetry spec asks drivers to record.""" + samples = load(args, configs) + results = [] + for (config, api, task), v in sorted(samples.items()): + name = f"OTel {config} {api} {task}" + metrics = [ + {"name": "megabytes_per_sec", "type": "MEDIAN", "value": med(v["megabytes_per_sec"]), + "metadata": {"improvement_direction": "up", "measurement_unit": "megabytes_per_second"}}, + {"name": "cpu_ex_gc_us_per_op", "type": "MEDIAN", "value": med(v["cpu_ex_gc_us_per_op"]), + "metadata": {"improvement_direction": "down", "measurement_unit": "microseconds_per_op"}}, + ] + base = samples.get(("off", api, task)) + if config != "off" and base: + loss = (1 - med(v["megabytes_per_sec"]) / med(base["megabytes_per_sec"])) * 100 + cpu = med(v["cpu_ex_gc_us_per_op"]) - med(base["cpu_ex_gc_us_per_op"]) + metrics += [ + {"name": "throughput_loss_vs_off_pct", "type": "MEDIAN", "value": loss, + "metadata": {"improvement_direction": "down", "measurement_unit": "percent"}}, + {"name": "added_cpu_us_per_op_vs_off", "type": "MEDIAN", "value": cpu, + "metadata": {"improvement_direction": "down", "measurement_unit": "microseconds_per_op"}}, + ] + results.append({"info": {"test_name": name, "args": {"threads": 1, "configuration": config, "api": api}}, + "metrics": metrics}) + Path(out).write_text(json.dumps(results, indent=2) + "\n") + print(f"dashboard results: {out} ({len(results)} entries)") + + +def main(): + ap = argparse.ArgumentParser(description=__doc__, formatter_class=argparse.RawDescriptionHelpFormatter) + ap.add_argument("--data", type=Path, required=True) + ap.add_argument("--out", type=Path, required=True) + ap.add_argument("--reps", type=int, default=5) + ap.add_argument("--configs", default=",".join(ALL)) + ap.add_argument("--pre-otel-worktree", type=Path) + ap.add_argument("--iterations", type=int, default=100) + ap.add_argument("--min-time", type=int, default=60) + ap.add_argument("--resume", action="store_true", help="skip repetitions whose result file exists") + ap.add_argument("--report-only", action="store_true") + ap.add_argument("--dashboard", type=Path, + help="also write results in the Evergreen performance-dashboard shape to this file") + args = ap.parse_args() + args.data = args.data.resolve() + args.out = args.out.resolve() + args.out.mkdir(parents=True, exist_ok=True) + configs = [c.strip() for c in args.configs.split(",") if c.strip()] + if "off" not in configs: + sys.exit("'off' is required as the baseline") + if "pre-otel" in configs and not args.pre_otel_worktree and not args.report_only: + sys.exit("--pre-otel-worktree is required for the pre-otel configuration") + if not args.report_only: + started = time.monotonic() + for rep in range(1, args.reps + 1): + order = deque(configs) + order.rotate(-(rep - 1)) + print(f"rep {rep}/{args.reps}: order {list(order)}", flush=True) + for c in order: + run_one(c, rep, args) + print(report(args, configs), flush=True) + print(f"total {time.monotonic() - started:.0f}s") + else: + print(report(args, configs)) + if args.dashboard: + write_dashboard(args, configs, args.dashboard) + + +if __name__ == "__main__": + main() diff --git a/driver-benchmarks/otel-compare-langs.py b/driver-benchmarks/otel-compare-langs.py new file mode 100644 index 00000000000..45c68e1817c --- /dev/null +++ b/driver-benchmarks/otel-compare-langs.py @@ -0,0 +1,78 @@ +#!/usr/bin/env python3 +"""Place the Java OTel overhead numbers beside the Python and Ruby figures posted on +mongodb/specifications#1986, on the spec's common metrics: throughput loss vs `off` +and added CPU µs/op vs `off`. Usage: otel-compare-langs.py """ +import json +import sys +from pathlib import Path + +# Published on PR 1986 / linked driver PRs. Python: PR 3102 description (sync, 16-core x86_64, MongoDB 8.0.4, CPython 3.9). +# Ruby: PR 3108 description (Evergreen, Ruby 4.0.1+YJIT), sdk-ratio = "sdk-parent-1pct". +OTHERS = { + "Python (sync)": { + ("Small doc insertOne", "api-only"): (10.2, 25), ("Small doc insertOne", "sdk-ratio"): (19.1, 53), + ("Small doc insertOne", "sdk-always"): (36.0, 130), + ("Find one by ID", "api-only"): (8.0, 24), ("Find one by ID", "sdk-ratio"): (16.3, 56), + ("Find one by ID", "sdk-always"): (31.6, 133), + "pre": {"Small doc insertOne": 1.8, "Find one by ID": 0.8}, + }, + "Python (async)": { + ("Small doc insertOne", "api-only"): (6.1, 26), ("Small doc insertOne", "sdk-ratio"): (11.3, 51), + ("Small doc insertOne", "sdk-always"): (24.4, 131), + ("Find one by ID", "api-only"): (4.5, 22), ("Find one by ID", "sdk-ratio"): (9.6, 50), + ("Find one by ID", "sdk-always"): (21.7, 130), + "pre": {"Small doc insertOne": -0.8, "Find one by ID": 0.6}, + }, + "Ruby": { + ("Small doc insertOne", "api-only"): (2.71, 7.30), ("Small doc insertOne", "sdk-ratio"): (8.06, 20.50), + ("Small doc insertOne", "sdk-always"): (11.22, 29.60), + ("Find one by ID", "api-only"): (5.35, 10.81), ("Find one by ID", "sdk-ratio"): (5.97, 19.36), + ("Find one by ID", "sdk-always"): (7.66, 26.90), + "pre": None, + }, +} + + +def main(results_dir): + summary = json.loads((Path(results_dir) / "summary.json").read_text()) + + def med(cfg, api, task, metric): + return summary[f"{cfg}/{api}/{task}"][metric]["median"] + + java = {} + for api in ("sync", "async"): + d = {} + for task in ("Small doc insertOne", "Find one by ID"): + base_mb = med("off", api, task, "megabytes_per_sec") + base_cpu = med("off", api, task, "cpu_ex_gc_us_per_op") + for cfg in ("api-only", "sdk-ratio", "sdk-always"): + d[(task, cfg)] = ((1 - med(cfg, api, task, "megabytes_per_sec") / base_mb) * 100, + med(cfg, api, task, "cpu_ex_gc_us_per_op") - base_cpu) + key = f"pre-otel/{api}/{task}" + d.setdefault("pre", {}) + if key in summary: + d["pre"][task] = (1 - base_mb / summary[key]["megabytes_per_sec"]["median"]) * 100 + java[f"Java ({api})"] = d + + langs = {**java, **OTHERS} + out = ["## Cross-language comparison (throughput loss vs `off` / added CPU µs per op vs `off`)\n"] + for task in ("Small doc insertOne", "Find one by ID"): + out.append(f"### {task}\n") + out.append("| Driver | api-only | sdk-ratio (1%) | sdk-always | `off` vs pre-OTel commit |") + out.append("|---|---|---|---|---|") + for name, d in langs.items(): + cells = [f"{d[(task, c)][0]:+.1f}% / +{d[(task, c)][1]:.0f} µs" for c in ("api-only", "sdk-ratio", "sdk-always")] + pre = d.get("pre") + cells.append(f"{pre[task]:+.1f}%" if pre and task in pre else "n/a") + out.append(f"| {name} | " + " | ".join(cells) + " |") + out.append("") + out.append("Java CPU is process CPU time excluding GC; Python is process CPU time; Ruby is CPU excluding GC. " + "Hosts differ (Java: Apple M4 Max, MongoDB 8.2.6, Temurin 17; Python: 16-core x86_64, MongoDB 8.0.4; " + "Ruby: Evergreen), so compare relative overhead, not absolute µs.") + text = "\n".join(out) + "\n" + (Path(results_dir) / "CROSS_LANGUAGE.md").write_text(text) + print(text) + + +if __name__ == "__main__": + main(sys.argv[1]) diff --git a/driver-benchmarks/otel-compare-runs.py b/driver-benchmarks/otel-compare-runs.py new file mode 100755 index 00000000000..0f040457bf9 --- /dev/null +++ b/driver-benchmarks/otel-compare-runs.py @@ -0,0 +1,64 @@ +#!/usr/bin/env python3 +"""Compare two otel-bench.py result directories (before/after an optimisation). +Usage: otel-compare-runs.py []""" +import json +import sys +from pathlib import Path + +TASKS = [("sync", "Small doc insertOne"), ("sync", "Find one by ID"), + ("async", "Small doc insertOne"), ("async", "Find one by ID")] +CONFIGS = ["off", "api-only", "sdk-ratio", "sdk-always"] + + +def load(d): + return json.loads((Path(d) / "summary.json").read_text()) + + +def med(s, cfg, api, task, metric): + return s[f"{cfg}/{api}/{task}"][metric]["median"] + + +def main(before, after, out=None): + b, a = load(before), load(after) + lines = ["# Java OTel overhead: before vs after optimisation\n", + f"Before: `{before}` After: `{after}`. Medians of 5 repetitions each. " + "Loss = throughput lost vs that run's own `off`; CPU = process CPU per op excluding GC.\n"] + lines.append("## Overhead vs `off` (loss % / added CPU µs per op)\n") + lines.append("| API | Task | Config | Before | After | Δ loss (pts) | Δ CPU (µs) |") + lines.append("|---|---|---|---|---|---|---|") + for api, task in TASKS: + bb_mb, ab_mb = med(b, "off", api, task, "megabytes_per_sec"), med(a, "off", api, task, "megabytes_per_sec") + bb_cpu, ab_cpu = med(b, "off", api, task, "cpu_ex_gc_us_per_op"), med(a, "off", api, task, "cpu_ex_gc_us_per_op") + for cfg in CONFIGS[1:]: + bl = (1 - med(b, cfg, api, task, "megabytes_per_sec") / bb_mb) * 100 + al = (1 - med(a, cfg, api, task, "megabytes_per_sec") / ab_mb) * 100 + bc = med(b, cfg, api, task, "cpu_ex_gc_us_per_op") - bb_cpu + ac = med(a, cfg, api, task, "cpu_ex_gc_us_per_op") - ab_cpu + lines.append(f"| {api} | {task} | {cfg} | {bl:+.1f}% / +{bc:.1f} | {al:+.1f}% / +{ac:.1f} | {al - bl:+.1f} | {ac - bc:+.1f} |") + lines.append("\n## Absolute medians (MB/s, CPU ex-GC µs/op)\n") + lines.append("| API | Task | Config | Before MB/s | After MB/s | Before CPU | After CPU |") + lines.append("|---|---|---|---|---|---|---|") + for api, task in TASKS: + for cfg in CONFIGS: + lines.append(f"| {api} | {task} | {cfg} | {med(b, cfg, api, task, 'megabytes_per_sec'):.3f} | " + f"{med(a, cfg, api, task, 'megabytes_per_sec'):.3f} | " + f"{med(b, cfg, api, task, 'cpu_ex_gc_us_per_op'):.1f} | {med(a, cfg, api, task, 'cpu_ex_gc_us_per_op'):.1f} |") + lines.append("\n## sdk-ratio vs sdk-always gap (the spec's gating diagnostic)\n") + lines.append("| API | Task | Before gap (pts loss / µs CPU) | After gap |") + lines.append("|---|---|---|---|") + for api, task in TASKS: + def gap(s): + off = med(s, "off", api, task, "megabytes_per_sec") + r = (1 - med(s, "sdk-ratio", api, task, "megabytes_per_sec") / off) * 100 + al = (1 - med(s, "sdk-always", api, task, "megabytes_per_sec") / off) * 100 + c = med(s, "sdk-always", api, task, "cpu_ex_gc_us_per_op") - med(s, "sdk-ratio", api, task, "cpu_ex_gc_us_per_op") + return f"{al - r:+.1f} / {c:+.1f}" + lines.append(f"| {api} | {task} | {gap(b)} | {gap(a)} |") + text = "\n".join(lines) + "\n" + if out: + Path(out).write_text(text) + print(text) + + +if __name__ == "__main__": + main(*sys.argv[1:]) diff --git a/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/InstrumentedBenchmarkRunner.java b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/InstrumentedBenchmarkRunner.java new file mode 100644 index 00000000000..88f6e1b47d2 --- /dev/null +++ b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/InstrumentedBenchmarkRunner.java @@ -0,0 +1,137 @@ +/* + * Copyright 2008-present MongoDB, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.mongodb.benchmark.benchmarks.otel; + +import com.mongodb.benchmark.framework.Benchmark; +import org.bson.Document; + +import java.lang.management.GarbageCollectorMXBean; +import java.lang.management.ManagementFactory; +import java.util.ArrayList; +import java.util.Collections; +import java.util.List; +import java.util.concurrent.TimeUnit; + +/** + * A {@link com.mongodb.benchmark.framework.BenchmarkRunner} variant that records, for every timed iteration, + * the process CPU time and the time spent in garbage collection alongside the wall-clock time. + *

+ * CPU time excludes time spent waiting on the server, so it exposes driver-side cost with far less noise + * than throughput. Process CPU time includes the driver's background threads (server monitoring), which cost + * the same in every tracing configuration. GC time varies between processes more than the cost of tracing + * does, so CPU time excluding GC is the steadier measure of the driver's own work. + */ +final class InstrumentedBenchmarkRunner { + private final Benchmark benchmark; + private final int opsPerIteration; + private final int numWarmupIterations; + private final int numIterations; + private final int minTimeSeconds; + private final int maxTimeSeconds; + + private final com.sun.management.OperatingSystemMXBean os = + (com.sun.management.OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean(); + private final List gcBeans = ManagementFactory.getGarbageCollectorMXBeans(); + + InstrumentedBenchmarkRunner(final Benchmark benchmark, final int opsPerIteration, final int numWarmupIterations, + final int numIterations, final int minTimeSeconds, final int maxTimeSeconds) { + this.benchmark = benchmark; + this.opsPerIteration = opsPerIteration; + this.numWarmupIterations = numWarmupIterations; + this.numIterations = numIterations; + this.minTimeSeconds = minTimeSeconds; + this.maxTimeSeconds = maxTimeSeconds; + } + + Document run() throws Exception { + benchmark.setUp(); + for (int i = 0; i < numWarmupIterations; i++) { + benchmark.before(); + benchmark.run(); + benchmark.after(); + } + + List wallNanos = new ArrayList<>(); + List cpuNanos = new ArrayList<>(); + List gcNanos = new ArrayList<>(); + long totalNanos = 0; + for (int i = 0; shouldContinue(i, totalNanos); i++) { + benchmark.before(); + long gcStart = gcTimeNanos(); + long cpuStart = os.getProcessCpuTime(); + long start = System.nanoTime(); + benchmark.run(); + long wall = System.nanoTime() - start; + long cpu = os.getProcessCpuTime() - cpuStart; + long gc = gcTimeNanos() - gcStart; + benchmark.after(); + wallNanos.add(wall); + cpuNanos.add(cpu); + gcNanos.add(gc); + totalNanos += wall; + } + benchmark.tearDown(); + + List cpuExGc = new ArrayList<>(cpuNanos.size()); + for (int i = 0; i < cpuNanos.size(); i++) { + cpuExGc.add(cpuNanos.get(i) - gcNanos.get(i)); + } + double medianWallNanos = median(wallNanos); + return new Document("test_name", benchmark.getName()) + .append("iterations", wallNanos.size()) + .append("ops_per_iteration", opsPerIteration) + .append("bytes_per_iteration", benchmark.getBytesPerRun()) + .append("megabytes_per_sec", (benchmark.getBytesPerRun() / 1_000_000d) / (medianWallNanos / 1_000_000_000d)) + .append("wall_us_per_op", medianWallNanos / opsPerIteration / 1_000d) + .append("cpu_us_per_op", median(cpuNanos) / opsPerIteration / 1_000d) + .append("gc_us_per_op", median(gcNanos) / opsPerIteration / 1_000d) + .append("cpu_ex_gc_us_per_op", median(cpuExGc) / opsPerIteration / 1_000d) + .append("wall_nanos", wallNanos); + } + + private long gcTimeNanos() { + long millis = 0; + for (GarbageCollectorMXBean bean : gcBeans) { + long t = bean.getCollectionTime(); + if (t > 0) { + millis += t; + } + } + return TimeUnit.MILLISECONDS.toNanos(millis); + } + + private boolean shouldContinue(final int iterationCount, final long totalNanos) { + if (totalNanos < TimeUnit.SECONDS.toNanos(minTimeSeconds)) { + return true; + } + if (totalNanos > TimeUnit.SECONDS.toNanos(maxTimeSeconds)) { + return false; + } + return iterationCount < numIterations; + } + + /** Median, averaging the middle two of an even-sized sample (unlike the spec's nearest-rank percentile). */ + static double median(final List values) { + List sorted = new ArrayList<>(values); + Collections.sort(sorted); + int n = sorted.size(); + if (n == 0) { + return Double.NaN; + } + return n % 2 == 1 ? sorted.get(n / 2) : (sorted.get(n / 2 - 1) + sorted.get(n / 2)) / 2d; + } +} diff --git a/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/OtelBenchmarkSuite.java b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/OtelBenchmarkSuite.java new file mode 100644 index 00000000000..53178a2ac68 --- /dev/null +++ b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/OtelBenchmarkSuite.java @@ -0,0 +1,199 @@ +/* + * Copyright 2008-present MongoDB, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.mongodb.benchmark.benchmarks.otel; + +import com.mongodb.MongoClientSettings; +import com.mongodb.benchmark.benchmarks.FindOneBenchmark; +import com.mongodb.benchmark.benchmarks.InsertOneBenchmark; +import com.mongodb.benchmark.framework.Benchmark; +import com.mongodb.observability.micrometer.MicrometerObservabilitySettings; +import io.micrometer.observation.ObservationRegistry; +import io.micrometer.tracing.handler.DefaultTracingObservationHandler; +import io.micrometer.tracing.otel.bridge.OtelCurrentTraceContext; +import io.micrometer.tracing.otel.bridge.OtelTracer; +import io.opentelemetry.context.Context; +import io.opentelemetry.sdk.trace.ReadWriteSpan; +import io.opentelemetry.sdk.trace.ReadableSpan; +import io.opentelemetry.sdk.trace.SdkTracerProvider; +import io.opentelemetry.sdk.trace.SdkTracerProviderBuilder; +import io.opentelemetry.sdk.trace.SpanProcessor; +import io.opentelemetry.sdk.trace.samplers.Sampler; +import org.bson.Document; +import org.bson.json.JsonWriterSettings; + +import java.io.FileOutputStream; +import java.io.OutputStreamWriter; +import java.io.Writer; +import java.nio.charset.StandardCharsets; +import java.util.ArrayList; +import java.util.List; +import java.util.Locale; +import java.util.concurrent.atomic.AtomicLong; + +/** + * Runs the OpenTelemetry overhead benchmark required by the OpenTelemetry specification's + * "Performance Implications" section (DRIVERS-3620) for one tracing configuration, in this process. + *

+ * The configuration is taken from the {@code org.mongodb.benchmarks.otel.config} system property: + *

    + *
  • {@code off}: no {@code ObservabilitySettings}; the baseline.
    • + *
  • {@code api-only}: a {@code MicrometerObservabilitySettings} with an {@code ObservationRegistry} + * that has no handlers. Micrometer reports such a registry as no-op, so every observation the driver + * starts is a no-op, which is the closest analogue of "tracing enabled, no SDK" available to a + * Micrometer-based driver.
    • + *
  • {@code sdk-ratio}: the registry has a {@code DefaultTracingObservationHandler} bridged to an + * OpenTelemetry {@code SdkTracerProvider} with a {@code traceIdRatioBased(0.01)} sampler.
    • + *
  • {@code sdk-always}: same, with {@code alwaysOn()}.
    • + *
+ * No exporter or span processor is installed for the SDK configurations. The tasks are the spec's + * "Small doc insertOne" and "Find one by ID", through the synchronous and the Reactive Streams API. + * Results are written as a JSON array to {@code org.mongodb.benchmarks.output}. + */ +public final class OtelBenchmarkSuite { + private static final String CONFIG_PROPERTY = "org.mongodb.benchmarks.otel.config"; + private static final String OUTPUT_PROPERTY = "org.mongodb.benchmarks.output"; + private static final String TASKS_PROPERTY = "org.mongodb.benchmarks.otel.tasks"; + private static final String MIN_TIME_PROPERTY = "org.mongodb.benchmarks.otel.minTimeSeconds"; + private static final String ITERATIONS_PROPERTY = "org.mongodb.benchmarks.otel.iterations"; + /** When true, installs a counting span processor and reports spans per operation; never set for timed runs. */ + private static final String VERIFY_PROPERTY = "org.mongodb.benchmarks.otel.verify"; + + private static final AtomicLong STARTED_SPANS = new AtomicLong(); + private static final AtomicLong SAMPLED_SPANS = new AtomicLong(); + + private static final int NUM_WARMUP_ITERATIONS = 1; + private static final int MAX_TIME_SECONDS = 300; + private static final int OPS_PER_ITERATION = 10_000; + + private OtelBenchmarkSuite() { + } + + public static void main(final String[] args) throws Exception { + String config = System.getProperty(CONFIG_PROPERTY, "off"); + int iterations = Integer.getInteger(ITERATIONS_PROPERTY, 100); + int minTimeSeconds = Integer.getInteger(MIN_TIME_PROPERTY, 60); + String tasks = System.getProperty(TASKS_PROPERTY, "sync-insert,sync-find,async-insert,async-find"); + + MongoClientSettings settings = settingsFor(config); + List results = new ArrayList<>(); + for (String task : tasks.split(",")) { + Benchmark benchmark = benchmarkFor(task.trim(), settings); + long start = System.currentTimeMillis(); + Document result = new InstrumentedBenchmarkRunner(benchmark, OPS_PER_ITERATION, NUM_WARMUP_ITERATIONS, + iterations, minTimeSeconds, MAX_TIME_SECONDS).run(); + result.append("api", task.startsWith("async") ? "async" : "sync").append("configuration", config); + if (Boolean.getBoolean(VERIFY_PROPERTY)) { + // The counters also see the warm-up iteration. + long ops = (long) OPS_PER_ITERATION * (result.getInteger("iterations") + NUM_WARMUP_ITERATIONS); + result.append("spans_started_per_op", STARTED_SPANS.getAndSet(0) / (double) ops) + .append("spans_sampled_per_op", SAMPLED_SPANS.getAndSet(0) / (double) ops); + } + results.add(result); + System.out.println(String.format(Locale.ROOT, "%-10s %-6s %-22s %7.3f MB/s cpu %6.1f us/op (%.0fs)%s", + config, result.getString("api"), result.getString("test_name"), + result.getDouble("megabytes_per_sec"), result.getDouble("cpu_us_per_op"), + (System.currentTimeMillis() - start) / 1000d, + result.containsKey("spans_started_per_op") + ? String.format(Locale.ROOT, " spans/op started %.2f sampled %.2f", + result.getDouble("spans_started_per_op"), result.getDouble("spans_sampled_per_op")) + : "")); + } + try (Writer writer = new OutputStreamWriter(new FileOutputStream(System.getProperty(OUTPUT_PROPERTY)), + StandardCharsets.UTF_8)) { + writer.write(new Document("results", results).toJson(JsonWriterSettings.builder().indent(true).build())); + } + } + + static Benchmark benchmarkFor(final String task, final MongoClientSettings settings) { + switch (task) { + case "sync-insert": + return new InsertOneBenchmark<>("Small", "./single_and_multi_document/small_doc.json", OPS_PER_ITERATION, + Document.class, document -> document.remove("_id")).applyMongoClientSettings(settings); + case "sync-find": + return new FindOneBenchmark<>("single_and_multi_document/tweet.json", Document.class) + .applyMongoClientSettings(settings); + case "async-insert": + return new ReactiveInsertOneBenchmark("Small", "./single_and_multi_document/small_doc.json", + OPS_PER_ITERATION, settings); + case "async-find": + return new ReactiveFindOneBenchmark("single_and_multi_document/tweet.json", settings); + default: + throw new IllegalArgumentException("Unknown task: " + task); + } + } + + static MongoClientSettings settingsFor(final String config) { + MongoClientSettings.Builder builder = MongoClientSettings.builder(); + switch (config) { + case "off": + break; + case "api-only": + builder.observabilitySettings(MicrometerObservabilitySettings.builder() + .observationRegistry(ObservationRegistry.create()) + .build()); + break; + case "sdk-ratio": + builder.observabilitySettings(sdkSettings(Sampler.traceIdRatioBased(0.01))); + break; + case "sdk-always": + builder.observabilitySettings(sdkSettings(Sampler.alwaysOn())); + break; + default: + throw new IllegalArgumentException("Unknown configuration: " + config); + } + return builder.build(); + } + + private static MicrometerObservabilitySettings sdkSettings(final Sampler sampler) { + // The harness installs the SDK and sampler; no exporter and no span processor (spec: Benchmarking). + SdkTracerProviderBuilder providerBuilder = SdkTracerProvider.builder().setSampler(sampler); + if (Boolean.getBoolean(VERIFY_PROPERTY)) { + providerBuilder.addSpanProcessor(new CountingSpanProcessor()); + } + SdkTracerProvider tracerProvider = providerBuilder.build(); + OtelTracer tracer = new OtelTracer(tracerProvider.get("mongodb-driver-benchmark"), + new OtelCurrentTraceContext(), event -> { }); + ObservationRegistry registry = ObservationRegistry.create(); + registry.observationConfig().observationHandler(new DefaultTracingObservationHandler(tracer)); + return MicrometerObservabilitySettings.builder().observationRegistry(registry).build(); + } + + /** Counts spans the SDK starts; only installed in verify mode, so the span count excludes sampler-dropped spans. */ + private static final class CountingSpanProcessor implements SpanProcessor { + @Override + public void onStart(final Context parentContext, final ReadWriteSpan span) { + STARTED_SPANS.incrementAndGet(); + if (span.getSpanContext().isSampled()) { + SAMPLED_SPANS.incrementAndGet(); + } + } + + @Override + public boolean isStartRequired() { + return true; + } + + @Override + public void onEnd(final ReadableSpan span) { + } + + @Override + public boolean isEndRequired() { + return false; + } + } +} diff --git a/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/ReactiveFindOneBenchmark.java b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/ReactiveFindOneBenchmark.java new file mode 100644 index 00000000000..d2c13d27bac --- /dev/null +++ b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/ReactiveFindOneBenchmark.java @@ -0,0 +1,89 @@ +/* + * Copyright 2008-present MongoDB, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.mongodb.benchmark.benchmarks.otel; + +import com.mongodb.MongoClientSettings; +import com.mongodb.benchmark.framework.Benchmark; +import com.mongodb.reactivestreams.client.MongoClient; +import com.mongodb.reactivestreams.client.MongoClients; +import com.mongodb.reactivestreams.client.MongoCollection; +import org.bson.BsonDocument; +import org.bson.BsonInt32; +import org.bson.Document; +import org.bson.codecs.DecoderContext; +import org.bson.codecs.DocumentCodec; +import org.bson.json.JsonReader; +import reactor.core.publisher.Mono; + +import java.nio.charset.StandardCharsets; +import java.util.ArrayList; +import java.util.List; + +/** + * DriverBench "Find one by ID" through the Reactive Streams API, one blocking subscription per operation. + */ +public class ReactiveFindOneBenchmark extends Benchmark { + private static final String DATABASE_NAME = "perftest"; + private static final String COLLECTION_NAME = "corpus"; + + private final String resourcePath; + private final MongoClientSettings settings; + private MongoClient client; + private MongoCollection collection; + private int fileLength; + + public ReactiveFindOneBenchmark(final String resourcePath, final MongoClientSettings settings) { + super("Find one by ID"); + this.resourcePath = resourcePath; + this.settings = settings; + } + + @Override + public void setUp() throws Exception { + client = MongoClients.create(settings); + collection = client.getDatabase(DATABASE_NAME).getCollection(COLLECTION_NAME); + byte[] bytes = readAllBytesFromRelativePath(resourcePath); + fileLength = bytes.length; + Mono.from(client.getDatabase(DATABASE_NAME).drop()).block(); + Document document = new DocumentCodec().decode(new JsonReader(new String(bytes, StandardCharsets.UTF_8)), + DecoderContext.builder().build()); + List documents = new ArrayList<>(NUM_INTERNAL_ITERATIONS); + for (int i = 0; i < NUM_INTERNAL_ITERATIONS; i++) { + Document copy = new Document(document); + copy.put("_id", i); + documents.add(copy); + } + Mono.from(collection.insertMany(documents)).block(); + } + + @Override + public void run() { + for (int i = 0; i < NUM_INTERNAL_ITERATIONS; i++) { + Mono.from(collection.find(new BsonDocument("_id", new BsonInt32(i))).first()).block(); + } + } + + @Override + public void tearDown() { + client.close(); + } + + @Override + public int getBytesPerRun() { + return fileLength * NUM_INTERNAL_ITERATIONS; + } +} diff --git a/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/ReactiveInsertOneBenchmark.java b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/ReactiveInsertOneBenchmark.java new file mode 100644 index 00000000000..566a7411881 --- /dev/null +++ b/driver-benchmarks/src/main/com/mongodb/benchmark/benchmarks/otel/ReactiveInsertOneBenchmark.java @@ -0,0 +1,88 @@ +/* + * Copyright 2008-present MongoDB, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.mongodb.benchmark.benchmarks.otel; + +import com.mongodb.MongoClientSettings; +import com.mongodb.benchmark.framework.Benchmark; +import com.mongodb.reactivestreams.client.MongoClient; +import com.mongodb.reactivestreams.client.MongoClients; +import com.mongodb.reactivestreams.client.MongoCollection; +import org.bson.Document; +import org.bson.codecs.DecoderContext; +import org.bson.codecs.DocumentCodec; +import org.bson.json.JsonReader; +import reactor.core.publisher.Mono; + +import java.nio.charset.StandardCharsets; + +/** + * DriverBench "Small doc insertOne" through the Reactive Streams API, one blocking subscription per operation. + */ +public class ReactiveInsertOneBenchmark extends Benchmark { + private static final String DATABASE_NAME = "perftest"; + private static final String COLLECTION_NAME = "corpus"; + + private final String resourcePath; + private final int numIterations; + private final MongoClientSettings settings; + private MongoClient client; + private MongoCollection collection; + private Document document; + private int fileLength; + + public ReactiveInsertOneBenchmark(final String name, final String resourcePath, final int numIterations, + final MongoClientSettings settings) { + super(name + " doc insertOne"); + this.resourcePath = resourcePath; + this.numIterations = numIterations; + this.settings = settings; + } + + @Override + public void setUp() throws Exception { + client = MongoClients.create(settings); + collection = client.getDatabase(DATABASE_NAME).getCollection(COLLECTION_NAME); + byte[] bytes = readAllBytesFromRelativePath(resourcePath); + fileLength = bytes.length; + document = new DocumentCodec().decode(new JsonReader(new String(bytes, StandardCharsets.UTF_8)), + DecoderContext.builder().build()); + Mono.from(client.getDatabase(DATABASE_NAME).drop()).block(); + } + + @Override + public void before() { + Mono.from(collection.drop()).block(); + } + + @Override + public void run() { + for (int i = 0; i < numIterations; i++) { + document.remove("_id"); + Mono.from(collection.insertOne(document)).block(); + } + } + + @Override + public void tearDown() { + client.close(); + } + + @Override + public int getBytesPerRun() { + return fileLength * numIterations; + } +} diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 7686cc15c41..011d07624fd 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -26,6 +26,7 @@ zstd = "1.5.5-3" jetbrains-annotations = "26.0.2" micrometer-tracing = "1.6.0-M3" # This version has a fix for https://github.com/micrometer-metrics/tracing/issues/1092 micrometer-observation-bom = "1.15.4" +opentelemetry-bom = "1.53.0" # benchmark-only: OpenTelemetry SDK for the driver-benchmarks OTel overhead suite kotlin = "1.8.10" kotlinx-coroutines-bom = "1.6.4" @@ -188,6 +189,9 @@ reflections = { module = "org.reflections:reflections", version.ref = "reflectio micrometer-tracing-integration-test-bom = { module = " io.micrometer:micrometer-tracing-bom", version.ref = "micrometer-tracing" } micrometer-tracing-integration-test = { module = " io.micrometer:micrometer-tracing-integration-test" } +micrometer-tracing-bridge-otel = { module = "io.micrometer:micrometer-tracing-bridge-otel" } +opentelemetry-bom = { module = "io.opentelemetry:opentelemetry-bom", version.ref = "opentelemetry-bom" } +opentelemetry-sdk-trace = { module = "io.opentelemetry:opentelemetry-sdk-trace" } [bundles] aws-java-sdk-v1 = ["aws-java-sdk-v1-core", "aws-java-sdk-v1-sts"]