Source Code for Module buildbot.status.progress

  1  # -*- test-case-name: buildbot.test.test_status -*- 
  2   
  3  from twisted.internet import reactor 
  4  from twisted.spread import pb 
  5  from twisted.python import log 
  6  from buildbot import util 
  7   
  8 -class StepProgress: 
  9      """I keep track of how much progress a single BuildStep has made. 
 10   
 11      Progress is measured along various axes. Time consumed is one that is 
 12      available for all steps. Amount of command output is another, and may be 
 13      better quantified by scanning the output for markers to derive number of 
 14      files compiled, directories walked, tests run, etc. 
 15   
 16      I am created when the build begins, and given to a BuildProgress object 
 17      so it can track the overall progress of the whole build. 
 18   
 19      """ 
 20   
 21      startTime = None 
 22      stopTime = None 
 23      expectedTime = None 
 24      buildProgress = None 
 25      debug = False 
 26   
 27 -    def __init__(self, name, metricNames): 
 28          self.name = name 
 29          self.progress = {} 
 30          self.expectations = {} 
 31          for m in metricNames: 
 32              self.progress[m] = None 
 33              self.expectations[m] = None 
 34   
 35 -    def setBuildProgress(self, bp): 
 36          self.buildProgress = bp 
 37   
 38 -    def setExpectations(self, metrics): 
 39          """The step can call this to explicitly set a target value for one 
 40          of its metrics. E.g., ShellCommands knows how many commands it will 
 41          execute, so it could set the 'commands' expectation.""" 
 42          for metric, value in metrics.items(): 
 43              self.expectations[metric] = value 
 44          self.buildProgress.newExpectations() 
 45   
 46 -    def setExpectedTime(self, seconds): 
 47          self.expectedTime = seconds 
 48          self.buildProgress.newExpectations() 
 49   
 50 -    def start(self): 
 51          if self.debug: print "StepProgress.start[%s]" % self.name 
 52          self.startTime = util.now() 
 53   
 54 -    def setProgress(self, metric, value): 
 55          """The step calls this as progress is made along various axes.""" 
 56          if self.debug: 
 57              print "setProgress[%s][%s] = %s" % (self.name, metric, value) 
 58          self.progress[metric] = value 
 59          if self.debug: 
 60              r = self.remaining() 
 61              print " step remaining:", r 
 62          self.buildProgress.newProgress() 
 63   
 64 -    def finish(self): 
 65          """This stops the 'time' metric and marks the step as finished 
 66          overall. It should be called after the last .setProgress has been 
 67          done for each axis.""" 
 68          if self.debug: print "StepProgress.finish[%s]" % self.name 
 69          self.stopTime = util.now() 
 70          self.buildProgress.stepFinished(self.name) 
 71   
 72 -    def totalTime(self): 
 73          if self.startTime != None and self.stopTime != None: 
 74              return self.stopTime - self.startTime 
 75   
 76 -    def remaining(self): 
 77          if self.startTime == None: 
 78              return self.expectedTime 
 79          if self.stopTime != None: 
 80              return 0 # already finished 
 81          # TODO: replace this with cleverness that graphs each metric vs. 
 82          # time, then finds the inverse function. Will probably need to save 
 83          # a timestamp with each setProgress update, when finished, go back 
 84          # and find the 2% transition points, then save those 50 values in a 
 85          # list. On the next build, do linear interpolation between the two 
 86          # closest samples to come up with a percentage represented by that 
 87          # metric. 
 88   
 89          # TODO: If no other metrics are available, just go with elapsed 
 90          # time. Given the non-time-uniformity of text output from most 
 91          # steps, this would probably be better than the text-percentage 
 92          # scheme currently implemented. 
 93   
 94          percentages = [] 
 95          for metric, value in self.progress.items(): 
 96              expectation = self.expectations[metric] 
 97              if value != None and expectation != None: 
 98                  p = 1.0 * value / expectation 
 99                  percentages.append(p) 
