Now that we have ~20 minutes of tests, it's good to know _why_ the tests
take ~20 minutes, and if this time is being spent well.
This adds the field test_time to test.py's -o/--output, which reports
the runtime of each test in seconds. This can be organized by suite,
case, etc, with our existing csv scripts.
Note I've limited the precision to only milliseconds (%.6f).
Realistically, this is plenty of precision, and with the number of tests
we have extra digits can really add up!
lines bytes
test.csv before: 525593 58432541 56MiB
test.csv full precision: 525593 (+0.0%) 69817693 67MiB (+19.5%)
test.csv milli precision: 525593 (+0.0%) 63162935 60MiB (+8.1%)
It still takes a bit of time to process this (50.3s), but now we can see
the biggest culprits of our ~20 minute test time:
$ ./scripts/summary.py test.csv -bcase -ftest_time -S
case test_time
...
test_fwrite_hole_compaction 74.4
test_fwrite_incr 109.7
test_dirs_mkdir_fuzz 115.3
test_fwrite_overwrite_compaction 132.4
test_rbyd_fuzz_append_removes 134.0
test_rbyd_fuzz_mixed 136.3
test_rbyd_fuzz_sparse 137.4
test_fwrite_w_seek 144.1
test_rbyd_fuzz_create_deletes 144.8
test_dirs_rm_many_backwards 208.4
test_dirs_rm_many 273.8
test_fwrite_fuzz_unaligned 283.2
test_dread_recursive_rm 316.7
test_fwrite_fuzz_aligned 551.0
test_dirs_general_fuzz 552.8
test_dirs_rm_fuzz 632.7
test_fwrite_reversed 719.0
test_dirs_mv_fuzz 1984.8
TOTAL 7471.3
Note this machine has 6 cores, 12 hthreads, 7471.3/60/6 => 20.8m, which
is why I don't run these tests single threaded.
Christopher Haster
a5fe2706bd