[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:          |
-------------------+--------------------

Comment (by juj):

 As a completely separate issue, looking at
 http://clb.demon.fi:8112/builders/win-incoming/builds/388 , I see a
 slightly misleading report. That page states that the eight steps that the
 build has, if you sum the times up, you get

   7 secs
 + 4 secs
 + 4 secs
 + 16 secs
 + 1hr 19min 3secs
 + 5hr 27min 28secs
 + 1hr 8min 43secs
 + 2hr 16min 42secs
 = 10hr 12min 27secs

 However, on the right hand side of that page in the Timing: block, it
 states

 Elapsed 20 hrs, 24 mins, 5 secs

 which is roughly *double* that of the accumulated times. Looking at the
 logs, I can see that half of that 20 hours were spent waiting for a lock
 (win-incoming was waiting for win-master to finish, a setup I must force
 so that win-incoming and win-master never run simultaneously, since they
 need access to home directory of the user). This was very puzzling at
 first and it took some time to understand that half of the elapsed time
 here was spent waiting for a lock. Perhaps printing out something like

 Elapsed 20 hrs, 24 mins, 5 secs (of which 10 hrs, 11 mins, 38 secs waiting
 for a lock)

 so that the time spent in the lock would be explicitly visible?

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