[#1150] Read the benchmark JTL with a CSV parser, so that an error whose message holds a comma reaches the step log (#1151)
Fixes #1150
### Problem
`compare-opendj.sh` listed the errors of each benchmark side with `awk
-F','`. JMeter quotes a `responseMessage`
that contains a comma, and every message naming a DN does, so the
columns after it shifted and such rows were
never matched as failures. On the PDB side this hid the result-80 and
result-32 rows of #1149 and left only
`BIND | 49`, the last consequence of a failed ADD.
### Change
The error listing in `bench_one` now reads the JTL with `python3`'s
`csv` module, which is already used by the
same Docker jobs in `build.yml`.
- Failures are grouped by operation, result code and message, with
digits in the message replaced by `N`. The
messages carry the entry DN or the elapsed milliseconds, and without
this each failed row would be a kind of its
own.
- The step log shows the number of failed rows and kinds of error, the
ten most frequent kinds and, when there are
more, how many are left out.
- The listing still goes to stderr, because stdout of `bench_one`
carries the server version. `|| true` keeps a
failure of the listing from stopping the benchmark.
The `err` columns of the step summary come from `statistics.json`
through `summary.sh` and are unchanged.
### Verification
The block, cut verbatim from the script, run on the
`benchmark-pdb-vs-je` artifacts named in the issue:
| JTL | Before (awk) | After |
|---|---|---|
|
[36845050319](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/36845050319),
PDB | `2 BIND \| 49` | 12 failed rows, 6 kinds of error:
DELETE/ADD/READD 80, COMPARE/MODIFY 32, BIND 49 |
|
[36738515054](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/36738515054),
PDB | `5131 BIND \| 800`, `2 BIND \| 49` | 5145 failed rows, 7 kinds of
error, with the 80 and 32 rows present |
| JE side and both build-vs-release runs | nothing | nothing (no failed
rows) |
Output for run 36845050319, PDB:
```
[b] 12 failed rows, 6 kinds of error (count | op | code | message):
3 DELETE | 80 | pdb: backend 'userRoot' did not apply the transaction after N attempts in N ms, the attempt cap being spent; the last conflict was com.persistit.exception.RollbackException
2 ADD | 80 | pdb: backend 'userRoot' did not apply the transaction after N attempts in N ms, the attempt cap being spent; the last conflict was com.persistit.exception.RollbackException
2 COMPARE | 32 | The specified entry mail=u_N_N@test.com,ou=People,dc=example,dc=com does not exist in the Directory Server
2 MODIFY | 32 | Entry mail=u_N_N@test.com,ou=People,dc=example,dc=com cannot be modified because no such entry exists in the server
2 BIND | 49 | Invalid Credentials
1 READD | 80 | pdb: backend 'userRoot' did not apply the transaction after N attempts in N ms, the attempt cap being spent; the last conflict was com.persistit.exception.RollbackException
```
A synthetic JTL with 13 kinds of error, messages holding commas and one
message spanning two lines printed ten
kinds and `... 3 more kinds not shown`. When the JTL is missing or
malformed, the block exits with 0. In every case
nothing was written to stdout. `bash -n` passes.
#1145 edits the same file in a different place (the `sysctl` near the
top), so the two do not conflict.
| | |
| | | -Jjmeter.reportgenerator.sample_filter='^(?!ADMIN_CONNECT).*' \ |
| | | -l "$out.jtl" -e -o "$out" > "$out.jmeter.out" 2>&1 || true |
| | | docker logs opendj-bench > "$out.docker.log" 2>&1 || true |
| | | # surface distinct error messages to the step log (stderr; stdout carries the version) |
| | | # surface distinct error messages to the step log (stderr; stdout carries the version). |
| | | # The JTL is CSV and JMeter quotes a message that holds a comma (every DN does), so it is |
| | | # read with a CSV parser. Digits are replaced before grouping: the messages carry the entry |
| | | # DN or the elapsed time, and verbatim each failed row would be a kind of its own. |
| | | if [ -f "$out.jtl" ]; then |
| | | local errs |
| | | errs="$(awk -F',' 'NR==1{for(i=1;i<=NF;i++)h[$i]=i; next} |
| | | tolower($h["success"])=="false"{print $h["label"]" | "$h["responseCode"]" | "$h["responseMessage"]}' \ |
| | | "$out.jtl" 2>/dev/null | sort | uniq -c | sort -rn | head -10)" |
| | | [ -z "$errs" ] || { echo "[$out] errors (count | op | code | message):" >&2; echo "$errs" >&2; } |
| | | python3 - "$out.jtl" "$out" >&2 <<'PY' || true |
| | | import collections, csv, re, sys |
| | | kinds = collections.Counter() |
| | | with open(sys.argv[1], newline='') as f: |
| | | for r in csv.DictReader(f): |
| | | if r['success'].strip().lower() == 'false': |
| | | kinds[r['label'], r['responseCode'].strip(), |
| | | re.sub(r'\d+', 'N', r['responseMessage'].strip())] += 1 |
| | | if kinds: |
| | | print('[%s] %d failed rows, %d kinds of error (count | op | code | message):' |
| | | % (sys.argv[2], sum(kinds.values()), len(kinds))) |
| | | for (label, code, message), n in kinds.most_common(10): |
| | | print('%7d %s | %s | %s' % (n, label, code, message)) |
| | | if len(kinds) > 10: |
| | | print('%7s %d more kinds not shown' % ('...', len(kinds) - 10)) |
| | | PY |
| | | fi |
| | | else |
| | | echo "ERROR: failed to start image $image" >&2 |