Notes on fdatasync for the test suite

[John Arbash Meinel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 08/26/2011 04:06 PM, John Arbash Meinel wrote:
> I've been feeling the pain of how slow our test suite has been lately,
> and I figured I'd poke around a bit if I could.
> 


I have a test suite run with timings for both a 2.3 branch and a 2.4
branch with fdatasync disabled (and one with it enabled). However, the
2.3 run took surprisingly longer than 2.4.
I wrote a script to make it easier to compare the individual test runs
by lining them up and comparing the run time. And every so often I see
just a huge spike in the 2.3 time. For example:

...TestLogEncodings.test_stdout_encoding                      237 > 155
...TestLogErrors.test_log_bad_message_re                      143 > 74
...TestLogErrors.test_log_change_incompatible_with_revision    32 > 7
...TestLogErrors.test_log_change_nonexistent_dotted_revno     147 > 71
...TestLogErrors.test_log_change_nonexistent_revno            143 > 71
...TestLogErrors.test_log_change_single_revno_only            118 > 65
...TestLogErrors.test_log_exclude_ancestry_no_range           249 > 142

...TestLogErrors.test_log_exclude_ancestry_single_revision   1363 > 344

...TestLogErrors.test_log_nonexistent_dotted_revno            191 > 74
...TestLogErrors.test_log_nonexistent_file                    208 > 76
...TestLogErrors.test_log_nonexistent_revno                   193 > 69

...TestLogErrors.test_log_reversed_dotted_revspecs           1159 > 351

...TestLogErrors.test_log_reversed_revspecs                   389 > 171
...TestLogErrors.test_log_unsupported_timezone                283 > 206
...TestLogErrors.test_log_zero_begin_revspec                  297 > 217
...TestLogErrors.test_log_zero_end_revspec                    274 > 203
...TestLogErrors.test_log_zero_revspec                        162 > 70
...TestLogExcludeCommonAncestry.test_exclude_common_ancestry_ 301 > 145
...TestLogFile.test_log_file1                                 752 > 348

...TestLogFile.test_log_file2                                1142 > 434

...TestLogFile.test_log_file3                                 722 > 337
...TestLogFile.test_log_file_historical_end                   865 > 459
...TestLogFile.test_log_file_historical_missing               830 > 473
...TestLogFile.test_log_file_historical_start                 856 < 939
...TestLogFile.test_log_file_renamed                         1282 > 1026

Just a test that suddenly runs in >1s where everything else is sub
second. I have another test run with fdatasync on, and things look quite
a bit worse.

But the fact that every-so-often we get a big spike in the run time
seems odd. But it might be because there are other processes running? (I
think Martin mentioned the machine is shared with U1).

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAk5eYIEACgkQJdeBCYSNAANb2ACgglTjl/5EoFQPqKqHfTp3Jied
/BYAn2uDZQ3SUGtXAdMA3TjbHeNCZGwr
=Iv3E
-----END PGP SIGNATURE-----