Add scripts to fully automate debezium/perf testing.

[jcferretti]

Example:

cd debezium/perf
./run_experiment.sh dh 5000 20 10 1.0

Will run an experiment for deephaven (tag dh; pass tag mz for materialize) with a rate of 5,000 pageviews per second. It will wait 20 seconds after setting the rate to begin sampling CPU and memory utilization using top in batch mode. 10 samples will be obtained, with a delay between samples of 1.0 seconds.

Output and logs for eeeeeeverything (docker compose log, top details, top samples, dt_ms delays sampled in engine while test is running) are left under the logs directory. One subdirectory under logs is created per run_experiment.sh execution, with all the log files for a single run in their own sub-directory for that run, eg:

cfs@erke 00:53:23 ~/dh/oss3/deephaven-core/debezium/perf
$ ls logs/
2022.03.22.04.30.28_UTC_mz_50    2022.03.22.04.35.09_UTC_mz_35000  2022.03.22.04.45.51_UTC_dh_5000   2022.03.22.04.49.45_UTC_dh_100000  2022.03.22.04.52.11_UTC_dh_160000
2022.03.22.04.33.49_UTC_mz_5000  2022.03.22.04.41.47_UTC_dh_50     2022.03.22.04.47.05_UTC_dh_35000  2022.03.22.04.50.58_UTC_dh_145000

cfs@erke 00:55:26 ~/dh/oss3/deephaven-core/debezium/perf
$ ls logs/2022.03.22.04.52.11_UTC_dh_160000
2022.03.22.04.52.43_UTC_dh_sample_dt.log  2022.03.22.04.53.04_EDT_top_details.log  2022.03.22.04.53.04_EDT_top_samples.log  docker-compose.log  start.log

cfs@erke 00:55:32 ~/dh/oss3/deephaven-core/debezium/perf
$ cat logs/2022.03.22.04.52.11_UTC_dh_160000/2022.03.22.04.53.04_EDT_top_samples.log
name=deephaven, tag=CPU_PCT, mean=174.55, samples=133.3, 115.8, 228.0, 126.0, 153.0, 160.0, 133.0, 168.0, 255.4, 273.0
name=deephaven, tag=RES_GiB, mean=5.77, samples=5.6, 5.6, 5.7, 5.7, 5.8, 5.8, 5.8, 5.9, 5.9, 5.9
name=redpanda, tag=CPU_PCT, mean=85.13, samples=80.0, 87.1, 84.0, 89.0, 85.0, 86.0, 87.0, 88.0, 82.2, 83.0
name=redpanda, tag=RES_GiB, mean=1.18, samples=1.1, 1.1, 1.1, 1.2, 1.2, 1.2, 1.2, 1.2, 1.2, 1.3

