Skip to content

Commit 80443ce

Browse files
authored
Merge pull request #397 from lensesio-dev/fix/perf-gcs-http-sink
Fix/perf gcs http sink
2 parents 8f8db67 + 7fd3b55 commit 80443ce

32 files changed

Lines changed: 3612 additions & 769 deletions

File tree

benchmarks/EXECUTIVE_SUMMARY.md

Lines changed: 135 additions & 0 deletions
Large diffs are not rendered by default.

benchmarks/README.md

Lines changed: 56 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,56 @@
1+
# Sink throughput benchmark: HTTP sink vs GCS sink
2+
3+
Local, network-free, Kafka-free comparison of the HTTP sink and GCS sink connectors'
4+
in-process pipelines. Built to answer a specific customer question: at the same input rate,
5+
why is the HTTP sink slower and more CPU/memory-hungry than the GCS sink, and why did raising
6+
`connect.http.batch.count` (previously recommended) not fix it?
7+
8+
This module is **deliberately excluded** from the root aggregate and from `fullTest`/CI: it is
9+
a local investigation tool, not a shipped connector or a correctness test suite.
10+
11+
**For methodology, results, and the objective conclusion, see
12+
[`EXECUTIVE_SUMMARY.md`](EXECUTIVE_SUMMARY.md).** This README only covers what the module is and
13+
how to run it.
14+
15+
## What "network removed" and "Kafka removed" mean here
16+
17+
- **Kafka removed**: both harnesses hand `SinkRecord`s directly to the real `put()` code path
18+
(`HttpSinkTask`'s render+enqueue logic for HTTP; the real `GCPStorageSinkTask.put()` for GCS).
19+
No consumer, broker, or serialization-over-the-wire is involved.
20+
- **Network removed**: the only thing swapped out in each sink is the bottom-most egress seam:
21+
- HTTP: the `org.http4s.client.Client[IO]` used by `HttpRequestSender` is replaced with a stub
22+
that returns `200 OK` instantly, or after a configurable simulated latency.
23+
- GCS: `GCPStorageSinkTask.createStorageInterface` is overridden to return
24+
[`NoOpGCPStorage`](src/test/scala/io/lenses/streamreactor/connect/benchmarks/gcs/NoOpGCPStorage.scala),
25+
which succeeds instantly (or after a configurable simulated latency) and never touches disk
26+
bytes or the network.
27+
28+
Everything above those seams (template rendering, the per-topic `RecordsQueue` and batch policy
29+
evaluation, `HttpSinkMetrics`, `WriterManager`, `IndexManagerV2`, and `JsonFormatWriter`'s
30+
per-record JSON serialisation) is unmodified production code, wrapped by the same decorators
31+
(`Retry`, `RetryingStorageInterface`, `StorageInterfaceWithMetrics`) production uses.
32+
33+
See the scaladoc on
34+
[`HttpSinkThroughputHarness`](src/test/scala/io/lenses/streamreactor/connect/benchmarks/http/HttpSinkThroughputHarness.scala)
35+
and
36+
[`GcsSinkThroughputHarness`](src/test/scala/io/lenses/streamreactor/connect/benchmarks/gcs/GcsSinkThroughputHarness.scala)
37+
for the exact seams, and `EXECUTIVE_SUMMARY.md` for the full methodology (warm-up, iteration
38+
counts, logging suppression, and why).
39+
40+
## Running it
41+
42+
```bash
43+
sbt "project benchmarks" "testOnly *SinkThroughputComparisonTest"
44+
```
45+
46+
This runs four scenarios (pure CPU ceiling at 0ms; egress latency sweep at 100/400/900ms, which
47+
includes a GCS `exactly.once.enable` on/off contrast; record size at 0ms; and a logging-cost
48+
delta) and prints two plain-text tables at the end: measured results (median of several
49+
iterations per scenario) and a GCS-vs-HTTP deviation table. The results table reports both `Ops`
50+
(every latency-charged storage call) and `Flushes` (uploaded data files) so GCS's per-round-trip
51+
amortisation is shown honestly. Expect it to take a few minutes -- most of that time is the
52+
benchmark itself doing real work, not sbt overhead.
53+
54+
To reproduce or extend the analysis, edit
55+
[`SinkThroughputComparisonTest`](src/test/scala/io/lenses/streamreactor/connect/benchmarks/SinkThroughputComparisonTest.scala)
56+
directly; it is the single entry point for all scenarios.
Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,43 @@
1+
<?xml version="1.0" encoding="UTF-8"?>
2+
3+
<!-- -->
4+
<!-- Copyright 2017-2026 Lenses.io Ltd -->
5+
<!-- -->
6+
<!-- Licensed under the Apache License, Version 2.0 (the "License"); -->
7+
<!-- you may not use this file except in compliance with the License. -->
8+
<!-- You may obtain a copy of the License at -->
9+
<!-- -->
10+
<!-- http://www.apache.org/licenses/LICENSE-2.0 -->
11+
<!-- -->
12+
<!-- Unless required by applicable law or agreed to in writing, software -->
13+
<!-- distributed under the License is distributed on an "AS IS" BASIS, -->
14+
<!-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.-->
15+
<!-- See the License for the specific language governing permissions and -->
16+
<!-- limitations under the License. -->
17+
<!-- -->
18+
<!--
19+
Root logger is WARN so that the throughput benchmarks measure compute, not
20+
logging I/O. `BatchPolicy` (HTTP sink batching) and `CommitPolicy` (cloud sink
21+
flush policy) log a line for every record considered while forming a
22+
batch/evaluating a flush; at INFO that logging is charged to the timed section
23+
of a benchmark run and would otherwise dominate the measurement, particularly
24+
for larger batch sizes. `SinkThroughputComparisonTest`'s logging-cost scenario
25+
raises `BatchPolicy` back to INFO temporarily (via `LoggerFactory` + logback's
26+
`Logger.setLevel`) to measure that cost directly as a named line item - see
27+
that test and benchmarks/EXECUTIVE_SUMMARY.md.
28+
-->
29+
<configuration>
30+
<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
31+
<encoder>
32+
<pattern>%d{ISO8601} %-5p [%t] [%c] [%M:%L] %m%n</pattern>
33+
</encoder>
34+
</appender>
35+
<!-- Trailing "$" required: these are Scala `object`s, and logback's logger hierarchy is
36+
dot-separated, so "BatchPolicy" (no "$") is a distinct, unrelated logger name from
37+
"BatchPolicy$" (the module's actual runtime logger name); it would silently not match. -->
38+
<logger name="io.lenses.streamreactor.common.batch.BatchPolicy$" level="WARN"/>
39+
<logger name="io.lenses.streamreactor.connect.cloud.common.sink.commit.CommitPolicy$" level="WARN"/>
40+
<root level="WARN">
41+
<appender-ref ref="stdout"/>
42+
</root>
43+
</configuration>
Lines changed: 177 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,177 @@
1+
/*
2+
* Copyright 2017-2026 Lenses.io Ltd
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
package io.lenses.streamreactor.connect.benchmarks
17+
18+
/**
19+
* Outcome of a single throughput run (one sink, one iteration of one scenario).
20+
*
21+
* @param sink label identifying which sink/config this run measured, e.g. "HTTP" or "GCS".
22+
* @param scenario short human-readable description of the sweep point, e.g. "latency=400ms".
23+
* @param records total number of records successfully drained.
24+
* @param elapsedNanos wall-clock time from the first `put()` call to full drain (all records
25+
* acknowledged/committed).
26+
* @param networkOps number of latency-charged network round-trips performed. For HTTP this
27+
* is the number of HTTP requests; for GCS this is every latency-charged
28+
* storage call (upload + temp-file move/delete + index/lock bookkeeping),
29+
* NOT just the upload count -- see [[flushes]].
30+
* @param flushes number of flushes/uploaded files. For HTTP this equals [[networkOps]]
31+
* (one request per batch). For GCS this is the `uploadFile` count (one
32+
* data file per flush), which with exactly-once enabled is far smaller
33+
* than [[networkOps]] because the commit chain makes several extra
34+
* latency-charged calls per flush.
35+
* @param heapUsedDeltaBytes approximate heap growth attributable to the run (best-effort; see
36+
* [[HeapSampler]]).
37+
*/
38+
final case class BenchResult(
39+
sink: String,
40+
scenario: String,
41+
records: Long,
42+
elapsedNanos: Long,
43+
networkOps: Long,
44+
flushes: Long,
45+
heapUsedDeltaBytes: Long,
46+
) {
47+
def elapsedMillis: Double = elapsedNanos / 1e6
48+
49+
def recordsPerSec: Double = if (elapsedNanos <= 0) 0.0 else records * 1e9 / elapsedNanos.toDouble
50+
51+
/** Records per latency-charged network round-trip -- the fair, apples-to-apples amortisation. */
52+
def avgRecordsPerOp: Double = if (networkOps <= 0) 0.0 else records.toDouble / networkOps.toDouble
53+
54+
def avgOpLatencyMillis: Double = if (networkOps <= 0) 0.0 else elapsedMillis / networkOps.toDouble
55+
}
56+
57+
/**
58+
* A scenario point measured across `iterations` repeats (after any discarded warm-up runs),
59+
* summarised as median/min/max `recordsPerSec` to absorb JIT warm-up and GC noise from a single
60+
* shared JVM process. Non-timing columns (records, ops, rec/op) are deterministic given fixed
61+
* inputs, so `sample` (the last measured iteration) is used to report those directly rather than
62+
* aggregating them.
63+
*
64+
* @param family groups scenario points that should be compared against each other across sinks,
65+
* e.g. "cpu-ceiling", "latency=400ms", "size=2048B". Used by
66+
* [[ResultsTablePrinter.printDeviation]] to line up the GCS and HTTP rows for the
67+
* same sweep point.
68+
* @param variant distinguishes multiple configurations run within the same sink/family, e.g.
69+
* "http batch=1500" vs "http batch=10000".
70+
*/
71+
final case class AggregatedResult(
72+
sink: String,
73+
family: String,
74+
variant: String,
75+
iterations: Int,
76+
medianRecordsPerSec: Double,
77+
minRecordsPerSec: Double,
78+
maxRecordsPerSec: Double,
79+
sample: BenchResult,
80+
)
81+
82+
object BenchAggregator {
83+
84+
/** `runs` must be non-empty measured iterations (warm-up iterations must already be excluded). */
85+
def aggregate(sink: String, family: String, variant: String, runs: Seq[BenchResult]): AggregatedResult = {
86+
require(runs.nonEmpty, "aggregate() requires at least one measured iteration")
87+
val sortedRates = runs.map(_.recordsPerSec).sorted
88+
AggregatedResult(
89+
sink = sink,
90+
family = family,
91+
variant = variant,
92+
iterations = runs.size,
93+
medianRecordsPerSec = median(sortedRates),
94+
minRecordsPerSec = sortedRates.head,
95+
maxRecordsPerSec = sortedRates.last,
96+
sample = runs.last,
97+
)
98+
}
99+
100+
private def median(sorted: Seq[Double]): Double = {
101+
val n = sorted.size
102+
if (n % 2 == 1) sorted(n / 2) else (sorted(n / 2 - 1) + sorted(n / 2)) / 2.0
103+
}
104+
}
105+
106+
/**
107+
* Renders [[AggregatedResult]]s as plain-text tables: the per-scenario measurements, and a
108+
* separate GCS-vs-HTTP deviation table computed by grouping on `family`.
109+
*/
110+
object ResultsTablePrinter {
111+
112+
def printAggregated(results: Seq[AggregatedResult]): String = {
113+
val header =
114+
f"${"Family"}%-24s ${"Variant"}%-34s ${"Sink"}%-5s ${"Iter"}%5s ${"Median rec/s"}%13s ${"Min rec/s"}%11s ${"Max rec/s"}%11s ${"Records"}%9s ${"Ops"}%6s ${"Flushes"}%8s ${"Rec/Op"}%9s ${"Avg Op(ms)"}%11s"
115+
val separator = "-" * header.length
116+
val rows = results.map { a =>
117+
f"${a.family}%-24s ${a.variant}%-34s ${a.sink}%-5s ${a.iterations}%5d ${a.medianRecordsPerSec}%13.1f ${a.minRecordsPerSec}%11.1f ${a.maxRecordsPerSec}%11.1f ${a.sample.records}%9d ${a.sample.networkOps}%6d ${a.sample.flushes}%8d ${a.sample.avgRecordsPerOp}%9.1f ${a.sample.avgOpLatencyMillis}%11.3f"
118+
}
119+
(Seq(header, separator) ++ rows).mkString("\n")
120+
}
121+
122+
/**
123+
* For every `family` that has a canonical GCS row, prints how each non-GCS (HTTP) row in that
124+
* same family compares to it, as a throughput ratio. The canonical GCS row is the default,
125+
* exactly-once-enabled configuration (the production default); families may additionally carry
126+
* an `eo=off` GCS variant, which is intentionally excluded from the ratio here so the comparison
127+
* stays against the production-default GCS behaviour (the `eo=off` numbers are shown in the main
128+
* results table). Families with no GCS row (e.g. the logging-cost HTTP-only comparison) are
129+
* skipped -- that comparison is HTTP-vs-HTTP, not GCS-vs-HTTP.
130+
*/
131+
def printDeviation(results: Seq[AggregatedResult]): String = {
132+
val byFamily = results.groupBy(_.family)
133+
val header = f"${"Family"}%-24s ${"GCS median rec/s"}%18s ${"HTTP variant"}%-34s ${"HTTP median rec/s"}%19s ${"GCS/HTTP ratio"}%15s"
134+
val separator = "-" * header.length
135+
val rows = byFamily.toSeq.sortBy(_._1).flatMap {
136+
case (family, rows) =>
137+
val httpRows = rows.filter(_.sink == "HTTP")
138+
// Canonical GCS row = the exactly-once-enabled (production default) variant, i.e. not the
139+
// "eo=off" contrast variant.
140+
val gcsRows = rows.filter(row => row.sink == "GCS" && !row.variant.contains("eo=off"))
141+
if (gcsRows.size != 1 || httpRows.isEmpty) {
142+
Seq.empty
143+
} else {
144+
val gcs = gcsRows.head
145+
httpRows.map { http =>
146+
val ratio = if (http.medianRecordsPerSec <= 0) Double.PositiveInfinity else gcs.medianRecordsPerSec / http.medianRecordsPerSec
147+
f"${family}%-24s ${gcs.medianRecordsPerSec}%18.1f ${http.variant}%-34s ${http.medianRecordsPerSec}%19.1f ${ratio}%14.2fx"
148+
}
149+
}
150+
}
151+
(Seq(header, separator) ++ rows).mkString("\n")
152+
}
153+
}
154+
155+
/**
156+
* Best-effort heap usage sampling around a benchmark run. Not a substitute for a real profiler:
157+
* intended only to corroborate large, order-of-magnitude differences, not to make precise
158+
* per-record allocation claims.
159+
*/
160+
object HeapSampler {
161+
162+
/** Requests a full GC and reads used heap. Best-effort: JVMs are not required to honour System.gc(). */
163+
def usedHeapBytes(): Long = {
164+
val runtime = Runtime.getRuntime
165+
System.gc()
166+
Thread.sleep(50)
167+
System.gc()
168+
runtime.totalMemory() - runtime.freeMemory()
169+
}
170+
171+
def measure[A](block: => A): (A, Long, Long) = {
172+
val before = usedHeapBytes()
173+
val result = block
174+
val after = usedHeapBytes()
175+
(result, before, after)
176+
}
177+
}
Lines changed: 65 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,65 @@
1+
/*
2+
* Copyright 2017-2026 Lenses.io Ltd
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
package io.lenses.streamreactor.connect.benchmarks
17+
18+
import org.apache.kafka.connect.data.Schema
19+
import org.apache.kafka.connect.sink.SinkRecord
20+
21+
/**
22+
* Produces identical synthetic `SinkRecord`s for both the HTTP sink and the GCS sink harnesses,
23+
* so that the two throughput measurements are driven from exactly the same input.
24+
*
25+
* Records carry a plain JSON string value (`Schema.STRING_SCHEMA`), which both sinks accept:
26+
* - The HTTP sink's `{{value}}` template substitution passes the string straight through.
27+
* - The GCS sink's `ValueToSinkDataConverter` turns a `String` into `StringSinkData`, which the
28+
* JSON format writer serialises via the standard Kafka `JsonConverter` — the same per-record
29+
* JSON-encoding cost a real deployment pays, even though the resulting bytes are a quoted/escaped
30+
* JSON string rather than a bare JSON object. This is irrelevant for a throughput comparison
31+
* (we are not asserting on output content), but is called out here and in the README.
32+
*/
33+
object RecordGenerator {
34+
35+
/**
36+
* @param topic Kafka topic name to stamp on every record.
37+
* @param count number of records to generate.
38+
* @param startOffset offset of the first record; subsequent records increment by 1.
39+
* @param partition Kafka partition to stamp on every record.
40+
* @param payloadBytes approximate size in bytes of the generated JSON value (padded with an
41+
* opaque filler field so the record body reaches roughly this size).
42+
*/
43+
def sinkRecords(
44+
topic: String,
45+
count: Int,
46+
startOffset: Long = 0L,
47+
partition: Int = 0,
48+
payloadBytes: Int = 128,
49+
): IndexedSeq[SinkRecord] = {
50+
val basePadding = math.max(0, payloadBytes - baseRecordOverheadBytes)
51+
val padding = "x" * basePadding
52+
(0 until count).map { i =>
53+
val offset = startOffset + i
54+
val json = jsonValue(offset, padding)
55+
new SinkRecord(topic, partition, null, null, Schema.STRING_SCHEMA, json, offset)
56+
}
57+
}
58+
59+
// Rough fixed overhead of the JSON envelope below (field names/quotes/braces), used so
60+
// `payloadBytes` approximates the total record size rather than the padding size alone.
61+
private val baseRecordOverheadBytes = 40
62+
63+
private def jsonValue(offset: Long, padding: String): String =
64+
s"""{"id":$offset,"name":"user-$offset","payload":"$padding"}"""
65+
}

0 commit comments

Comments
 (0)