Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

dataflow/logging: Activate on data #8539

Merged
merged 4 commits into from Oct 7, 2021

Conversation

antiguru
Copy link
Member

@antiguru antiguru commented Oct 5, 2021

Currently, the logging dataflows activate once every introspection
interval to process data. This can cause a significant buildup of data
before it is processed.

In addition to activating the replay operator periodically, also
activate it once a sufficient amount of data has been accumulated.
Ideally, the data processing should be activated as soon as some data is
available, but this could cause a situation where activating causes
additional data to be produced.

For this reason, the dataflow activates after 32 batches have been
published by the logging infrastructure. This seems to be a reasonable
trade-off between memory (currently at most 8KiB per batch) and latency.

The time-based activation is still required in case there is no data for
a specific dataflow. In this case, we still need to advance the clock,
which the time-based activation takes care of.

Signed-off-by: Moritz Hoffmann mh@materialize.com

Motivation

Description

Tips for reviewer

Checklist

  • This PR has adequate test coverage.
  • This PR adds a release note for any user-facing behavior changes.

@antiguru
Copy link
Member Author

antiguru commented Oct 5, 2021

Adding some evidence of performance impact. I'm testing dbbench with a constant throughput of 400 select count(*) from ..., 14 Timely workers, 1s introspection, debug introspection turned on. Current main is hardly able to keep up and shows significant latency spikes of >200ms. The PR avoids all the spikes, for slightly higher median, but lower average.

dbbench config:

duration = 120s

[setup]
query=create materialized view if not exists test2 as select generate_series as x from generate_series(1, 100)
query=create view if not exists tempview1 as select * from test2 where x % 2 = 1

[teardown]
query=drop view tempview1
query=drop view test2

[loadtest]
#query=select * from tempview1
#rate=3000
query=select count(*) from tempview1
rate=400
start=1s

Master: Memory ~2.5GiB