cfs@erke 00:55:58 ~/dh/oss3/deephaven-core/debezium/perf
$ cat logs/2022.03.22.04.52.11_UTC_dh_160000/2022.03.22.04.52.43_UTC_dh_sample_dt.log
timestamp=2022-03-22T04:52:44.309627+00:00, total=815, max_received_at=2022-03-22T00:52:44.000000000 NY, dt_ms=307.89
timestamp=2022-03-22T04:52:46.290729+00:00, total=109679, max_received_at=2022-03-22T00:52:45.000000000 NY, dt_ms=1006.389
timestamp=2022-03-22T04:52:47.987919+00:00, total=409944, max_received_at=2022-03-22T00:52:46.000000000 NY, dt_ms=1591.089
timestamp=2022-03-22T04:52:49.721161+00:00, total=702507, max_received_at=2022-03-22T00:52:48.000000000 NY, dt_ms=1409.57
timestamp=2022-03-22T04:52:51.169180+00:00, total=971331, max_received_at=2022-03-22T00:52:50.000000000 NY, dt_ms=967.83
timestamp=2022-03-22T04:52:52.681980+00:00, total=1201189, max_received_at=2022-03-22T00:52:51.000000000 NY, dt_ms=1405.783
timestamp=2022-03-22T04:52:53.862047+00:00, total=1412028, max_received_at=2022-03-22T00:52:53.000000000 NY, dt_ms=707.464
timestamp=2022-03-22T04:52:54.842203+00:00, total=1585155, max_received_at=2022-03-22T00:52:54.000000000 NY, dt_ms=700.582
timestamp=2022-03-22T04:52:55.830672+00:00, total=1747439, max_received_at=2022-03-22T00:52:55.000000000 NY, dt_ms=642.255
timestamp=2022-03-22T04:52:56.777560+00:00, total=1907802, max_received_at=2022-03-22T00:52:56.000000000 NY, dt_ms=651.736
timestamp=2022-03-22T04:52:57.720971+00:00, total=2064241, max_received_at=2022-03-22T00:52:57.000000000 NY, dt_ms=574.986
timestamp=2022-03-22T04:52:58.879020+00:00, total=2222055, max_received_at=2022-03-22T00:52:58.000000000 NY, dt_ms=704.596
timestamp=2022-03-22T04:52:59.744292+00:00, total=2379990, max_received_at=2022-03-22T00:52:59.000000000 NY, dt_ms=626.779
timestamp=2022-03-22T04:53:00.726564+00:00, total=2538962, max_received_at=2022-03-22T00:53:00.000000000 NY, dt_ms=647.509
timestamp=2022-03-22T04:53:01.741872+00:00, total=2696045, max_received_at=2022-03-22T00:53:01.000000000 NY, dt_ms=642.178
timestamp=2022-03-22T04:53:02.765281+00:00, total=2857195, max_received_at=2022-03-22T00:53:02.000000000 NY, dt_ms=629.699
timestamp=2022-03-22T04:53:03.767569+00:00, total=3015750, max_received_at=2022-03-22T00:53:03.000000000 NY, dt_ms=638.359
timestamp=2022-03-22T04:53:04.739523+00:00, total=3176300, max_received_at=2022-03-22T00:53:04.000000000 NY, dt_ms=611.571
timestamp=2022-03-22T04:53:05.754946+00:00, total=3334029, max_received_at=2022-03-22T00:53:05.000000000 NY, dt_ms=610.89
timestamp=2022-03-22T04:53:06.771903+00:00, total=3485308, max_received_at=2022-03-22T00:53:06.000000000 NY, dt_ms=639.887
timestamp=2022-03-22T04:53:07.803041+00:00, total=3654084, max_received_at=2022-03-22T00:53:07.000000000 NY, dt_ms=656.77
timestamp=2022-03-22T04:53:08.806292+00:00, total=3809334, max_received_at=2022-03-22T00:53:08.000000000 NY, dt_ms=689.275
timestamp=2022-03-22T04:53:09.760774+00:00, total=3966717, max_received_at=2022-03-22T00:53:09.000000000 NY, dt_ms=643.09
timestamp=2022-03-22T04:53:10.778483+00:00, total=4125600, max_received_at=2022-03-22T00:53:10.000000000 NY, dt_ms=659.709
timestamp=2022-03-22T04:53:12.088984+00:00, total=4284969, max_received_at=2022-03-22T00:53:11.000000000 NY, dt_ms=946.283
timestamp=2022-03-22T04:53:13.137217+00:00, total=4468803, max_received_at=2022-03-22T00:53:12.000000000 NY, dt_ms=927.123
timestamp=2022-03-22T04:53:14.114280+00:00, total=4640684, max_received_at=2022-03-22T00:53:13.000000000 NY, dt_ms=985.271

