Notes on fdatasync for the test suite

[vila]

>>>>> John Arbash Meinel <john at arbash-meinel.com> writes:

    > 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).

Some more data points from that 'make check timings' patch landed on
bzr.dev *only* at revno 6120. This patch output time UTC stamps before
and after running selftest and nothing else.

pqm creates a patch.<stamp>.log file for every submission. These files
are mirrored at chinstrap:/srv/bzr-pqm-logs/. The stamp itself is
probably created when the submission is *received* rather than started
and in an unknown time zone (I'm guessing here but from the lines below
it's obvious that it's not UTC and it's not when the job start).

Each line mentions:

- the file stamp (unknown TZ),

- no duration for submissions that either failed or didn't output time
  stamps (could be submissions against branches other than trunk),

- the duration of selftest (i.e. excluding extension compilation and doc
  generation),

- the start time of selftest (UTC)
- the end time of selftest (UTC)

$ for p in patch.1314[89]*.log ; do pqm-time.py $p ; done
2011-09-01 02:25:12: duration:
2011-09-01 02:25:17: duration:
2011-09-01 02:25:23: duration:
2011-09-01 07:07:47: duration: 2:06:56 start: 2011-09-01 10:57:30, end: 2011-09-01 13:04:26
2011-09-01 11:03:19: duration: 2:09:02 start: 2011-09-01 13:07:19, end: 2011-09-01 15:16:21
2011-09-01 13:03:31: duration: 2:53:02 start: 2011-09-01 15:18:26, end: 2011-09-01 18:11:28
2011-09-01 13:03:34: duration: 2:07:47 start: 2011-09-01 18:13:16, end: 2011-09-01 20:21:03
2011-09-01 18:26:41: duration:
2011-09-01 20:04:31: duration:
2011-09-01 22:36:40: duration: 2:04:57 start: 2011-09-01 21:10:23, end: 2011-09-01 23:15:20

The last line is weird as the time stamp appears to be *after* the
selftest start (22h36 >> 21:10) and I have no good guess here. I'd be
inclined to guess for UTC+2 (so 22h36 UTC+2 == 20h36 UTC) but that would
mean that even for that last submission, it took ~45 minutes to do
whatever is needed before starting the 'make check', compile extensions
and generate the doc ? A bit too much...

Anyone knows how/when the file time stamp is created and in which TZ ?

       Vincent