buildbot.status.progress

1 # This file is part of Buildbot. Buildbot is free software: you can 2 # redistribute it and/or modify it under the terms of the GNU General Public 3 # License as published by the Free Software Foundation, version 2. 4 # 5 # This program is distributed in the hope that it will be useful, but WITHOUT 6 # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS 7 # FOR A PARTICULAR PURPOSE. See the GNU General Public License for more 8 # details. 9 # 10 # You should have received a copy of the GNU General Public License along with 11 # this program; if not, write to the Free Software Foundation, Inc., 51 12 # Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. 13 # 14 # Copyright Buildbot Team Members 15 16 17 from twisted.internet import reactor 18 from twisted.spread import pb 19 from twisted.python import log 20 from buildbot import util 21 from collections import defaultdict 22

23 -class StepProgress:

24 """I keep track of how much progress a single BuildStep has made. 25 26 Progress is measured along various axes. Time consumed is one that is 27 available for all steps. Amount of command output is another, and may be 28 better quantified by scanning the output for markers to derive number of 29 files compiled, directories walked, tests run, etc. 30 31 I am created when the build begins, and given to a BuildProgress object 32 so it can track the overall progress of the whole build. 33 34 """ 35 36 startTime = None 37 stopTime = None 38 expectedTime = None 39 buildProgress = None 40 debug = False 41

42 - def __init__(self, name, metricNames):

43 self.name = name 44 self.progress = {} 45 self.expectations = {} 46 for m in metricNames: 47 self.progress[m] = None 48 self.expectations[m] = None

49

50 - def setBuildProgress(self, bp):

51 self.buildProgress = bp

52

53 - def setExpectations(self, metrics):

54 """The step can call this to explicitly set a target value for one 55 of its metrics. E.g., ShellCommands knows how many commands it will 56 execute, so it could set the 'commands' expectation.""" 57 for metric, value in metrics.items(): 58 self.expectations[metric] = value 59 self.buildProgress.newExpectations()

60

61 - def setExpectedTime(self, seconds):

62 self.expectedTime = seconds 63 self.buildProgress.newExpectations()

64

65 - def start(self):

66 if self.debug: print "StepProgress.start[%s]" % self.name 67 self.startTime = util.now()

68

69 - def setProgress(self, metric, value):

70 """The step calls this as progress is made along various axes.""" 71 if self.debug: 72 print "setProgress[%s][%s] = %s" % (self.name, metric, value) 73 self.progress[metric] = value 74 if self.debug: 75 r = self.remaining() 76 print " step remaining:", r 77 self.buildProgress.newProgress()

78

79 - def finish(self):

80 """This stops the 'time' metric and marks the step as finished 81 overall. It should be called after the last .setProgress has been 82 done for each axis.""" 83 if self.debug: print "StepProgress.finish[%s]" % self.name 84 self.stopTime = util.now() 85 self.buildProgress.stepFinished(self.name)

86

87 - def totalTime(self):

88 if self.startTime != None and self.stopTime != None: 89 return self.stopTime - self.startTime

90

91 - def remaining(self):

92 if self.startTime == None: 93 return self.expectedTime 94 if self.stopTime != None: 95 return 0 # already finished 96 # TODO: replace this with cleverness that graphs each metric vs. 97 # time, then finds the inverse function. Will probably need to save 98 # a timestamp with each setProgress update, when finished, go back 99 # and find the 2% transition points, then save those 50 values in a 100 # list. On the next build, do linear interpolation between the two 101 # closest samples to come up with a percentage represented by that 102 # metric. 103 104 # TODO: If no other metrics are available, just go with elapsed 105 # time. Given the non-time-uniformity of text output from most 106 # steps, this would probably be better than the text-percentage 107 # scheme currently implemented. 108 109 percentages = [] 110 for metric, value in self.progress.items(): 111 expectation = self.expectations[metric] 112 if value != None and expectation != None: 113 p = 1.0 * value / expectation 114 percentages.append(p) 115 if percentages: 116 avg = reduce(lambda x,y: x+y, percentages) / len(percentages) 117 if avg > 1.0: 118 # overdue 119 avg = 1.0 120 if avg < 0.0: 121 avg = 0.0 122 if percentages and self.expectedTime != None: 123 return self.expectedTime - (avg * self.expectedTime) 124 if self.expectedTime is not None: 125 # fall back to pure time 126 return self.expectedTime - (util.now() - self.startTime) 127 return None # no idea

128 129

130 -class WatcherState:

131 - def __init__(self, interval):

132 self.interval = interval 133 self.timer = None 134 self.needUpdate = 0

135

136 -class BuildProgress(pb.Referenceable):

137 """I keep track of overall build progress. I hold a list of StepProgress 138 objects. 139 """ 140

141 - def __init__(self, stepProgresses):

142 self.steps = {} 143 for s in stepProgresses: 144 self.steps[s.name] = s 145 s.setBuildProgress(self) 146 self.finishedSteps = [] 147 self.watchers = {} 148 self.debug = 0

149

150 - def setExpectationsFrom(self, exp):

151 """Set our expectations from the builder's Expectations object.""" 152 for name, metrics in exp.steps.items(): 153 s = self.steps.get(name) 154 if s: 155 s.setExpectedTime(exp.times[name]) 156 s.setExpectations(exp.steps[name])

157

158 - def newExpectations(self):

159 """Call this when one of the steps has changed its expectations. 160 This should trigger us to update our ETA value and notify any 161 subscribers.""" 162 pass # subscribers are not implemented: they just poll

163

