[Buildbot] #2901: Finished time of a build step does not match the elapsedTime of the same step.

[Buildbot trac]

#2901: Finished time of a build step does not match the elapsedTime of the same
step.
-------------------+--------------------
Reporter:  juj     |       Owner:
    Type:  defect  |      Status:  new
Priority:  major   |   Milestone:  0.9.0
 Version:  0.8.8   |  Resolution:
Keywords:          |
-------------------+--------------------
Changes (by dustin):

 * milestone:  undecided => 0.9.0


Comment:

 elapsedTime and the step timeout are calculated on the slave, while the
 total step time is calculated on the master.  We've had issues with small
 discrepancies on busy masters, where it takes many seconds for the master
 to get around to processing the command's completion.  But that doesn't
 seem to be the case here, particularly given that the master is correct.

 I wonder if there is something odd going on with the clock on Windows?

 In the `twistd.log` on the slave, `startTime` is set shortly (on the order
 of milliseconds on a reasonably-loaded system) after logging
 "RunProcess._startCommand".  `elapsedTime` is calculated just before
 logging "Command finished with signal.. exit code..".  Are the timestamps
 for those two log entries 15 minutes apart?  If so, any idea which was
 correct?  Does the time do anything funny in intervening log entries
 (like, run backward)?

--
Ticket URL: <http://trac.buildbot.net/ticket/2901#comment:3>
Buildbot <http://buildbot.net/>
Buildbot: build/test automation