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 buildbot.util.bbcollections 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[name] 154 s.setExpectedTime(exp.times[name]) 155 s.setExpectations(exp.steps[name])

156

157 - def newExpectations(self):

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

162

163 - def stepFinished(self, stepname):

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

168

169 - def newProgress(self):

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

175

176 - def remaining(self):

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

185 - def eta(self):

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

191 192

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

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

201 - def remote_unsubscribe(self, remote):

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

206 #remote.dontNotifyOnDisconnect(self.removeWatcher)

207 - def removeWatcher(self, remote):

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

217 - def sendAllUpdates(self):

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

220 - def updateWatcher(self, remote):

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

231 - def startTimer(self, remote):

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

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

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

245

246 - def watcherTimeout(self, remote):

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

254 - def sendLastUpdates(self):

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

258 259

260 -class Expectations:

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

267 - def __init__(self, buildprogress):

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

285

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

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

293

294 - def update(self, buildprogress):

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

314

315 - def expectedBuildTime(self):

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

324

Source Code for Module buildbot.status.progress