2021/10/05 13:18:02 Connecting to postgres://materialize:XXX@localhost:6875/materialize?sslmode=disable
2021/10/05 13:18:02 Connected
2021/10/05 13:18:02 Performing setup
2021/10/05 13:18:03 starting loadtest
2021/10/05 13:18:04 loadtest: 398 transactions (400.292 TPS), latency 13.038292ms±3.872989ms; 398 rows (400.292 RPS), 398 queries (400.292 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:05 loadtest: 401 transactions (400.780 TPS), latency 16.876627ms±4.775919ms; 401 rows (400.780 RPS), 401 queries (400.780 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:06 loadtest: 399 transactions (400.256 TPS), latency 17.107195ms±4.831792ms; 399 rows (400.256 RPS), 399 queries (400.256 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:07 loadtest: 400 transactions (400.351 TPS), latency 13.157333ms±3.969217ms; 400 rows (400.351 RPS), 400 queries (400.351 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:08 loadtest: 401 transactions (400.499 TPS), latency 13.643872ms±4.148543ms; 401 rows (400.499 RPS), 401 queries (400.499 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:09 loadtest: 330 transactions (400.643 TPS), latency 1.698619ms±32.029µs; 330 rows (400.643 RPS), 330 queries (400.643 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:10 loadtest: 409 transactions (351.090 TPS), latency 24.436688ms±6.314532ms; 409 rows (351.090 RPS), 409 queries (351.090 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:11 loadtest: 399 transactions (350.104 TPS), latency 17.863494ms±5.139953ms; 399 rows (350.104 RPS), 399 queries (350.104 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:12 loadtest: 399 transactions (400.101 TPS), latency 19.258691ms±5.460439ms; 399 rows (400.101 RPS), 399 queries (400.101 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:13 loadtest: 402 transactions (400.498 TPS), latency 20.410805ms±5.546665ms; 402 rows (400.498 RPS), 402 queries (400.498 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:14 loadtest: 402 transactions (400.390 TPS), latency 16.402552ms±4.727255ms; 402 rows (400.390 RPS), 402 queries (400.390 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:15 loadtest: 403 transactions (400.370 TPS), latency 17.079475ms±4.90745ms; 403 rows (400.370 RPS), 403 queries (400.370 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:16 loadtest: 402 transactions (399.885 TPS), latency 20.071244ms±5.446461ms; 402 rows (399.885 RPS), 402 queries (399.885 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:17 loadtest: 403 transactions (400.250 TPS), latency 18.363545ms±5.031294ms; 403 rows (400.250 RPS), 403 queries (400.250 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:18 loadtest: 402 transactions (400.373 TPS), latency 23.266686ms±6.110969ms; 402 rows (400.373 RPS), 402 queries (400.373 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:19 loadtest: 404 transactions (377.039 TPS), latency 23.160984ms±6.053397ms; 404 rows (377.039 RPS), 404 queries (377.039 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:20 loadtest: 402 transactions (400.603 TPS), latency 21.189764ms±5.823126ms; 402 rows (400.603 RPS), 402 queries (400.603 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:21 loadtest: 402 transactions (400.387 TPS), latency 19.562519ms±5.385971ms; 402 rows (400.387 RPS), 402 queries (400.387 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:22 loadtest: 403 transactions (400.347 TPS), latency 26.895967ms±6.841733ms; 403 rows (400.347 RPS), 403 queries (400.347 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:23 loadtest: 402 transactions (400.373 TPS), latency 22.641072ms±5.979681ms; 402 rows (400.373 RPS), 402 queries (400.373 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:24 loadtest: 402 transactions (400.468 TPS), latency 29.756467ms±7.445567ms; 402 rows (400.468 RPS), 402 queries (400.468 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:25 loadtest: 402 transactions (400.367 TPS), latency 25.294323ms±6.419123ms; 402 rows (400.367 RPS), 402 queries (400.367 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:26 loadtest: 403 transactions (400.643 TPS), latency 27.803656ms±7.031654ms; 403 rows (400.643 RPS), 403 queries (400.643 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:27 loadtest: 402 transactions (400.420 TPS), latency 29.027267ms±7.114431ms; 402 rows (400.420 RPS), 402 queries (400.420 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:28 loadtest: 402 transactions (400.331 TPS), latency 40.066354ms±9.286822ms; 402 rows (400.331 RPS), 402 queries (400.331 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:29 loadtest: 402 transactions (400.315 TPS), latency 32.075036ms±7.822677ms; 402 rows (400.315 RPS), 402 queries (400.315 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:30 loadtest: 403 transactions (400.544 TPS), latency 31.922095ms±7.540013ms; 403 rows (400.544 RPS), 403 queries (400.544 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:31 loadtest: 403 transactions (400.217 TPS), latency 27.202822ms±6.713276ms; 403 rows (400.217 RPS), 403 queries (400.217 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:32 loadtest: 402 transactions (399.985 TPS), latency 28.588707ms±7.04759ms; 402 rows (399.985 RPS), 402 queries (399.985 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:33 loadtest: 402 transactions (400.098 TPS), latency 29.579201ms±7.159404ms; 402 rows (400.098 RPS), 402 queries (400.098 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:34 loadtest: 403 transactions (400.455 TPS), latency 30.341321ms±7.10625ms; 403 rows (400.455 RPS), 403 queries (400.455 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:35 loadtest: 403 transactions (400.441 TPS), latency 59.039652ms±11.50445ms; 403 rows (400.441 RPS), 403 queries (400.441 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:36 loadtest: 402 transactions (400.534 TPS), latency 40.400191ms±9.08111ms; 402 rows (400.534 RPS), 402 queries (400.534 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:37 loadtest: 403 transactions (400.466 TPS), latency 38.957061ms±8.483059ms; 403 rows (400.466 RPS), 403 queries (400.466 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:38 loadtest: 401 transactions (400.050 TPS), latency 32.882994ms±7.603561ms; 401 rows (400.050 RPS), 401 queries (400.050 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:39 loadtest: 400 transactions (400.049 TPS), latency 35.044905ms±8.11767ms; 400 rows (400.049 RPS), 400 queries (400.049 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:40 loadtest: 400 transactions (400.084 TPS), latency 49.545019ms±10.250448ms; 400 rows (400.084 RPS), 400 queries (400.084 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:41 loadtest: 400 transactions (400.691 TPS), latency 44.774655ms±9.794367ms; 400 rows (400.691 RPS), 400 queries (400.691 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:42 loadtest: 400 transactions (400.089 TPS), latency 45.055396ms±9.383424ms; 400 rows (400.089 RPS), 400 queries (400.089 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:43 loadtest: 400 transactions (400.037 TPS), latency 45.082602ms±9.515474ms; 400 rows (400.037 RPS), 400 queries (400.037 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:44 loadtest: 400 transactions (400.463 TPS), latency 53.621642ms±11.084788ms; 400 rows (400.463 RPS), 400 queries (400.463 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:45 loadtest: 400 transactions (400.477 TPS), latency 44.119239ms±9.359709ms; 400 rows (400.477 RPS), 400 queries (400.477 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:46 loadtest: 400 transactions (400.346 TPS), latency 45.40695ms±9.561781ms; 400 rows (400.346 RPS), 400 queries (400.346 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:47 loadtest: 401 transactions (400.758 TPS), latency 48.475705ms±10.102767ms; 401 rows (400.758 RPS), 401 queries (400.758 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:48 loadtest: 399 transactions (400.097 TPS), latency 43.556216ms±9.117582ms; 399 rows (400.097 RPS), 399 queries (400.097 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:49 loadtest: 400 transactions (400.479 TPS), latency 41.434076ms±8.612427ms; 400 rows (400.479 RPS), 400 queries (400.479 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:50 loadtest: 400 transactions (400.407 TPS), latency 47.585242ms±9.818571ms; 400 rows (400.407 RPS), 400 queries (400.407 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:51 loadtest: 400 transactions (400.347 TPS), latency 48.525688ms±9.955065ms; 400 rows (400.347 RPS), 400 queries (400.347 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:52 loadtest: 400 transactions (400.242 TPS), latency 53.959045ms±10.514531ms; 400 rows (400.242 RPS), 400 queries (400.242 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:53 loadtest: 400 transactions (400.424 TPS), latency 50.102058ms±10.118463ms; 400 rows (400.424 RPS), 400 queries (400.424 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:54 loadtest: 400 transactions (400.452 TPS), latency 52.115778ms±10.463109ms; 400 rows (400.452 RPS), 400 queries (400.452 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:55 loadtest: 400 transactions (400.261 TPS), latency 56.00884ms±11.053501ms; 400 rows (400.261 RPS), 400 queries (400.261 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:56 loadtest: 400 transactions (400.483 TPS), latency 59.396189ms±11.153936ms; 400 rows (400.483 RPS), 400 queries (400.483 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:57 loadtest: 399 transactions (399.477 TPS), latency 67.725656ms±12.559906ms; 399 rows (399.477 RPS), 399 queries (399.477 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:58 loadtest: 400 transactions (400.446 TPS), latency 56.54036ms±10.90153ms; 400 rows (400.446 RPS), 400 queries (400.446 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:18:59 loadtest: 400 transactions (400.228 TPS), latency 60.122831ms±10.820374ms; 400 rows (400.228 RPS), 400 queries (400.228 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:00 loadtest: 400 transactions (400.358 TPS), latency 53.232781ms±9.990673ms; 400 rows (400.358 RPS), 400 queries (400.358 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:01 loadtest: 400 transactions (399.509 TPS), latency 57.535067ms±10.799002ms; 400 rows (399.509 RPS), 400 queries (399.509 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:02 loadtest: 400 transactions (400.275 TPS), latency 59.533178ms±10.995598ms; 400 rows (400.275 RPS), 400 queries (400.275 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:03 loadtest: 400 transactions (400.340 TPS), latency 53.929083ms±9.933382ms; 400 rows (400.340 RPS), 400 queries (400.340 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:04 loadtest: 400 transactions (400.483 TPS), latency 62.189271ms±11.654894ms; 400 rows (400.483 RPS), 400 queries (400.483 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:05 loadtest: 400 transactions (400.586 TPS), latency 65.353508ms±12.027319ms; 400 rows (400.586 RPS), 400 queries (400.586 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:06 loadtest: 400 transactions (400.373 TPS), latency 61.385567ms±11.215937ms; 400 rows (400.373 RPS), 400 queries (400.373 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:07 loadtest: 400 transactions (400.372 TPS), latency 62.00997ms±11.127269ms; 400 rows (400.372 RPS), 400 queries (400.372 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:08 loadtest: 400 transactions (400.444 TPS), latency 62.174454ms±11.01079ms; 400 rows (400.444 RPS), 400 queries (400.444 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:09 loadtest: 400 transactions (400.324 TPS), latency 62.672186ms±11.284437ms; 400 rows (400.324 RPS), 400 queries (400.324 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:10 loadtest: 400 transactions (400.512 TPS), latency 69.642168ms±11.539347ms; 400 rows (400.512 RPS), 400 queries (400.512 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:11 loadtest: 400 transactions (400.136 TPS), latency 76.408564ms±12.701023ms; 400 rows (400.136 RPS), 400 queries (400.136 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:12 loadtest: 400 transactions (400.195 TPS), latency 61.904452ms±10.821634ms; 400 rows (400.195 RPS), 400 queries (400.195 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:13 loadtest: 400 transactions (400.590 TPS), latency 66.581546ms±11.330445ms; 400 rows (400.590 RPS), 400 queries (400.590 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:14 loadtest: 400 transactions (400.184 TPS), latency 85.207081ms±13.602797ms; 400 rows (400.184 RPS), 400 queries (400.184 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:15 loadtest: 400 transactions (400.060 TPS), latency 75.472789ms±12.724497ms; 400 rows (400.060 RPS), 400 queries (400.060 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:16 loadtest: 400 transactions (400.455 TPS), latency 61.441748ms±10.493581ms; 400 rows (400.455 RPS), 400 queries (400.455 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:17 loadtest: 400 transactions (400.265 TPS), latency 95.912086ms±14.722893ms; 400 rows (400.265 RPS), 400 queries (400.265 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:18 loadtest: 400 transactions (400.290 TPS), latency 73.164668ms±12.310385ms; 400 rows (400.290 RPS), 400 queries (400.290 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:19 loadtest: 400 transactions (400.209 TPS), latency 88.16348ms±14.310892ms; 400 rows (400.209 RPS), 400 queries (400.209 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:20 loadtest: 400 transactions (399.900 TPS), latency 81.8772ms±12.833789ms; 400 rows (399.900 RPS), 400 queries (399.900 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:21 loadtest: 400 transactions (400.356 TPS), latency 58.775029ms±9.812298ms; 400 rows (400.356 RPS), 400 queries (400.356 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:22 loadtest: 400 transactions (400.311 TPS), latency 49.293504ms±8.032698ms; 400 rows (400.311 RPS), 400 queries (400.311 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:23 loadtest: 400 transactions (400.190 TPS), latency 56.894768ms±9.268503ms; 400 rows (400.190 RPS), 400 queries (400.190 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:24 loadtest: 400 transactions (399.994 TPS), latency 54.423716ms±8.66122ms; 400 rows (399.994 RPS), 400 queries (399.994 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:25 loadtest: 400 transactions (400.128 TPS), latency 76.464364ms±11.893537ms; 400 rows (400.128 RPS), 400 queries (400.128 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:26 loadtest: 400 transactions (400.583 TPS), latency 85.627826ms±12.923767ms; 400 rows (400.583 RPS), 400 queries (400.583 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:27 loadtest: 400 transactions (400.122 TPS), latency 80.686373ms±12.7399ms; 400 rows (400.122 RPS), 400 queries (400.122 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:28 loadtest: 400 transactions (400.262 TPS), latency 83.404436ms±13.168ms; 400 rows (400.262 RPS), 400 queries (400.262 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:29 loadtest: 400 transactions (400.092 TPS), latency 73.586645ms±11.236279ms; 400 rows (400.092 RPS), 400 queries (400.092 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:30 loadtest: 400 transactions (400.031 TPS), latency 90.699701ms±13.020417ms; 400 rows (400.031 RPS), 400 queries (400.031 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:31 loadtest: 400 transactions (400.380 TPS), latency 76.99758ms±10.982929ms; 400 rows (400.380 RPS), 400 queries (400.380 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:32 loadtest: 400 transactions (400.105 TPS), latency 100.644499ms±13.962942ms; 400 rows (400.105 RPS), 400 queries (400.105 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:33 loadtest: 400 transactions (400.082 TPS), latency 83.177665ms±11.529113ms; 400 rows (400.082 RPS), 400 queries (400.082 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:34 loadtest: 400 transactions (400.314 TPS), latency 105.076709ms±14.101498ms; 400 rows (400.314 RPS), 400 queries (400.314 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:35 loadtest: 396 transactions (395.779 TPS), latency 129.531303ms±16.238826ms; 396 rows (395.779 RPS), 396 queries (395.779 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:36 loadtest: 357 transactions (355.184 TPS), latency 127.23929ms±15.737125ms; 357 rows (355.184 RPS), 357 queries (355.184 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:37 loadtest: 300 transactions (282.551 TPS), latency 83.083081ms±14.236137ms; 300 rows (282.551 RPS), 300 queries (282.551 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:38 loadtest: 544 transactions (398.314 TPS), latency 158.887495ms±12.625057ms; 544 rows (398.314 RPS), 544 queries (398.314 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:39 loadtest: 388 transactions (385.573 TPS), latency 111.018321ms±13.892903ms; 388 rows (385.573 RPS), 388 queries (385.573 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:40 loadtest: 334 transactions (323.065 TPS), latency 85.954405ms±13.370901ms; 334 rows (323.065 RPS), 334 queries (323.065 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:41 loadtest: 362 transactions (305.333 TPS), latency 91.711214ms±11.818305ms; 362 rows (305.333 RPS), 362 queries (305.333 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:42 loadtest: 467 transactions (356.902 TPS), latency 127.385147ms±11.729279ms; 467 rows (356.902 RPS), 467 queries (356.902 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:43 loadtest: 338 transactions (340.294 TPS), latency 69.354087ms±10.349828ms; 338 rows (340.294 RPS), 338 queries (340.294 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:44 loadtest: 474 transactions (375.800 TPS), latency 127.579061ms±11.28622ms; 474 rows (375.800 RPS), 474 queries (375.800 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:45 loadtest: 424 transactions (388.304 TPS), latency 93.290609ms±11.58961ms; 424 rows (388.304 RPS), 424 queries (388.304 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:46 loadtest: 330 transactions (321.462 TPS), latency 101.909374ms±16.335732ms; 330 rows (321.462 RPS), 330 queries (321.462 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:47 loadtest: 451 transactions (372.776 TPS), latency 119.271633ms±12.257513ms; 451 rows (372.776 RPS), 451 queries (372.776 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:48 loadtest: 325 transactions (301.521 TPS), latency 94.171358ms±15.79857ms; 325 rows (301.521 RPS), 325 queries (301.521 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:49 loadtest: 401 transactions (352.321 TPS), latency 135.098345ms±14.967834ms; 401 rows (352.321 RPS), 401 queries (352.321 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:50 loadtest: 398 transactions (323.223 TPS), latency 109.076377ms±13.133347ms; 398 rows (323.223 RPS), 398 queries (323.223 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:51 loadtest: 427 transactions (366.970 TPS), latency 105.913014ms±11.545915ms; 427 rows (366.970 RPS), 427 queries (366.970 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:52 loadtest: 399 transactions (330.134 TPS), latency 96.713305ms±11.895296ms; 399 rows (330.134 RPS), 399 queries (330.134 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:53 loadtest: 405 transactions (335.799 TPS), latency 102.608184ms±13.689641ms; 405 rows (335.799 RPS), 405 queries (335.799 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:54 loadtest: 395 transactions (331.619 TPS), latency 97.48716ms±13.061035ms; 395 rows (331.619 RPS), 395 queries (331.619 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:55 loadtest: 379 transactions (320.790 TPS), latency 113.593524ms±16.118517ms; 379 rows (320.790 RPS), 379 queries (320.790 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:56 loadtest: 406 transactions (322.559 TPS), latency 141.385245ms±17.274518ms; 406 rows (322.559 RPS), 406 queries (322.559 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:57 loadtest: 358 transactions (297.922 TPS), latency 112.377908ms±16.124619ms; 358 rows (297.922 RPS), 358 queries (297.922 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:58 loadtest: 401 transactions (306.068 TPS), latency 168.287765ms±18.837239ms; 401 rows (306.068 RPS), 401 queries (306.068 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:19:59 loadtest: 453 transactions (337.998 TPS), latency 168.858366ms±14.832106ms; 453 rows (337.998 RPS), 453 queries (337.998 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:20:00 loadtest: 380 transactions (318.854 TPS), latency 116.600789ms±14.16695ms; 380 rows (318.854 RPS), 380 queries (318.854 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:20:01 loadtest: 453 transactions (357.816 TPS), latency 156.506905ms±13.090758ms; 453 rows (357.816 RPS), 453 queries (357.816 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:20:02 loadtest: 355 transactions (317.738 TPS), latency 86.129686ms±11.379352ms; 355 rows (317.738 RPS), 355 queries (317.738 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:20:02 stopping loadtest
2021/10/05 13:20:02 loadtest: 47597 transactions (399.636 TPS), latency 65.061324ms±1.086511ms; 47597 rows (399.636 RPS), 47597 queries (399.636 QPS); 0 aborts (0.000%), latency 0s±0s
Transactions:
  1.048576ms -   2.097152ms [ 23133]: ██████████████████████████████████████████████████
  2.097152ms -   4.194304ms [  4239]: █████████▏
  4.194304ms -   8.388608ms [   444]: ▉
  8.388608ms -  16.777216ms [   647]: █▍
 16.777216ms -  33.554432ms [  1092]: ██▎
 33.554432ms -  67.108864ms [  2056]: ████▍
 67.108864ms - 134.217728ms [  4424]: █████████▌
134.217728ms - 268.435456ms [  9943]: █████████████████████▍
268.435456ms - 536.870912ms [  1619]: ███▍
2021/10/05 13:20:02 Performing teardown

PR applied: Memory ~1GiB

2021/10/05 13:24:23 Connecting to postgres://materialize:XXX@localhost:6875/materialize?sslmode=disable
2021/10/05 13:24:23 Connected
2021/10/05 13:24:23 Performing setup
2021/10/05 13:24:24 starting loadtest
2021/10/05 13:24:25 loadtest: 398 transactions (400.533 TPS), latency 2.760639ms±367.095µs; 398 rows (400.533 RPS), 398 queries (400.533 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:26 loadtest: 400 transactions (400.203 TPS), latency 3.644472ms±818.725µs; 400 rows (400.203 RPS), 400 queries (400.203 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:27 loadtest: 400 transactions (399.904 TPS), latency 3.520231ms±823.166µs; 400 rows (399.904 RPS), 400 queries (399.904 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:28 loadtest: 400 transactions (399.591 TPS), latency 2.961971ms±522.16µs; 400 rows (399.591 RPS), 400 queries (399.591 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:29 loadtest: 400 transactions (400.350 TPS), latency 3.273671ms±720.413µs; 400 rows (400.350 RPS), 400 queries (400.350 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:30 loadtest: 400 transactions (400.224 TPS), latency 3.123521ms±525.473µs; 400 rows (400.224 RPS), 400 queries (400.224 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:31 loadtest: 400 transactions (400.226 TPS), latency 3.715569ms±853.039µs; 400 rows (400.226 RPS), 400 queries (400.226 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:32 loadtest: 400 transactions (399.975 TPS), latency 3.739108ms±861.784µs; 400 rows (399.975 RPS), 400 queries (399.975 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:33 loadtest: 400 transactions (399.996 TPS), latency 3.032419ms±647.491µs; 400 rows (399.996 RPS), 400 queries (399.996 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:34 loadtest: 400 transactions (399.959 TPS), latency 3.203532ms±645.359µs; 400 rows (399.959 RPS), 400 queries (399.959 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:35 loadtest: 400 transactions (399.954 TPS), latency 3.702251ms±830.757µs; 400 rows (399.954 RPS), 400 queries (399.954 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:36 loadtest: 400 transactions (400.033 TPS), latency 2.850146ms±482.993µs; 400 rows (400.033 RPS), 400 queries (400.033 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:37 loadtest: 400 transactions (399.943 TPS), latency 3.364456ms±710.055µs; 400 rows (399.943 RPS), 400 queries (399.943 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:38 loadtest: 400 transactions (399.834 TPS), latency 3.766148ms±872.377µs; 400 rows (399.834 RPS), 400 queries (399.834 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:39 loadtest: 400 transactions (400.078 TPS), latency 3.945492ms±901.9µs; 400 rows (400.078 RPS), 400 queries (400.078 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:40 loadtest: 400 transactions (400.157 TPS), latency 3.886905ms±902.689µs; 400 rows (400.157 RPS), 400 queries (400.157 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:41 loadtest: 400 transactions (400.494 TPS), latency 3.42445ms±704.179µs; 400 rows (400.494 RPS), 400 queries (400.494 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:42 loadtest: 401 transactions (400.501 TPS), latency 3.653369ms±832.822µs; 401 rows (400.501 RPS), 401 queries (400.501 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:43 loadtest: 399 transactions (400.274 TPS), latency 3.880462ms±893.939µs; 399 rows (400.274 RPS), 399 queries (400.274 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:44 loadtest: 400 transactions (399.801 TPS), latency 3.615952ms±744.775µs; 400 rows (399.801 RPS), 400 queries (399.801 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:45 loadtest: 400 transactions (400.127 TPS), latency 2.795289ms±425.974µs; 400 rows (400.127 RPS), 400 queries (400.127 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:46 loadtest: 400 transactions (399.832 TPS), latency 2.980406ms±537.186µs; 400 rows (399.832 RPS), 400 queries (399.832 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:47 loadtest: 400 transactions (400.397 TPS), latency 4.017302ms±926.121µs; 400 rows (400.397 RPS), 400 queries (400.397 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:48 loadtest: 400 transactions (400.192 TPS), latency 3.276028ms±696.563µs; 400 rows (400.192 RPS), 400 queries (400.192 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:49 loadtest: 400 transactions (399.956 TPS), latency 3.241737ms±637.889µs; 400 rows (399.956 RPS), 400 queries (399.956 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:50 loadtest: 400 transactions (399.543 TPS), latency 3.779185ms±797.617µs; 400 rows (399.543 RPS), 400 queries (399.543 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:51 loadtest: 400 transactions (400.208 TPS), latency 3.358418ms±658.137µs; 400 rows (400.208 RPS), 400 queries (400.208 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:52 loadtest: 400 transactions (399.887 TPS), latency 3.900802ms±873.485µs; 400 rows (399.887 RPS), 400 queries (399.887 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:53 loadtest: 400 transactions (400.238 TPS), latency 3.473208ms±684.067µs; 400 rows (400.238 RPS), 400 queries (400.238 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:54 loadtest: 400 transactions (400.438 TPS), latency 3.336396ms±650.73µs; 400 rows (400.438 RPS), 400 queries (400.438 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:55 loadtest: 400 transactions (400.115 TPS), latency 3.933865ms±834.457µs; 400 rows (400.115 RPS), 400 queries (400.115 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:56 loadtest: 400 transactions (400.092 TPS), latency 4.214946ms±964.673µs; 400 rows (400.092 RPS), 400 queries (400.092 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:57 loadtest: 400 transactions (400.035 TPS), latency 3.243726ms±618.615µs; 400 rows (400.035 RPS), 400 queries (400.035 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:58 loadtest: 400 transactions (399.881 TPS), latency 2.701798ms±410.764µs; 400 rows (399.881 RPS), 400 queries (399.881 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:24:59 loadtest: 400 transactions (400.154 TPS), latency 4.443388ms±1.000765ms; 400 rows (400.154 RPS), 400 queries (400.154 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:00 loadtest: 400 transactions (399.506 TPS), latency 2.883413ms±469.79µs; 400 rows (399.506 RPS), 400 queries (399.506 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:01 loadtest: 400 transactions (399.812 TPS), latency 3.372701ms±612.764µs; 400 rows (399.812 RPS), 400 queries (399.812 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:02 loadtest: 400 transactions (400.340 TPS), latency 2.95826ms±512.966µs; 400 rows (400.340 RPS), 400 queries (400.340 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:03 loadtest: 400 transactions (400.282 TPS), latency 3.698323ms±741.471µs; 400 rows (400.282 RPS), 400 queries (400.282 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:04 loadtest: 400 transactions (400.093 TPS), latency 4.601512ms±1.086392ms; 400 rows (400.093 RPS), 400 queries (400.093 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:05 loadtest: 400 transactions (400.332 TPS), latency 3.408149ms±764.983µs; 400 rows (400.332 RPS), 400 queries (400.332 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:06 loadtest: 400 transactions (399.892 TPS), latency 3.187938ms±569.948µs; 400 rows (399.892 RPS), 400 queries (399.892 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:07 loadtest: 400 transactions (400.092 TPS), latency 3.45644ms±694.956µs; 400 rows (400.092 RPS), 400 queries (400.092 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:08 loadtest: 400 transactions (399.863 TPS), latency 3.696844ms±778.468µs; 400 rows (399.863 RPS), 400 queries (399.863 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:09 loadtest: 400 transactions (400.302 TPS), latency 2.963473ms±489.02µs; 400 rows (400.302 RPS), 400 queries (400.302 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:10 loadtest: 400 transactions (400.161 TPS), latency 3.491234ms±702.6µs; 400 rows (400.161 RPS), 400 queries (400.161 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:11 loadtest: 400 transactions (399.820 TPS), latency 3.909451ms±836.602µs; 400 rows (399.820 RPS), 400 queries (399.820 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:12 loadtest: 400 transactions (400.077 TPS), latency 3.539992ms±740.217µs; 400 rows (400.077 RPS), 400 queries (400.077 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:13 loadtest: 400 transactions (400.055 TPS), latency 3.225485ms±638.804µs; 400 rows (400.055 RPS), 400 queries (400.055 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:14 loadtest: 400 transactions (399.957 TPS), latency 3.486642ms±672.417µs; 400 rows (399.957 RPS), 400 queries (399.957 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:15 loadtest: 400 transactions (400.239 TPS), latency 3.248407ms±613.875µs; 400 rows (400.239 RPS), 400 queries (400.239 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:16 loadtest: 400 transactions (400.400 TPS), latency 3.560002ms±751.037µs; 400 rows (400.400 RPS), 400 queries (400.400 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:17 loadtest: 400 transactions (400.480 TPS), latency 3.782463ms±773.816µs; 400 rows (400.480 RPS), 400 queries (400.480 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:18 loadtest: 400 transactions (399.838 TPS), latency 3.688658ms±673.584µs; 400 rows (399.838 RPS), 400 queries (399.838 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:19 loadtest: 400 transactions (399.787 TPS), latency 3.656786ms±728.99µs; 400 rows (399.787 RPS), 400 queries (399.787 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:20 loadtest: 400 transactions (400.384 TPS), latency 3.394076ms±726.177µs; 400 rows (400.384 RPS), 400 queries (400.384 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:21 loadtest: 400 transactions (400.418 TPS), latency 2.810011ms±424.068µs; 400 rows (400.418 RPS), 400 queries (400.418 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:22 loadtest: 400 transactions (400.062 TPS), latency 3.184785ms±607.161µs; 400 rows (400.062 RPS), 400 queries (400.062 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:23 loadtest: 400 transactions (400.004 TPS), latency 3.352668ms±682.048µs; 400 rows (400.004 RPS), 400 queries (400.004 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:24 loadtest: 400 transactions (400.061 TPS), latency 3.607617ms±700.609µs; 400 rows (400.061 RPS), 400 queries (400.061 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:25 loadtest: 400 transactions (399.937 TPS), latency 3.317262ms±663.455µs; 400 rows (399.937 RPS), 400 queries (399.937 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:26 loadtest: 400 transactions (400.165 TPS), latency 3.303195ms±614.28µs; 400 rows (400.165 RPS), 400 queries (400.165 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:27 loadtest: 400 transactions (400.091 TPS), latency 4.27099ms±917.81µs; 400 rows (400.091 RPS), 400 queries (400.091 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:28 loadtest: 400 transactions (400.454 TPS), latency 3.43523ms±654.207µs; 400 rows (400.454 RPS), 400 queries (400.454 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:29 loadtest: 400 transactions (400.320 TPS), latency 3.540802ms±691.103µs; 400 rows (400.320 RPS), 400 queries (400.320 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:30 loadtest: 400 transactions (399.852 TPS), latency 3.247976ms±664.689µs; 400 rows (399.852 RPS), 400 queries (399.852 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:31 loadtest: 400 transactions (400.261 TPS), latency 4.109996ms±789.333µs; 400 rows (400.261 RPS), 400 queries (400.261 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:32 loadtest: 400 transactions (400.396 TPS), latency 3.44874ms±704.624µs; 400 rows (400.396 RPS), 400 queries (400.396 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:33 loadtest: 400 transactions (400.361 TPS), latency 3.057845ms±579.151µs; 400 rows (400.361 RPS), 400 queries (400.361 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:34 loadtest: 400 transactions (399.873 TPS), latency 3.480551ms±717.746µs; 400 rows (399.873 RPS), 400 queries (399.873 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:35 loadtest: 400 transactions (400.247 TPS), latency 3.447354ms±717.554µs; 400 rows (400.247 RPS), 400 queries (400.247 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:36 loadtest: 400 transactions (400.194 TPS), latency 3.252668ms±585.053µs; 400 rows (400.194 RPS), 400 queries (400.194 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:37 loadtest: 400 transactions (400.138 TPS), latency 3.179834ms±621.564µs; 400 rows (400.138 RPS), 400 queries (400.138 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:38 loadtest: 400 transactions (400.189 TPS), latency 3.086218ms±557.363µs; 400 rows (400.189 RPS), 400 queries (400.189 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:39 loadtest: 400 transactions (400.277 TPS), latency 2.835031ms±429.967µs; 400 rows (400.277 RPS), 400 queries (400.277 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:40 loadtest: 400 transactions (400.489 TPS), latency 2.831531ms±475.179µs; 400 rows (400.489 RPS), 400 queries (400.489 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:41 loadtest: 400 transactions (400.354 TPS), latency 3.63899ms±763.061µs; 400 rows (400.354 RPS), 400 queries (400.354 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:42 loadtest: 400 transactions (400.387 TPS), latency 3.443531ms±768.478µs; 400 rows (400.387 RPS), 400 queries (400.387 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:43 loadtest: 400 transactions (400.345 TPS), latency 3.495314ms±739.364µs; 400 rows (400.345 RPS), 400 queries (400.345 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:44 loadtest: 400 transactions (400.027 TPS), latency 3.005191ms±555.115µs; 400 rows (400.027 RPS), 400 queries (400.027 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:45 loadtest: 400 transactions (399.842 TPS), latency 4.568218ms±995.542µs; 400 rows (399.842 RPS), 400 queries (399.842 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:46 loadtest: 400 transactions (400.091 TPS), latency 4.052529ms±874.976µs; 400 rows (400.091 RPS), 400 queries (400.091 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:47 loadtest: 400 transactions (399.959 TPS), latency 4.008414ms±854.943µs; 400 rows (399.959 RPS), 400 queries (399.959 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:48 loadtest: 400 transactions (400.149 TPS), latency 3.562455ms±666.096µs; 400 rows (400.149 RPS), 400 queries (400.149 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:49 loadtest: 400 transactions (400.307 TPS), latency 3.993163ms±817.057µs; 400 rows (400.307 RPS), 400 queries (400.307 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:50 loadtest: 400 transactions (400.316 TPS), latency 3.49857ms±716.138µs; 400 rows (400.316 RPS), 400 queries (400.316 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:51 loadtest: 400 transactions (399.890 TPS), latency 3.642536ms±770.606µs; 400 rows (399.890 RPS), 400 queries (399.890 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:52 loadtest: 400 transactions (400.090 TPS), latency 3.814394ms±742.603µs; 400 rows (400.090 RPS), 400 queries (400.090 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:53 loadtest: 400 transactions (400.211 TPS), latency 3.670287ms±799.034µs; 400 rows (400.211 RPS), 400 queries (400.211 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:54 loadtest: 400 transactions (400.213 TPS), latency 4.332957ms±889.549µs; 400 rows (400.213 RPS), 400 queries (400.213 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:55 loadtest: 400 transactions (399.902 TPS), latency 4.335079ms±916.782µs; 400 rows (399.902 RPS), 400 queries (399.902 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:56 loadtest: 400 transactions (400.208 TPS), latency 3.614321ms±778.751µs; 400 rows (400.208 RPS), 400 queries (400.208 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:57 loadtest: 400 transactions (400.368 TPS), latency 3.889929ms±917.896µs; 400 rows (400.368 RPS), 400 queries (400.368 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:58 loadtest: 400 transactions (399.955 TPS), latency 3.798378ms±846.765µs; 400 rows (399.955 RPS), 400 queries (399.955 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:25:59 loadtest: 400 transactions (399.393 TPS), latency 3.477311ms±687.422µs; 400 rows (399.393 RPS), 400 queries (399.393 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:00 loadtest: 400 transactions (400.387 TPS), latency 3.655756ms±815.757µs; 400 rows (400.387 RPS), 400 queries (400.387 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:01 loadtest: 400 transactions (400.287 TPS), latency 3.248168ms±600.472µs; 400 rows (400.287 RPS), 400 queries (400.287 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:02 loadtest: 400 transactions (399.921 TPS), latency 3.296115ms±646.71µs; 400 rows (399.921 RPS), 400 queries (399.921 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:03 loadtest: 400 transactions (400.397 TPS), latency 3.43878ms±702.989µs; 400 rows (400.397 RPS), 400 queries (400.397 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:04 loadtest: 400 transactions (400.131 TPS), latency 3.240277ms±652.543µs; 400 rows (400.131 RPS), 400 queries (400.131 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:05 loadtest: 400 transactions (400.051 TPS), latency 4.107601ms±890.404µs; 400 rows (400.051 RPS), 400 queries (400.051 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:06 loadtest: 400 transactions (400.442 TPS), latency 3.272139ms±677.818µs; 400 rows (400.442 RPS), 400 queries (400.442 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:07 loadtest: 400 transactions (400.276 TPS), latency 4.957555ms±1.123505ms; 400 rows (400.276 RPS), 400 queries (400.276 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:08 loadtest: 400 transactions (400.242 TPS), latency 3.261082ms±613.711µs; 400 rows (400.242 RPS), 400 queries (400.242 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:09 loadtest: 400 transactions (400.531 TPS), latency 3.703658ms±851.563µs; 400 rows (400.531 RPS), 400 queries (400.531 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:10 loadtest: 400 transactions (399.956 TPS), latency 3.116092ms±558.641µs; 400 rows (399.956 RPS), 400 queries (399.956 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:11 loadtest: 400 transactions (400.190 TPS), latency 2.923328ms±558.689µs; 400 rows (400.190 RPS), 400 queries (400.190 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:12 loadtest: 400 transactions (399.738 TPS), latency 3.852576ms±801.12µs; 400 rows (399.738 RPS), 400 queries (399.738 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:13 loadtest: 400 transactions (400.463 TPS), latency 4.394808ms±983.93µs; 400 rows (400.463 RPS), 400 queries (400.463 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:14 loadtest: 400 transactions (399.997 TPS), latency 3.195568ms±623.771µs; 400 rows (399.997 RPS), 400 queries (399.997 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:15 loadtest: 400 transactions (400.187 TPS), latency 3.219396ms±636.226µs; 400 rows (400.187 RPS), 400 queries (400.187 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:16 loadtest: 401 transactions (400.152 TPS), latency 4.208521ms±902.545µs; 401 rows (400.152 RPS), 401 queries (400.152 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:17 loadtest: 399 transactions (400.530 TPS), latency 3.555648ms±722.421µs; 399 rows (400.530 RPS), 399 queries (400.530 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:18 loadtest: 400 transactions (400.461 TPS), latency 3.044388ms±511.829µs; 400 rows (400.461 RPS), 400 queries (400.461 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:19 loadtest: 400 transactions (399.628 TPS), latency 3.154613ms±632.957µs; 400 rows (399.628 RPS), 400 queries (399.628 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:20 loadtest: 400 transactions (400.246 TPS), latency 3.783886ms±793.236µs; 400 rows (400.246 RPS), 400 queries (400.246 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:21 loadtest: 400 transactions (400.342 TPS), latency 3.623897ms±842.665µs; 400 rows (400.342 RPS), 400 queries (400.342 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:22 loadtest: 400 transactions (400.196 TPS), latency 3.194783ms±612.143µs; 400 rows (400.196 RPS), 400 queries (400.196 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:23 loadtest: 400 transactions (400.057 TPS), latency 4.020214ms±882.578µs; 400 rows (400.057 RPS), 400 queries (400.057 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/05 13:26:23 stopping loadtest
2021/10/05 13:26:23 loadtest: 47599 transactions (400.004 TPS), latency 3.52171ms±67.316µs; 47599 rows (400.004 RPS), 47599 queries (400.004 QPS); 0 aborts (0.000%), latency 0s±0s
Transactions:
  1.048576ms -   2.097152ms [ 24859]: ██████████████████████████████████████████████████
  2.097152ms -   4.194304ms [ 18795]: █████████████████████████████████████▊
  4.194304ms -   8.388608ms [   922]: █▊
  8.388608ms -  16.777216ms [  1153]: ██▎
 16.777216ms -  33.554432ms [  1273]: ██▌
 33.554432ms -  67.108864ms [   597]: █▏
2021/10/05 13:26:23 Performing teardown

@antiguru
Copy link
Member Author

antiguru commented Oct 6, 2021

I figured the activation ack shouldn't come from the logging demux operator but directly from the replay operator. It should prevent some lifeness issues that we'd risk otherwise (only for up to the introspection interval).

2021/10/06 12:01:06 Connecting to postgres://materialize:XXX@localhost:6875/materialize?sslmode=disable
2021/10/06 12:01:06 Connected
2021/10/06 12:01:06 Performing setup
2021/10/06 12:01:08 starting loadtest
2021/10/06 12:01:09 loadtest: 398 transactions (400.176 TPS), latency 2.791228ms±94.794µs; 398 rows (400.176 RPS), 398 queries (400.176 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:10 loadtest: 400 transactions (399.981 TPS), latency 2.809704ms±103.82µs; 400 rows (399.981 RPS), 400 queries (399.981 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:11 loadtest: 400 transactions (399.766 TPS), latency 2.660548ms±69.717µs; 400 rows (399.766 RPS), 400 queries (399.766 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:12 loadtest: 400 transactions (400.198 TPS), latency 2.647619ms±79.077µs; 400 rows (400.198 RPS), 400 queries (400.198 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:13 loadtest: 400 transactions (399.908 TPS), latency 2.669676ms±88.065µs; 400 rows (399.908 RPS), 400 queries (399.908 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:14 loadtest: 400 transactions (400.023 TPS), latency 2.585914ms±80.612µs; 400 rows (400.023 RPS), 400 queries (400.023 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:15 loadtest: 400 transactions (399.979 TPS), latency 2.559775ms±62.113µs; 400 rows (399.979 RPS), 400 queries (399.979 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:16 loadtest: 400 transactions (400.144 TPS), latency 2.600735ms±81.242µs; 400 rows (400.144 RPS), 400 queries (400.144 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:17 loadtest: 400 transactions (400.034 TPS), latency 2.639352ms±95.548µs; 400 rows (400.034 RPS), 400 queries (400.034 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:18 loadtest: 400 transactions (399.437 TPS), latency 2.704199ms±95.364µs; 400 rows (399.437 RPS), 400 queries (399.437 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:19 loadtest: 399 transactions (399.140 TPS), latency 2.586985ms±65.788µs; 399 rows (399.140 RPS), 399 queries (399.140 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:20 loadtest: 400 transactions (399.516 TPS), latency 3.059775ms±145.329µs; 400 rows (399.516 RPS), 400 queries (399.516 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:21 loadtest: 401 transactions (400.354 TPS), latency 2.790037ms±87.485µs; 401 rows (400.354 RPS), 401 queries (400.354 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:22 loadtest: 400 transactions (400.341 TPS), latency 2.789771ms±116.097µs; 400 rows (400.341 RPS), 400 queries (400.341 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:23 loadtest: 400 transactions (400.459 TPS), latency 2.74442ms±105.027µs; 400 rows (400.459 RPS), 400 queries (400.459 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:24 loadtest: 400 transactions (400.367 TPS), latency 2.652ms±70.922µs; 400 rows (400.367 RPS), 400 queries (400.367 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:25 loadtest: 399 transactions (400.333 TPS), latency 2.686877ms±116.597µs; 399 rows (400.333 RPS), 399 queries (400.333 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:26 loadtest: 401 transactions (400.216 TPS), latency 2.655759ms±62.098µs; 401 rows (400.216 RPS), 401 queries (400.216 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:27 loadtest: 399 transactions (400.014 TPS), latency 2.704319ms±66.653µs; 399 rows (400.014 RPS), 399 queries (400.014 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:28 loadtest: 400 transactions (400.007 TPS), latency 2.678214ms±82.92µs; 400 rows (400.007 RPS), 400 queries (400.007 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:29 loadtest: 400 transactions (400.001 TPS), latency 2.587556ms±62.625µs; 400 rows (400.001 RPS), 400 queries (400.001 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:30 loadtest: 400 transactions (400.012 TPS), latency 2.749635ms±97.975µs; 400 rows (400.012 RPS), 400 queries (400.012 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:31 loadtest: 401 transactions (400.254 TPS), latency 2.668717ms±73.097µs; 401 rows (400.254 RPS), 401 queries (400.254 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:32 loadtest: 400 transactions (400.482 TPS), latency 2.77041ms±110.822µs; 400 rows (400.482 RPS), 400 queries (400.482 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:33 loadtest: 399 transactions (400.231 TPS), latency 2.704758ms±67.137µs; 399 rows (400.231 RPS), 399 queries (400.231 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:34 loadtest: 400 transactions (399.928 TPS), latency 2.674862ms±105.268µs; 400 rows (399.928 RPS), 400 queries (399.928 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:35 loadtest: 400 transactions (400.215 TPS), latency 2.685478ms±73.623µs; 400 rows (400.215 RPS), 400 queries (400.215 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:36 loadtest: 401 transactions (400.238 TPS), latency 2.579905ms±81.608µs; 401 rows (400.238 RPS), 401 queries (400.238 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:37 loadtest: 399 transactions (399.872 TPS), latency 2.734158ms±120.292µs; 399 rows (399.872 RPS), 399 queries (399.872 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:38 loadtest: 400 transactions (399.583 TPS), latency 2.687819ms±108.748µs; 400 rows (399.583 RPS), 400 queries (399.583 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:39 loadtest: 400 transactions (400.314 TPS), latency 2.614716ms±77.28µs; 400 rows (400.314 RPS), 400 queries (400.314 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:40 loadtest: 400 transactions (400.233 TPS), latency 2.656976ms±63.685µs; 400 rows (400.233 RPS), 400 queries (400.233 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:41 loadtest: 400 transactions (400.133 TPS), latency 2.69999ms±92.963µs; 400 rows (400.133 RPS), 400 queries (400.133 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:42 loadtest: 400 transactions (400.017 TPS), latency 2.709958ms±98.395µs; 400 rows (400.017 RPS), 400 queries (400.017 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:43 loadtest: 401 transactions (400.459 TPS), latency 2.72622ms±79.96µs; 401 rows (400.459 RPS), 401 queries (400.459 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:44 loadtest: 399 transactions (399.452 TPS), latency 2.844344ms±83.937µs; 399 rows (399.452 RPS), 399 queries (399.452 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:45 loadtest: 400 transactions (399.730 TPS), latency 2.780827ms±79.245µs; 400 rows (399.730 RPS), 400 queries (399.730 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:46 loadtest: 400 transactions (399.830 TPS), latency 2.872106ms±117.871µs; 400 rows (399.830 RPS), 400 queries (399.830 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:47 loadtest: 400 transactions (400.086 TPS), latency 2.856609ms±120.137µs; 400 rows (400.086 RPS), 400 queries (400.086 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:48 loadtest: 401 transactions (400.219 TPS), latency 2.74299ms±68.793µs; 401 rows (400.219 RPS), 401 queries (400.219 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:49 loadtest: 400 transactions (400.436 TPS), latency 2.868848ms±118.388µs; 400 rows (400.436 RPS), 400 queries (400.436 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:50 loadtest: 399 transactions (400.406 TPS), latency 2.677646ms±82.958µs; 399 rows (400.406 RPS), 399 queries (400.406 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:51 loadtest: 400 transactions (400.129 TPS), latency 2.675353ms±102.978µs; 400 rows (400.129 RPS), 400 queries (400.129 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:52 loadtest: 400 transactions (400.245 TPS), latency 2.660248ms±68.027µs; 400 rows (400.245 RPS), 400 queries (400.245 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:53 loadtest: 401 transactions (400.527 TPS), latency 2.72573ms±83.998µs; 401 rows (400.527 RPS), 401 queries (400.527 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:54 loadtest: 399 transactions (400.358 TPS), latency 2.657858ms±73.844µs; 399 rows (400.358 RPS), 399 queries (400.358 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:55 loadtest: 400 transactions (400.255 TPS), latency 2.709039ms±104.752µs; 400 rows (400.255 RPS), 400 queries (400.255 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:56 loadtest: 400 transactions (399.563 TPS), latency 2.688911ms±84.964µs; 400 rows (399.563 RPS), 400 queries (399.563 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:57 loadtest: 400 transactions (400.368 TPS), latency 2.723232ms±83.914µs; 400 rows (400.368 RPS), 400 queries (400.368 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:58 loadtest: 400 transactions (400.024 TPS), latency 2.606399ms±76.911µs; 400 rows (400.024 RPS), 400 queries (400.024 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:01:59 loadtest: 400 transactions (399.695 TPS), latency 2.5795ms±85.192µs; 400 rows (399.695 RPS), 400 queries (399.695 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:00 loadtest: 400 transactions (400.472 TPS), latency 2.665817ms±80.786µs; 400 rows (400.472 RPS), 400 queries (400.472 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:01 loadtest: 401 transactions (400.433 TPS), latency 2.793262ms±116.917µs; 401 rows (400.433 RPS), 401 queries (400.433 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:02 loadtest: 399 transactions (400.082 TPS), latency 2.798382ms±96.262µs; 399 rows (400.082 RPS), 399 queries (400.082 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:03 loadtest: 399 transactions (398.479 TPS), latency 2.711352ms±89.018µs; 399 rows (398.479 RPS), 399 queries (398.479 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:04 loadtest: 400 transactions (399.874 TPS), latency 2.697788ms±91.168µs; 400 rows (399.874 RPS), 400 queries (399.874 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:05 loadtest: 400 transactions (399.752 TPS), latency 2.685775ms±87.223µs; 400 rows (399.752 RPS), 400 queries (399.752 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:06 loadtest: 401 transactions (400.215 TPS), latency 2.662836ms±92.851µs; 401 rows (400.215 RPS), 401 queries (400.215 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:07 loadtest: 399 transactions (400.408 TPS), latency 2.745812ms±88.301µs; 399 rows (400.408 RPS), 399 queries (400.408 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:08 loadtest: 400 transactions (400.227 TPS), latency 2.771454ms±98.509µs; 400 rows (400.227 RPS), 400 queries (400.227 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:09 loadtest: 400 transactions (400.096 TPS), latency 2.7924ms±83.884µs; 400 rows (400.096 RPS), 400 queries (400.096 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:10 loadtest: 400 transactions (400.468 TPS), latency 2.702199ms±94.798µs; 400 rows (400.468 RPS), 400 queries (400.468 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:11 loadtest: 400 transactions (400.212 TPS), latency 2.899485ms±98.371µs; 400 rows (400.212 RPS), 400 queries (400.212 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:12 loadtest: 400 transactions (400.231 TPS), latency 2.708003ms±82.409µs; 400 rows (400.231 RPS), 400 queries (400.231 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:13 loadtest: 400 transactions (399.729 TPS), latency 2.780875ms±96.953µs; 400 rows (399.729 RPS), 400 queries (399.729 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:14 loadtest: 400 transactions (399.803 TPS), latency 2.711184ms±96.705µs; 400 rows (399.803 RPS), 400 queries (399.803 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:15 loadtest: 400 transactions (400.196 TPS), latency 2.574301ms±68.985µs; 400 rows (400.196 RPS), 400 queries (400.196 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:16 loadtest: 400 transactions (399.620 TPS), latency 2.83232ms±144.192µs; 400 rows (399.620 RPS), 400 queries (399.620 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:17 loadtest: 400 transactions (399.948 TPS), latency 2.648861ms±80.693µs; 400 rows (399.948 RPS), 400 queries (399.948 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:18 loadtest: 400 transactions (400.112 TPS), latency 2.676634ms±98.498µs; 400 rows (400.112 RPS), 400 queries (400.112 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:19 loadtest: 400 transactions (399.842 TPS), latency 2.629239ms±89.088µs; 400 rows (399.842 RPS), 400 queries (399.842 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:20 loadtest: 400 transactions (399.926 TPS), latency 2.820157ms±127.176µs; 400 rows (399.926 RPS), 400 queries (399.926 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:21 loadtest: 400 transactions (400.243 TPS), latency 2.692968ms±88.264µs; 400 rows (400.243 RPS), 400 queries (400.243 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:22 loadtest: 401 transactions (400.398 TPS), latency 2.710088ms±110.86µs; 401 rows (400.398 RPS), 401 queries (400.398 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:23 loadtest: 399 transactions (400.382 TPS), latency 2.717839ms±86.668µs; 399 rows (400.382 RPS), 399 queries (400.382 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:24 loadtest: 400 transactions (400.334 TPS), latency 2.708336ms±67.156µs; 400 rows (400.334 RPS), 400 queries (400.334 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:25 loadtest: 401 transactions (400.135 TPS), latency 2.70689ms±85.976µs; 401 rows (400.135 RPS), 401 queries (400.135 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:26 loadtest: 399 transactions (400.314 TPS), latency 2.692469ms±98.799µs; 399 rows (400.314 RPS), 399 queries (400.314 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:27 loadtest: 400 transactions (399.941 TPS), latency 2.714934ms±96.436µs; 400 rows (399.941 RPS), 400 queries (399.941 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:28 loadtest: 400 transactions (400.076 TPS), latency 2.663081ms±69.01µs; 400 rows (400.076 RPS), 400 queries (400.076 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:29 loadtest: 400 transactions (400.446 TPS), latency 2.659525ms±79.569µs; 400 rows (400.446 RPS), 400 queries (400.446 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:30 loadtest: 400 transactions (400.284 TPS), latency 2.711554ms±89.347µs; 400 rows (400.284 RPS), 400 queries (400.284 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:31 loadtest: 400 transactions (400.088 TPS), latency 2.705537ms±91.07µs; 400 rows (400.088 RPS), 400 queries (400.088 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:32 loadtest: 400 transactions (399.492 TPS), latency 2.748982ms±95.058µs; 400 rows (399.492 RPS), 400 queries (399.492 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:33 loadtest: 400 transactions (399.972 TPS), latency 2.737268ms±68.067µs; 400 rows (399.972 RPS), 400 queries (399.972 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:34 loadtest: 400 transactions (399.721 TPS), latency 2.761394ms±97.447µs; 400 rows (399.721 RPS), 400 queries (399.721 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:35 loadtest: 400 transactions (399.969 TPS), latency 2.759919ms±91.973µs; 400 rows (399.969 RPS), 400 queries (399.969 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:36 loadtest: 400 transactions (399.976 TPS), latency 2.680421ms±93.796µs; 400 rows (399.976 RPS), 400 queries (399.976 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:37 loadtest: 401 transactions (399.987 TPS), latency 2.747201ms±88.388µs; 401 rows (399.987 RPS), 401 queries (399.987 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:38 loadtest: 399 transactions (400.235 TPS), latency 2.745088ms±111.087µs; 399 rows (400.235 RPS), 399 queries (400.235 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:39 loadtest: 400 transactions (400.011 TPS), latency 2.675917ms±62.758µs; 400 rows (400.011 RPS), 400 queries (400.011 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:40 loadtest: 400 transactions (399.631 TPS), latency 2.651182ms±126.692µs; 400 rows (399.631 RPS), 400 queries (399.631 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:41 loadtest: 400 transactions (399.432 TPS), latency 2.628968ms±68.499µs; 400 rows (399.432 RPS), 400 queries (399.432 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:42 loadtest: 401 transactions (400.096 TPS), latency 2.649603ms±83.982µs; 401 rows (400.096 RPS), 401 queries (400.096 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:43 loadtest: 399 transactions (400.423 TPS), latency 2.729863ms±108.817µs; 399 rows (400.423 RPS), 399 queries (400.423 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:44 loadtest: 400 transactions (400.374 TPS), latency 2.667599ms±88.775µs; 400 rows (400.374 RPS), 400 queries (400.374 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:45 loadtest: 400 transactions (400.065 TPS), latency 2.581114ms±85.257µs; 400 rows (400.065 RPS), 400 queries (400.065 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:46 loadtest: 401 transactions (400.182 TPS), latency 2.829439ms±106.512µs; 401 rows (400.182 RPS), 401 queries (400.182 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:47 loadtest: 400 transactions (400.454 TPS), latency 2.668791ms±67.368µs; 400 rows (400.454 RPS), 400 queries (400.454 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:48 loadtest: 400 transactions (400.524 TPS), latency 2.748846ms±102.818µs; 400 rows (400.524 RPS), 400 queries (400.524 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:49 loadtest: 399 transactions (399.688 TPS), latency 2.645942ms±90.864µs; 399 rows (399.688 RPS), 399 queries (399.688 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:50 loadtest: 400 transactions (399.698 TPS), latency 2.66552ms±93.436µs; 400 rows (399.698 RPS), 400 queries (399.698 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:51 loadtest: 400 transactions (400.340 TPS), latency 2.588099ms±63.898µs; 400 rows (400.340 RPS), 400 queries (400.340 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:52 loadtest: 400 transactions (399.881 TPS), latency 2.729305ms±96.521µs; 400 rows (399.881 RPS), 400 queries (399.881 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:53 loadtest: 400 transactions (400.184 TPS), latency 2.619113ms±66.819µs; 400 rows (400.184 RPS), 400 queries (400.184 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:54 loadtest: 401 transactions (400.130 TPS), latency 2.747448ms±82.185µs; 401 rows (400.130 RPS), 401 queries (400.130 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:55 loadtest: 400 transactions (400.398 TPS), latency 2.595019ms±90.833µs; 400 rows (400.398 RPS), 400 queries (400.398 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:56 loadtest: 399 transactions (400.171 TPS), latency 2.737354ms±110.676µs; 399 rows (400.171 RPS), 399 queries (400.171 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:57 loadtest: 400 transactions (399.211 TPS), latency 2.627181ms±64.988µs; 400 rows (399.211 RPS), 400 queries (399.211 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:58 loadtest: 399 transactions (400.032 TPS), latency 2.682408ms±92.421µs; 399 rows (400.032 RPS), 399 queries (400.032 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:02:59 loadtest: 400 transactions (399.326 TPS), latency 2.758259ms±96.419µs; 400 rows (399.326 RPS), 400 queries (399.326 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:00 loadtest: 400 transactions (399.726 TPS), latency 2.798764ms±127.726µs; 400 rows (399.726 RPS), 400 queries (399.726 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:01 loadtest: 400 transactions (399.451 TPS), latency 2.877134ms±80.349µs; 400 rows (399.451 RPS), 400 queries (399.451 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:02 loadtest: 400 transactions (399.566 TPS), latency 2.708244ms±92.333µs; 400 rows (399.566 RPS), 400 queries (399.566 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:03 loadtest: 400 transactions (400.179 TPS), latency 2.781563ms±85.043µs; 400 rows (400.179 RPS), 400 queries (400.179 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:04 loadtest: 400 transactions (399.811 TPS), latency 2.717806ms±98.593µs; 400 rows (399.811 RPS), 400 queries (399.811 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:05 loadtest: 401 transactions (400.331 TPS), latency 2.685886ms±78.91µs; 401 rows (400.331 RPS), 401 queries (400.331 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:06 loadtest: 400 transactions (400.425 TPS), latency 2.649127ms±78.582µs; 400 rows (400.425 RPS), 400 queries (400.425 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:07 loadtest: 399 transactions (399.721 TPS), latency 2.753245ms±98.185µs; 399 rows (399.721 RPS), 399 queries (399.721 QPS); 0 aborts (0.000%), latency 0s±0s
2021/10/06 12:03:07 stopping loadtest
2021/10/06 12:03:07 loadtest: 47597 transactions (399.975 TPS), latency 2.708477ms±8.447µs; 47597 rows (399.975 RPS), 47597 queries (399.975 QPS); 0 aborts (0.000%), latency 0s±0s
Transactions:
  1.048576ms -   2.097152ms [  3684]: ████▎
  2.097152ms -   4.194304ms [ 42890]: ██████████████████████████████████████████████████
  4.194304ms -   8.388608ms [   871]: █
  8.388608ms -  16.777216ms [   152]: ▏
2021/10/06 12:03:07 Performing teardown

@antiguru
Copy link
Member Author

antiguru commented Oct 6, 2021

Setting the threshold to 64 batches seems to have a beneficial effect:

2021/10/06 12:15:25 loadtest: 47599 transactions (399.994 TPS), latency 2.58097ms±7.883µs; 47599 rows (399.994 RPS), 47599 queries (399.994 QPS); 0 aborts (0.000%), latency 0s±0s
Transactions:
  1.048576ms -   2.097152ms [  6407]: ███████▉
  2.097152ms -   4.194304ms [ 40354]: ██████████████████████████████████████████████████
  4.194304ms -   8.388608ms [   737]: ▉
  8.388608ms -  16.777216ms [   101]: ▏

This would increase memory consumption to 64*8KiB=512KiB per log and worker before the replay operator would be triggered.

@antiguru antiguru added this to In progress in Compute via automation Oct 6, 2021
@antiguru antiguru added A-dataflow Area: dataflow T-memory Theme: memory T-performance Theme: performance improvements labels Oct 6, 2021
Copy link
Contributor

@frankmcsherry frankmcsherry left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this mostly looks good, with the caveat that the build in delaying mechanism is probably non-obvious enough to want to fix up before pushing anywhere else. I can see the goal there, but I wonder if there is a cleaner way to do it (e.g. have the logger receive buffers, and notify at a threshold number of events rather than number of calls).

Comment on lines +45 to +65
/// Acknowledge the activation, which enables new activations to be scheduled.
pub fn ack(&mut self) {
self.inner.borrow_mut().ack()
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Most timely activators do not have this. Is there an explainer for why this is important, and how to use it correctly?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe relatedly, looking at the use, is this important to cause the delaying, or could one just count up, and activate every 32 (or whatever) calls to activate, and reset the counter on each activation? It seems like this allows a pre-emptive resetting, which .. could be helpful in preventing some spurious activations but probably no more than the native activations (i.e. once per second).

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is important that once the operator has been activated, we do not activate it again until it was scheduled. Without this mechanism, we tend to queue activations, which potentially cause more work to consolidate but do not trigger additional or earlier activations. This seems to be an anti-pattern, but is safer in that it doesn't try to put more load on the system once it is under load.

}

impl ActivatorInner {
const THRESHOLD: usize = 32;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seems to be an important part of the explanation, I think. Like, "you shouldn't expect an activation unless you activate this many times". I can see why that is useful in our code, but it seems a bit opaque and mysterious. If it's an important concept, maybe promote it to a struct member and make it part of the new() call?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I changed the PR to expose the parameter and make it part of the new() call. Also added more documentation to describe what its purpose is.

antiguru and others added 4 commits October 7, 2021 15:07
Currently, the logging dataflows activate once every introspection
interval to process data. This can cause a significant buildup of data
before it is processed.

In addition to activating the replay operator periodically, also
activate it once a sufficient amount of data has been accumulated.
Ideally, the data processing should be activated as soon as some data is
available, but this could cause a situation where activating causes
additional data to be produced.

For this reason, the dataflow activates after 32 batches have been
published by the logging infrastructure. This seems to be a reasonable
trade-off between memory (currently at most 8KiB per batch) and latency.

The time-based activation is still required in case there is no data for
a specific dataflow. In this case, we still need to advance the clock,
which the time-based activation takes care of.

Signed-off-by: Moritz Hoffmann <mh@materialize.com>
Signed-off-by: Moritz Hoffmann <mh@materialize.com>
Signed-off-by: Moritz Hoffmann <mh@materialize.com>
Signed-off-by: Moritz Hoffmann <mh@materialize.com>
@antiguru
Copy link
Member Author

antiguru commented Oct 7, 2021

I wonder if there is a cleaner way to do it (e.g. have the logger receive buffers, and notify at a threshold number of events rather than number of calls).

The underlying log infrastructure tries to make sure that log buffers are limited in size by 8KiB, but they can be smaller. I'd like to keep the intuition that the number of published buffers corresponds to a size in memory rather than a number of elements, which the current approach fulfills.

@antiguru antiguru merged commit e890114 into MaterializeInc:main Oct 7, 2021
Compute automation moved this from In progress to Done Oct 7, 2021
@antiguru antiguru deleted the logging_activated branch October 29, 2021 08:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-dataflow Area: dataflow T-memory Theme: memory T-performance Theme: performance improvements
Projects
No open projects
Development

Successfully merging this pull request may close these issues.

Logging operators are only scheduled at introspection intervals, causing state to build up
2 participants