Use subshell to:
- avoid change/restore of TIMEFORMAT
- grepping out trace output, by using set +x in a subshell
- use array for options to avoid extra backslashes
Do not stop processing pathologically slow queries,
since this may hide errors in other queries,
i.e. when the test failed on one of servers (upstream or from PR)
and someone interpret this is as OK with the following comment:
"the failure was on the upstream server it is OK, PR should fix it"
Anyway there is almost zero such queries right now, and before merging
something this should be reviewed.
killall requires strict match, i.e. "clickhouse-server" not
"clickhouse":
2021-12-03 05:24:56 + env kill -- -21700
2021-12-03 05:24:56 kill: (-21700): No such process
2021-12-03 05:24:56 + killall clickhouse
2021-12-03 05:24:56 clickhouse: no process found
2021-12-03 05:24:56 + echo Servers stopped.
2021-12-03 05:24:56 Servers stopped.
2021-12-03 05:24:56 + analyze_queries
$ tail -n1 *-server-log.log
==> left-server-log.log <==
2021.12.03 05:26:59.530647 [ 450 ] {} <Trace> SystemLog (system.asynchronous_metric_log): Flushed system log up to offset 1668052
==> right-server-log.log <==
2021.12.03 05:27:20.873136 [ 466 ] {} <Trace> SystemLog (system.metric_log): Flushed system log up to offset 9605
==> setup-server-log.log <==
2021.12.03 02:47:14.844395 [ 96 ] {} <Information> Application: Child process exited normally with code 0.
As you can see killall instantly fails with no such process, while this
cannot be true since it was there, and also according to logs there were
messages after running analyze_queries() from compare.sh
This should fix problems like in [1].
[1]: https://clickhouse-test-reports.s3.yandex.net/32080/344298f4037f88b114b8e798bb30036b24be8f16/performance_comparison/report.html#fail1
trace_log/query_log from performance tests shows (for
cases when prewarm query fails with timeout, 15sec) excessive
writeTraceInfo() in trace_log and QueryProfilerRuns in query_log, but
this is not the root cause of the timeout, but consequence.
Also query_log shows that on failures the following profile events has
significantly higher values:
- PerfLocalMemoryMisses (6.3x more)
- PerfLocalMemoryReferences (7x more)
- PerfDataTLBMisses (6.9x more)
- PerfInstructionTLBMisses (6.4x more)
During looking at performance tests logs I noticed that once the prewarm
query fails other server (left/right) was merging (MergeTree) something
in *_log tables.
But, using MergeTree for *_log in performance tests is useless, since
anyway environment for performance tests uses ramdrive.
And so MergeTree merges just increase overhead.
Eventually I expect that this should decrease extra memory referencing
and so this should decrease cache/TLB misses.
CI: https://clickhouse-test-reports.s3.yandex.net/30886/c504e0c08df7a926bb479a1d297f326f5c48a32f/performance_comparison/report.html#fail1
v2: <partition_by remove="remove"/>
Before this patch:
- upstream/master and PR's *with* perf tests or pef scripts changes:
--runs=13 --max-queries=0
- PRs *without* perf changes:
--runs=7 --max-queries=20
- PRs w/ only perf tests changes:
--runs-13 --max-queries=0 <list of perf tests>
After:
- upstream/master and PR's *with* perf tests changes:
--runs=13 --max-queries=0
- PRs *without* perf changes:
--runs=7 --max-queries=10
- PRs w/ only perf tests changes:
--runs-13 --max-queries=0 <list of perf tests>
So to underline, now we will not look at perf scripts changes anymore,
and we will also decrease number of random queries to run to 10.
Reading files using mmap() does not have any significant benefits over
plain read() [1].
[1]: https://gist.github.com/azat/3d6c8d82bdd91e7a38d997fd6bcfd574
And not only it does not have significant benefits, it also has some
issues, due to max_server_memory_usage (default to 90% of available
RAM), since when you read files with mmap() eventually process RSS may
exceed max_server_memory_usage, and in this case any allocation will
fail (with "Memory limit exceeded (total)") error (yes kernel will
unload pages, but likely it will happens after queries will starting to
fail), like in this test [2].
[2]: https://gist.github.com/azat/4813489828162e6c2ce131963c6a1acb
TL;DR;
Note that there was also an idea to take those mmap()'ed regions in
memory tracking (#23211), but there are some drawbacks (since accounting
mmap() is tricky, first of all you need to account only once per inode
for file and plus kernel can unload some pages and those memory will not
be used by the server anymore).
And as an adddition to #23211 there was #23212, that adds
max_bytes_to_use_mmap_io, but since mmap is not a subject for memory
accounting there is no need in it.