cfs@erke 00:58:16 ~/dh/oss3/deephaven-core/debezium/perf
$ grep 'ycle' logs/2022.03.22.04.52.11_UTC_dh_160000/docker-compose.log | tail -n 5
server_1        | 2022-03-22T04:53:10.189Z | EFAULT.refreshThread |  INFO | .e.u.UpdateGraphProcessor | Update Graph Processor cycleTime=822.011596ms, lockWaitTime=0.257218ms, yieldTime=0.0ms, sleepTime=0.0ms
server_1        | 2022-03-22T04:53:11.226Z | EFAULT.refreshThread |  INFO | .e.u.UpdateGraphProcessor | Update Graph Processor cycleTime=858.911646ms, lockWaitTime=0.249392ms, yieldTime=0.0ms, sleepTime=0.0ms
server_1        | 2022-03-22T04:53:12.531Z | EFAULT.refreshThread |  INFO | .e.u.UpdateGraphProcessor | Update Graph Processor cycleTime=1163.408291ms, lockWaitTime=0.106879ms, yieldTime=0.0ms, sleepTime=0.0ms
server_1        | 2022-03-22T04:53:13.621Z | EFAULT.refreshThread |  INFO | .e.u.UpdateGraphProcessor | Update Graph Processor cycleTime=1055.980283ms, lockWaitTime=0.199678ms, yieldTime=0.0ms, sleepTime=0.0ms
server_1        | 2022-03-22T04:53:14.353Z | EFAULT.refreshThread |  INFO | .e.u.UpdateGraphProcessor | Update Graph Processor cycleTime=731.680506ms, lockWaitTime=0.238769ms, yieldTime=0.0ms, sleepTime=0.0ms

Example output when running run_experiment.sh:

cfs@erke 00:30:26 ~/dh/oss3/deephaven-core/debezium/perf
$ ./run_experiment.sh mz 50 20 10 1.0
Starting compose and waiting for simulation to start.
Compose start done.
PERF_TAG=2022.03.22.04.30.28_UTC_mz_50
Running demo in engine and sampling delays.
Creating core-debezium-perf_mzcli_run ... done
CREATE SOURCE
CREATE SOURCE
CREATE SOURCE
CREATE SOURCE
CREATE VIEW
CREATE VIEW
CREATE VIEW
CREATE VIEW
CREATE VIEW
CREATE VIEW
CREATE VIEW
CREATE SOURCE
CREATE VIEW
CREATE VIEW
CREATE SINK
CREATE SOURCE
CREATE VIEW
Setting pageviews per second
LOADGEN Connected.
Setting pageviews_per_second: old value was 50, new value is 50.
Goodbye.
Waiting for 20 seconds...
Sampling top.
name=redpanda, tag=CPU_PCT, mean=88.14, samples=93.3, 86.0, 87.0, 87.0, 85.1, 87.0, 92.0, 92.0, 86.0, 86.0
name=redpanda, tag=RES_GiB, mean=0.75, samples=0.755, 0.755, 0.755, 0.755, 0.755, 0.755, 0.755, 0.755, 0.755, 0.755
name=materialize, tag=CPU_PCT, mean=30.60, samples=33.3, 29.0, 28.0, 31.0, 29.7, 30.0, 31.0, 31.0, 31.0, 32.0
name=materialize, tag=RES_GiB, mean=0.16, samples=0.1565, 0.1565, 0.156, 0.1565, 0.1566, 0.1566, 0.1564, 0.1568, 0.1568, 0.1573
Stopping compose.
Stopping core-debezium-perf_loadgen_1      ... done
Stopping core-debezium-perf_debezium_1     ... done
Stopping core-debezium-perf_materialized_1 ... done
Stopping core-debezium-perf_redpanda_1     ... done
Stopping core-debezium-perf_mysql_1        ... done
Stopping core-debezium-perf_mzcli_run_bba6d1ec5f46 ... done
Removing core-debezium-perf_mzcli_run_bba6d1ec5f46 ... done
Removing core-debezium-perf_mzcli_run_54141b216bf9 ... done
Removing core-debezium-perf_loadgen_1              ... done
Removing core-debezium-perf_debezium_1             ... done
Removing core-debezium-perf_materialized_1         ... done
Removing core-debezium-perf_redpanda_1             ... done
Removing core-debezium-perf_mysql_1                ... done
Removing core-debezium-perf_mzcli_1                ... done
Removing network core-debezium-perf_default
Experiment finished.