Describe the bug
.github/benchmark/compare-opendj.sh prints the distinct errors of each benchmark side to the step log. It
splits the JMeter result file with a plain awk -F',':
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)"
The JTL is CSV, and JMeter quotes any responseMessage that contains a comma. awk does not understand the
quoting. Every comma inside the message shifts the columns after it to the right, so $h["success"] reads the
dataType column (text) or something later. The row is never matched, and the failure never reaches the log.
The rows that get lost are the ones that matter most:
Evidence
The same filter, run on the benchmark-pdb-vs-je artifacts, against the number of ,false, rows:
| Run |
Side |
Failed rows |
Printed by the script |
| 36845050319 |
PDB |
12 |
2 BIND | 49 | Invalid Credentials |
| 36738515054 |
PDB |
5 145 |
5131 BIND | 800 | ... connection has been closed, 2 BIND | 49 | Invalid Credentials |
In both runs the 10–12 rows that hold the cause are missing. Six or eight are result 80 from PDBStorage, and
four are result 32 from COMPARE and MODIFY. The log keeps only BIND 49, which is the last consequence of a
failed ADD, so it points the reader at authentication instead of at the backend. That is how #1149 went unnoticed
from 11.09 to 01.10.
The err columns of the step summary are not affected. summary.sh reads them from JMeter's
statistics.json, so the counts there are correct. Only the step log, which carries the messages, is wrong.
Second, smaller problem: messages are grouped verbatim
uniq -c groups on the full message, but these messages carry per-row values: the elapsed milliseconds in the
result-80 message and the entry DN in the result-32 ones. Even once the rows are parsed correctly, each of them
would print as a separate line with count 1, and head -10 would cut off whatever comes after the first ten.
Replacing digits (or at least the DN and the timing) before grouping keeps one line per kind of failure.
What it needs
Parse the JTL with a CSV-aware reader, for example a few lines of python3 -c 'import csv ...', which is present
on the ubuntu-latest runners. Normalize the variable parts before counting. A quick check: run the step
against the artifacts above. The PDB side has to show result 80 and result 32, not just BIND 49.
.github/workflows/benchmark.yml (OpenLDAP vs OpenDJ) uploads its *.jtl files but does not parse them, so it
is not affected.
Related
Describe the bug
.github/benchmark/compare-opendj.shprints the distinct errors of each benchmark side to the step log. Itsplits the JMeter result file with a plain
awk -F',':The JTL is CSV, and JMeter quotes any
responseMessagethat contains a comma. awk does not understand thequoting. Every comma inside the message shifts the columns after it to the right, so
$h["success"]reads thedataTypecolumn (text) or something later. The row is never matched, and the failure never reaches the log.The rows that get lost are the ones that matter most:
pdb: backend 'userRoot' did not apply the transaction after 10 attempts in 2830 ms, the attempt cap being spent; ...(result 80, PDBStorage.write() fails ordinary concurrent ADD/DELETE with result 80: the attempt cap from #937 is spent under single-suffix write load #1149)
The specified entry mail=u_12_7@test.com,ou=People,dc=example,dc=com does not exist in the Directory Server(result 32). Every message that names a DN contains commas.
Evidence
The same filter, run on the
benchmark-pdb-vs-jeartifacts, against the number of,false,rows:2 BIND | 49 | Invalid Credentials5131 BIND | 800 | ... connection has been closed,2 BIND | 49 | Invalid CredentialsIn both runs the 10–12 rows that hold the cause are missing. Six or eight are result 80 from
PDBStorage, andfour are result 32 from COMPARE and MODIFY. The log keeps only
BIND 49, which is the last consequence of afailed ADD, so it points the reader at authentication instead of at the backend. That is how #1149 went unnoticed
from 11.09 to 01.10.
The
errcolumns of the step summary are not affected.summary.shreads them from JMeter'sstatistics.json, so the counts there are correct. Only the step log, which carries the messages, is wrong.Second, smaller problem: messages are grouped verbatim
uniq -cgroups on the full message, but these messages carry per-row values: the elapsed milliseconds in theresult-80 message and the entry DN in the result-32 ones. Even once the rows are parsed correctly, each of them
would print as a separate line with count 1, and
head -10would cut off whatever comes after the first ten.Replacing digits (or at least the DN and the timing) before grouping keeps one line per kind of failure.
What it needs
Parse the JTL with a CSV-aware reader, for example a few lines of
python3 -c 'import csv ...', which is presenton the
ubuntu-latestrunners. Normalize the variable parts before counting. A quick check: run the stepagainst the artifacts above. The PDB side has to show result 80 and result 32, not just BIND 49.
.github/workflows/benchmark.yml(OpenLDAP vs OpenDJ) uploads its*.jtlfiles but does not parse them, so itis not affected.
Related