100          if percentages: 
101              avg = reduce(lambda x,y: x+y, percentages) / len(percentages) 
102              if avg > 1.0: 
103                  # overdue 
104                  avg = 1.0 
105              if avg < 0.0: 
106                  avg = 0.0 
107          if percentages and self.expectedTime != None: 
108              return self.expectedTime - (avg * self.expectedTime) 
109          if self.expectedTime is not None: 
110              # fall back to pure time 
111              return self.expectedTime - (util.now() - self.startTime) 
112          return None # no idea 
113   
114   
115 -class WatcherState: 
116 -    def __init__(self, interval): 
117          self.interval = interval 
118          self.timer = None 
119          self.needUpdate = 0 
120   
121 -class BuildProgress(pb.Referenceable): 
122      """I keep track of overall build progress. I hold a list of StepProgress 
123      objects. 
124      """ 
125   
126 -    def __init__(self, stepProgresses): 
127          self.steps = {} 
128          for s in stepProgresses: 
129              self.steps[s.name] = s 
130              s.setBuildProgress(self) 
131          self.finishedSteps = [] 
132          self.watchers = {} 
133          self.debug = 0 
134   
135 -    def setExpectationsFrom(self, exp): 
136          """Set our expectations from the builder's Expectations object.""" 
137          for name, metrics in exp.steps.items(): 
138              s = self.steps[name] 
139              s.setExpectedTime(exp.times[name]) 
140              s.setExpectations(exp.steps[name]) 
141   
142 -    def newExpectations(self): 
143          """Call this when one of the steps has changed its expectations. 
144          This should trigger us to update our ETA value and notify any 
145          subscribers.""" 
146          pass # subscribers are not implemented: they just poll 
147   
148 -    def stepFinished(self, stepname): 
149          assert(stepname not in self.finishedSteps) 
150          self.finishedSteps.append(stepname) 
151          if len(self.finishedSteps) == len(self.steps.keys()): 
152              self.sendLastUpdates() 
153               
154 -    def newProgress(self): 
155          r = self.remaining() 
156          if self.debug: 
157              print " remaining:", r 
158          if r != None: 
159              self.sendAllUpdates() 
160           
161 -    def remaining(self): 
162          # sum eta of all steps 
163          sum = 0 
164          for name, step in self.steps.items(): 
165              rem = step.remaining() 
166              if rem == None: 
167                  return None # not sure 
168              sum += rem 
169          return sum 
170 -    def eta(self): 
171          left = self.remaining() 
172          if left == None: 
173              return None # not sure 
174          done = util.now() + left 
175          return done 
176   
177   
178 -    def remote_subscribe(self, remote, interval=5): 
179          # [interval, timer, needUpdate] 
180          # don't send an update more than once per interval 
181          self.watchers[remote] = WatcherState(interval) 
182          remote.notifyOnDisconnect(self.removeWatcher) 
183          self.updateWatcher(remote) 
184          self.startTimer(remote) 
185          log.msg("BuildProgress.remote_subscribe(%s)" % remote) 
186 -    def remote_unsubscribe(self, remote): 
187          # TODO: this doesn't work. I think 'remote' will always be different 
188          # than the object that appeared in _subscribe. 
189          log.msg("BuildProgress.remote_unsubscribe(%s)" % remote) 
190          self.removeWatcher(remote) 
191          #remote.dontNotifyOnDisconnect(self.removeWatcher) 
192 -    def removeWatcher(self, remote): 
193          #log.msg("removeWatcher(%s)" % remote) 
194          try: 
195              timer = self.watchers[remote].timer 
196              if timer: 
197                  timer.cancel() 
198              del self.watchers[remote] 
199          except KeyError: 
200              log.msg("Weird, removeWatcher on non-existent subscriber:", 
201                      remote) 
202 -    def sendAllUpdates(self): 
203          for r in self.watchers.keys(): 
204              self.updateWatcher(r) 
205 -    def updateWatcher(self, remote): 
206          # an update wants to go to this watcher. Send it if we can, otherwise 
207          # queue it for later 
208          w = self.watchers[remote] 
209          if not w.timer: 
210              # no timer, so send update now and start the timer 
211              self.sendUpdate(remote) 
212              self.startTimer(remote) 
213          else: 
214              # timer is running, just mark as needing an update 
215              w.needUpdate = 1 
216 -    def startTimer(self, remote): 
217          w = self.watchers[remote] 
218          timer = reactor.callLater(w.interval, self.watcherTimeout, remote) 
219          w.timer = timer 
220 -    def sendUpdate(self, remote, last=0): 
221          self.watchers[remote].needUpdate = 0 
222          #text = self.asText() # TODO: not text, duh 
223          try: 
224              remote.callRemote("progress", self.remaining()) 
225              if last: 
226                  remote.callRemote("finished", self) 
227          except: 
228              log.deferr() 
229              self.removeWatcher(remote) 
230   
231 -    def watcherTimeout(self, remote): 
232          w = self.watchers.get(remote, None) 
233          if not w: 
234              return # went away 
235          w.timer = None 
236          if w.needUpdate: 
237              self.sendUpdate(remote) 
238              self.startTimer(remote) 
239 -    def sendLastUpdates(self): 
240          for remote in self.watchers.keys(): 
241              self.sendUpdate(remote, 1) 
242              self.removeWatcher(remote) 
243   
244           
245 -class Expectations: 
246      debug = False 
247      # decay=1.0 ignores all but the last build 
248      # 0.9 is short time constant. 0.1 is very long time constant 
249      # TODO: let decay be specified per-metric 
250      decay = 0.5 
251   
252 -    def __init__(self, buildprogress): 
253          """Create us from a successful build. We will expect each step to 
254          take as long as it did in that build.""" 
255   
256          # .steps maps stepname to dict2 
257          # dict2 maps metricname to final end-of-step value 
258          self.steps = {} 
259   
260          # .times maps stepname to per-step elapsed time 
261          self.times = {} 
262   
263          for name, step in buildprogress.steps.items(): 
264              self.steps[name] = {} 
265              for metric, value in step.progress.items(): 
266                  self.steps[name][metric] = value 
267              self.times[name] = None 
268              if step.startTime is not None and step.stopTime is not None: 
269                  self.times[name] = step.stopTime - step.startTime 
270   
271 -    def wavg(self, old, current): 
272          if old is None: 
273              return current 
274          if current is None: 
275              return old 
276          else: 
277              return (current * self.decay) + (old * (1 - self.decay)) 
278   
279 -    def update(self, buildprogress): 
280          for name, stepprogress in buildprogress.steps.items(): 
281              old = self.times[name] 
282              current = stepprogress.totalTime() 
283              if current == None: 
284                  log.msg("Expectations.update: current[%s] was None!" % name) 
285                  continue 
286              new = self.wavg(old, current) 
287              self.times[name] = new 
288              if self.debug: 
289                  print "new expected time[%s] = %s, old %s, cur %s" % \ 
290                        (name, new, old, current) 
291               
292              for metric, current in stepprogress.progress.items(): 
293                  old = self.steps[name][metric] 
294                  new = self.wavg(old, current) 
295                  if self.debug: 
296                      print "new expectation[%s][%s] = %s, old %s, cur %s" % \ 
297                            (name, metric, new, old, current) 
298                  self.steps[name][metric] = new 
299   
300 -    def expectedBuildTime(self): 
301          if None in self.times.values(): 
302              return None 
303          #return sum(self.times.values()) 
304          # python-2.2 doesn't have 'sum'. TODO: drop python-2.2 support 
305          s = 0 
306          for v in self.times.values(): 
307              s += v 
308          return s 
309