164 - def stepFinished(self, stepname):

165 assert(stepname not in self.finishedSteps) 166 self.finishedSteps.append(stepname) 167 if len(self.finishedSteps) == len(self.steps.keys()): 168 self.sendLastUpdates()

169

170 - def newProgress(self):

171 r = self.remaining() 172 if self.debug: 173 print " remaining:", r 174 if r != None: 175 self.sendAllUpdates()

176

177 - def remaining(self):

178 # sum eta of all steps 179 sum = 0 180 for name, step in self.steps.items(): 181 rem = step.remaining() 182 if rem == None: 183 return None # not sure 184 sum += rem 185 return sum

186 - def eta(self):

187 left = self.remaining() 188 if left == None: 189 return None # not sure 190 done = util.now() + left 191 return done

192 193

194 - def remote_subscribe(self, remote, interval=5):

195 # [interval, timer, needUpdate] 196 # don't send an update more than once per interval 197 self.watchers[remote] = WatcherState(interval) 198 remote.notifyOnDisconnect(self.removeWatcher) 199 self.updateWatcher(remote) 200 self.startTimer(remote) 201 log.msg("BuildProgress.remote_subscribe(%s)" % remote)

202 - def remote_unsubscribe(self, remote):

203 # TODO: this doesn't work. I think 'remote' will always be different 204 # than the object that appeared in _subscribe. 205 log.msg("BuildProgress.remote_unsubscribe(%s)" % remote) 206 self.removeWatcher(remote)

207 #remote.dontNotifyOnDisconnect(self.removeWatcher)

208 - def removeWatcher(self, remote):

209 #log.msg("removeWatcher(%s)" % remote) 210 try: 211 timer = self.watchers[remote].timer 212 if timer: 213 timer.cancel() 214 del self.watchers[remote] 215 except KeyError: 216 log.msg("Weird, removeWatcher on non-existent subscriber:", 217 remote)

218 - def sendAllUpdates(self):

219 for r in self.watchers.keys(): 220 self.updateWatcher(r)

221 - def updateWatcher(self, remote):

222 # an update wants to go to this watcher. Send it if we can, otherwise 223 # queue it for later 224 w = self.watchers[remote] 225 if not w.timer: 226 # no timer, so send update now and start the timer 227 self.sendUpdate(remote) 228 self.startTimer(remote) 229 else: 230 # timer is running, just mark as needing an update 231 w.needUpdate = 1

232 - def startTimer(self, remote):

233 w = self.watchers[remote] 234 timer = reactor.callLater(w.interval, self.watcherTimeout, remote) 235 w.timer = timer

236 - def sendUpdate(self, remote, last=0):

237 self.watchers[remote].needUpdate = 0 238 #text = self.asText() # TODO: not text, duh 239 try: 240 remote.callRemote("progress", self.remaining()) 241 if last: 242 remote.callRemote("finished", self) 243 except: 244 log.deferr() 245 self.removeWatcher(remote)

246

247 - def watcherTimeout(self, remote):

248 w = self.watchers.get(remote, None) 249 if not w: 250 return # went away 251 w.timer = None 252 if w.needUpdate: 253 self.sendUpdate(remote) 254 self.startTimer(remote)

255 - def sendLastUpdates(self):

256 for remote in self.watchers.keys(): 257 self.sendUpdate(remote, 1) 258 self.removeWatcher(remote)

259 260

261 -class Expectations:

262 debug = False 263 # decay=1.0 ignores all but the last build 264 # 0.9 is short time constant. 0.1 is very long time constant 265 # TODO: let decay be specified per-metric 266 decay = 0.5 267

268 - def __init__(self, buildprogress):

269 """Create us from a successful build. We will expect each step to 270 take as long as it did in that build.""" 271 272 # .steps maps stepname to dict2 273 # dict2 maps metricname to final end-of-step value 274 self.steps = defaultdict(dict) 275 276 # .times maps stepname to per-step elapsed time 277 self.times = {} 278 279 for name, step in buildprogress.steps.items(): 280 self.steps[name] = {} 281 for metric, value in step.progress.items(): 282 self.steps[name][metric] = value 283 self.times[name] = None 284 if step.startTime is not None and step.stopTime is not None: 285 self.times[name] = step.stopTime - step.startTime

286

287 - def wavg(self, old, current):

288 if old is None: 289 return current 290 if current is None: 291 return old 292 else: 293 return (current * self.decay) + (old * (1 - self.decay))

294

295 - def update(self, buildprogress):

296 for name, stepprogress in buildprogress.steps.items(): 297 old = self.times.get(name) 298 current = stepprogress.totalTime() 299 if current == None: 300 log.msg("Expectations.update: current[%s] was None!" % name) 301 continue 302 new = self.wavg(old, current) 303 self.times[name] = new 304 if self.debug: 305 print "new expected time[%s] = %s, old %s, cur %s" % \ 306 (name, new, old, current) 307 308 for metric, current in stepprogress.progress.items(): 309 old = self.steps[name].get(metric) 310 new = self.wavg(old, current) 311 if self.debug: 312 print "new expectation[%s][%s] = %s, old %s, cur %s" % \ 313 (name, metric, new, old, current) 314 self.steps[name][metric] = new

315

316 - def expectedBuildTime(self):

317 if None in self.times.values(): 318 return None 319 #return sum(self.times.values()) 320 # python-2.2 doesn't have 'sum'. TODO: drop python-2.2 support 321 s = 0 322 for v in self.times.values(): 323 s += v 324 return s

325

Source Code for Module buildbot.status.progress