OLD | NEW |
| (Empty) |
1 # -*- test-case-name: buildbot.test.test_steps -*- | |
2 | |
3 from zope.interface import implements | |
4 from twisted.internet import reactor, defer, error | |
5 from twisted.protocols import basic | |
6 from twisted.spread import pb | |
7 from twisted.python import log | |
8 from twisted.python.failure import Failure | |
9 from twisted.web.util import formatFailure | |
10 | |
11 from buildbot import interfaces, locks | |
12 from buildbot.status import progress | |
13 from buildbot.status.builder import SUCCESS, WARNINGS, FAILURE, SKIPPED, \ | |
14 EXCEPTION | |
15 | |
16 """ | |
17 BuildStep and RemoteCommand classes for master-side representation of the | |
18 build process | |
19 """ | |
20 | |
21 class RemoteCommand(pb.Referenceable): | |
22 """ | |
23 I represent a single command to be run on the slave. I handle the details | |
24 of reliably gathering status updates from the slave (acknowledging each), | |
25 and (eventually, in a future release) recovering from interrupted builds. | |
26 This is the master-side object that is known to the slave-side | |
27 L{buildbot.slave.bot.SlaveBuilder}, to which status updates are sent. | |
28 | |
29 My command should be started by calling .run(), which returns a | |
30 Deferred that will fire when the command has finished, or will | |
31 errback if an exception is raised. | |
32 | |
33 Typically __init__ or run() will set up self.remote_command to be a | |
34 string which corresponds to one of the SlaveCommands registered in | |
35 the buildslave, and self.args to a dictionary of arguments that will | |
36 be passed to the SlaveCommand instance. | |
37 | |
38 start, remoteUpdate, and remoteComplete are available to be overridden | |
39 | |
40 @type commandCounter: list of one int | |
41 @cvar commandCounter: provides a unique value for each | |
42 RemoteCommand executed across all slaves | |
43 @type active: boolean | |
44 @ivar active: whether the command is currently running | |
45 """ | |
46 commandCounter = [0] # we use a list as a poor man's singleton | |
47 active = False | |
48 | |
49 def __init__(self, remote_command, args): | |
50 """ | |
51 @type remote_command: string | |
52 @param remote_command: remote command to start. This will be | |
53 passed to | |
54 L{buildbot.slave.bot.SlaveBuilder.remote_startCom
mand} | |
55 and needs to have been registered | |
56 slave-side by | |
57 L{buildbot.slave.registry.registerSlaveCommand} | |
58 @type args: dict | |
59 @param args: arguments to send to the remote command | |
60 """ | |
61 | |
62 self.remote_command = remote_command | |
63 self.args = args | |
64 | |
65 def run(self, step, remote): | |
66 self.active = True | |
67 self.step = step | |
68 self.remote = remote | |
69 c = self.commandCounter[0] | |
70 self.commandCounter[0] += 1 | |
71 #self.commandID = "%d %d" % (c, random.randint(0, 1000000)) | |
72 self.commandID = "%d" % c | |
73 log.msg("%s: RemoteCommand.run [%s]" % (self, self.commandID)) | |
74 self.deferred = defer.Deferred() | |
75 | |
76 d = defer.maybeDeferred(self.start) | |
77 | |
78 # _finished is called with an error for unknown commands, errors | |
79 # that occur while the command is starting (including OSErrors in | |
80 # exec()), StaleBroker (when the connection was lost before we | |
81 # started), and pb.PBConnectionLost (when the slave isn't responding | |
82 # over this connection, perhaps it had a power failure, or NAT | |
83 # weirdness). If this happens, self.deferred is fired right away. | |
84 d.addErrback(self._finished) | |
85 | |
86 # Connections which are lost while the command is running are caught | |
87 # when our parent Step calls our .lostRemote() method. | |
88 return self.deferred | |
89 | |
90 def start(self): | |
91 """ | |
92 Tell the slave to start executing the remote command. | |
93 | |
94 @rtype: L{twisted.internet.defer.Deferred} | |
95 @returns: a deferred that will fire when the remote command is | |
96 done (with None as the result) | |
97 """ | |
98 | |
99 # Allow use of WithProperties in logfile path names. | |
100 cmd_args = self.args | |
101 if cmd_args.has_key("logfiles") and cmd_args["logfiles"]: | |
102 cmd_args = cmd_args.copy() | |
103 properties = self.step.build.getProperties() | |
104 cmd_args["logfiles"] = properties.render(cmd_args["logfiles"]) | |
105 | |
106 # This method only initiates the remote command. | |
107 # We will receive remote_update messages as the command runs. | |
108 # We will get a single remote_complete when it finishes. | |
109 # We should fire self.deferred when the command is done. | |
110 d = self.remote.callRemote("startCommand", self, self.commandID, | |
111 self.remote_command, cmd_args) | |
112 return d | |
113 | |
114 def interrupt(self, why): | |
115 # TODO: consider separating this into interrupt() and stop(), where | |
116 # stop() unconditionally calls _finished, but interrupt() merely | |
117 # asks politely for the command to stop soon. | |
118 | |
119 log.msg("RemoteCommand.interrupt", self, why) | |
120 if not self.active: | |
121 log.msg(" but this RemoteCommand is already inactive") | |
122 return | |
123 if not self.remote: | |
124 log.msg(" but our .remote went away") | |
125 return | |
126 if isinstance(why, Failure) and why.check(error.ConnectionLost): | |
127 log.msg("RemoteCommand.disconnect: lost slave") | |
128 self.remote = None | |
129 self._finished(why) | |
130 return | |
131 | |
132 # tell the remote command to halt. Returns a Deferred that will fire | |
133 # when the interrupt command has been delivered. | |
134 | |
135 d = defer.maybeDeferred(self.remote.callRemote, "interruptCommand", | |
136 self.commandID, str(why)) | |
137 # the slave may not have remote_interruptCommand | |
138 d.addErrback(self._interruptFailed) | |
139 return d | |
140 | |
141 def _interruptFailed(self, why): | |
142 log.msg("RemoteCommand._interruptFailed", self) | |
143 # TODO: forcibly stop the Command now, since we can't stop it | |
144 # cleanly | |
145 return None | |
146 | |
147 def remote_update(self, updates): | |
148 """ | |
149 I am called by the slave's L{buildbot.slave.bot.SlaveBuilder} so | |
150 I can receive updates from the running remote command. | |
151 | |
152 @type updates: list of [object, int] | |
153 @param updates: list of updates from the remote command | |
154 """ | |
155 self.buildslave.messageReceivedFromSlave() | |
156 max_updatenum = 0 | |
157 for (update, num) in updates: | |
158 #log.msg("update[%d]:" % num) | |
159 try: | |
160 if self.active: # ignore late updates | |
161 self.remoteUpdate(update) | |
162 except: | |
163 # log failure, terminate build, let slave retire the update | |
164 self._finished(Failure()) | |
165 # TODO: what if multiple updates arrive? should | |
166 # skip the rest but ack them all | |
167 if num > max_updatenum: | |
168 max_updatenum = num | |
169 return max_updatenum | |
170 | |
171 def remoteUpdate(self, update): | |
172 raise NotImplementedError("You must implement this in a subclass") | |
173 | |
174 def remote_complete(self, failure=None): | |
175 """ | |
176 Called by the slave's L{buildbot.slave.bot.SlaveBuilder} to | |
177 notify me the remote command has finished. | |
178 | |
179 @type failure: L{twisted.python.failure.Failure} or None | |
180 | |
181 @rtype: None | |
182 """ | |
183 self.buildslave.messageReceivedFromSlave() | |
184 # call the real remoteComplete a moment later, but first return an | |
185 # acknowledgement so the slave can retire the completion message. | |
186 if self.active: | |
187 reactor.callLater(0, self._finished, failure) | |
188 return None | |
189 | |
190 def _finished(self, failure=None): | |
191 self.active = False | |
192 # call .remoteComplete. If it raises an exception, or returns the | |
193 # Failure that we gave it, our self.deferred will be errbacked. If | |
194 # it does not (either it ate the Failure or there the step finished | |
195 # normally and it didn't raise a new exception), self.deferred will | |
196 # be callbacked. | |
197 d = defer.maybeDeferred(self.remoteComplete, failure) | |
198 # arrange for the callback to get this RemoteCommand instance | |
199 # instead of just None | |
200 d.addCallback(lambda r: self) | |
201 # this fires the original deferred we returned from .run(), | |
202 # with self as the result, or a failure | |
203 d.addBoth(self.deferred.callback) | |
204 | |
205 def remoteComplete(self, maybeFailure): | |
206 """Subclasses can override this. | |
207 | |
208 This is called when the RemoteCommand has finished. 'maybeFailure' | |
209 will be None if the command completed normally, or a Failure | |
210 instance in one of the following situations: | |
211 | |
212 - the slave was lost before the command was started | |
213 - the slave didn't respond to the startCommand message | |
214 - the slave raised an exception while starting the command | |
215 (bad command name, bad args, OSError from missing executable) | |
216 - the slave raised an exception while finishing the command | |
217 (they send back a remote_complete message with a Failure payload) | |
218 | |
219 and also (for now): | |
220 - slave disconnected while the command was running | |
221 | |
222 This method should do cleanup, like closing log files. It should | |
223 normally return the 'failure' argument, so that any exceptions will | |
224 be propagated to the Step. If it wants to consume them, return None | |
225 instead.""" | |
226 | |
227 return maybeFailure | |
228 | |
229 class LoggedRemoteCommand(RemoteCommand): | |
230 """ | |
231 | |
232 I am a L{RemoteCommand} which gathers output from the remote command into | |
233 one or more local log files. My C{self.logs} dictionary contains | |
234 references to these L{buildbot.status.builder.LogFile} instances. Any | |
235 stdout/stderr/header updates from the slave will be put into | |
236 C{self.logs['stdio']}, if it exists. If the remote command uses other log | |
237 files, they will go into other entries in C{self.logs}. | |
238 | |
239 If you want to use stdout or stderr, you should create a LogFile named | |
240 'stdio' and pass it to my useLog() message. Otherwise stdout/stderr will | |
241 be ignored, which is probably not what you want. | |
242 | |
243 Unless you tell me otherwise, when my command completes I will close all | |
244 the LogFiles that I know about. | |
245 | |
246 @ivar logs: maps logname to a LogFile instance | |
247 @ivar _closeWhenFinished: maps logname to a boolean. If true, this | |
248 LogFile will be closed when the RemoteCommand | |
249 finishes. LogFiles which are shared between | |
250 multiple RemoteCommands should use False here. | |
251 | |
252 """ | |
253 | |
254 rc = None | |
255 debug = False | |
256 | |
257 def __init__(self, *args, **kwargs): | |
258 self.logs = {} | |
259 self.delayedLogs = {} | |
260 self._closeWhenFinished = {} | |
261 RemoteCommand.__init__(self, *args, **kwargs) | |
262 | |
263 def __repr__(self): | |
264 return "<RemoteCommand '%s' at %d>" % (self.remote_command, id(self)) | |
265 | |
266 def useLog(self, loog, closeWhenFinished=False, logfileName=None): | |
267 """Start routing messages from a remote logfile to a local LogFile | |
268 | |
269 I take a local ILogFile instance in 'loog', and arrange to route | |
270 remote log messages for the logfile named 'logfileName' into it. By | |
271 default this logfileName comes from the ILogFile itself (using the | |
272 name by which the ILogFile will be displayed), but the 'logfileName' | |
273 argument can be used to override this. For example, if | |
274 logfileName='stdio', this logfile will collect text from the stdout | |
275 and stderr of the command. | |
276 | |
277 @param loog: an instance which implements ILogFile | |
278 @param closeWhenFinished: a boolean, set to False if the logfile | |
279 will be shared between multiple | |
280 RemoteCommands. If True, the logfile will | |
281 be closed when this ShellCommand is done | |
282 with it. | |
283 @param logfileName: a string, which indicates which remote log file | |
284 should be routed into this ILogFile. This should | |
285 match one of the keys of the logfiles= argument | |
286 to ShellCommand. | |
287 | |
288 """ | |
289 | |
290 assert interfaces.ILogFile.providedBy(loog) | |
291 if not logfileName: | |
292 logfileName = loog.getName() | |
293 assert logfileName not in self.logs | |
294 assert logfileName not in self.delayedLogs | |
295 self.logs[logfileName] = loog | |
296 self._closeWhenFinished[logfileName] = closeWhenFinished | |
297 | |
298 def useLogDelayed(self, logfileName, activateCallBack, closeWhenFinished=Fal
se): | |
299 assert logfileName not in self.logs | |
300 assert logfileName not in self.delayedLogs | |
301 self.delayedLogs[logfileName] = (activateCallBack, closeWhenFinished) | |
302 | |
303 def start(self): | |
304 log.msg("LoggedRemoteCommand.start") | |
305 if 'stdio' not in self.logs: | |
306 log.msg("LoggedRemoteCommand (%s) is running a command, but " | |
307 "it isn't being logged to anything. This seems unusual." | |
308 % self) | |
309 self.updates = {} | |
310 return RemoteCommand.start(self) | |
311 | |
312 def addStdout(self, data): | |
313 if 'stdio' in self.logs: | |
314 self.logs['stdio'].addStdout(data) | |
315 def addStderr(self, data): | |
316 if 'stdio' in self.logs: | |
317 self.logs['stdio'].addStderr(data) | |
318 def addHeader(self, data): | |
319 if 'stdio' in self.logs: | |
320 self.logs['stdio'].addHeader(data) | |
321 | |
322 def addToLog(self, logname, data): | |
323 # Activate delayed logs on first data. | |
324 if logname in self.delayedLogs: | |
325 (activateCallBack, closeWhenFinished) = self.delayedLogs[logname] | |
326 del self.delayedLogs[logname] | |
327 loog = activateCallBack(self) | |
328 self.logs[logname] = loog | |
329 self._closeWhenFinished[logname] = closeWhenFinished | |
330 | |
331 if logname in self.logs: | |
332 self.logs[logname].addStdout(data) | |
333 else: | |
334 log.msg("%s.addToLog: no such log %s" % (self, logname)) | |
335 | |
336 def remoteUpdate(self, update): | |
337 if self.debug: | |
338 for k,v in update.items(): | |
339 log.msg("Update[%s]: %s" % (k,v)) | |
340 if update.has_key('stdout'): | |
341 # 'stdout': data | |
342 self.addStdout(update['stdout']) | |
343 if update.has_key('stderr'): | |
344 # 'stderr': data | |
345 self.addStderr(update['stderr']) | |
346 if update.has_key('header'): | |
347 # 'header': data | |
348 self.addHeader(update['header']) | |
349 if update.has_key('log'): | |
350 # 'log': (logname, data) | |
351 logname, data = update['log'] | |
352 self.addToLog(logname, data) | |
353 if update.has_key('rc'): | |
354 rc = self.rc = update['rc'] | |
355 log.msg("%s rc=%s" % (self, rc)) | |
356 self.addHeader("program finished with exit code %d\n" % rc) | |
357 | |
358 for k in update: | |
359 if k not in ('stdout', 'stderr', 'header', 'rc'): | |
360 if k not in self.updates: | |
361 self.updates[k] = [] | |
362 self.updates[k].append(update[k]) | |
363 | |
364 def remoteComplete(self, maybeFailure): | |
365 for name,loog in self.logs.items(): | |
366 if self._closeWhenFinished[name]: | |
367 if maybeFailure: | |
368 loog.addHeader("\nremoteFailed: %s" % maybeFailure) | |
369 else: | |
370 log.msg("closing log %s" % loog) | |
371 loog.finish() | |
372 return maybeFailure | |
373 | |
374 | |
375 class LogObserver: | |
376 implements(interfaces.ILogObserver) | |
377 | |
378 def setStep(self, step): | |
379 self.step = step | |
380 | |
381 def setLog(self, loog): | |
382 assert interfaces.IStatusLog.providedBy(loog) | |
383 loog.subscribe(self, True) | |
384 | |
385 def logChunk(self, build, step, log, channel, text): | |
386 if channel == interfaces.LOG_CHANNEL_STDOUT: | |
387 self.outReceived(text) | |
388 elif channel == interfaces.LOG_CHANNEL_STDERR: | |
389 self.errReceived(text) | |
390 | |
391 # TODO: add a logEnded method? er, stepFinished? | |
392 | |
393 def outReceived(self, data): | |
394 """This will be called with chunks of stdout data. Override this in | |
395 your observer.""" | |
396 pass | |
397 | |
398 def errReceived(self, data): | |
399 """This will be called with chunks of stderr data. Override this in | |
400 your observer.""" | |
401 pass | |
402 | |
403 | |
404 class LogLineObserver(LogObserver): | |
405 def __init__(self): | |
406 self.stdoutParser = basic.LineOnlyReceiver() | |
407 self.stdoutParser.delimiter = "\n" | |
408 self.stdoutParser.lineReceived = self.outLineReceived | |
409 self.stdoutParser.transport = self # for the .disconnecting attribute | |
410 self.disconnecting = False | |
411 | |
412 self.stderrParser = basic.LineOnlyReceiver() | |
413 self.stderrParser.delimiter = "\n" | |
414 self.stderrParser.lineReceived = self.errLineReceived | |
415 self.stderrParser.transport = self | |
416 | |
417 def setMaxLineLength(self, max_length): | |
418 """ | |
419 Set the maximum line length: lines longer than max_length are | |
420 dropped. Default is 16384 bytes. Use sys.maxint for effective | |
421 infinity. | |
422 """ | |
423 self.stdoutParser.MAX_LENGTH = max_length | |
424 self.stderrParser.MAX_LENGTH = max_length | |
425 | |
426 def outReceived(self, data): | |
427 self.stdoutParser.dataReceived(data) | |
428 | |
429 def errReceived(self, data): | |
430 self.stderrParser.dataReceived(data) | |
431 | |
432 def outLineReceived(self, line): | |
433 """This will be called with complete stdout lines (not including the | |
434 delimiter). Override this in your observer.""" | |
435 pass | |
436 | |
437 def errLineReceived(self, line): | |
438 """This will be called with complete lines of stderr (not including | |
439 the delimiter). Override this in your observer.""" | |
440 pass | |
441 | |
442 | |
443 class RemoteShellCommand(LoggedRemoteCommand): | |
444 """This class helps you run a shell command on the build slave. It will | |
445 accumulate all the command's output into a Log named 'stdio'. When the | |
446 command is finished, it will fire a Deferred. You can then check the | |
447 results of the command and parse the output however you like.""" | |
448 | |
449 def __init__(self, workdir, command, env=None, | |
450 want_stdout=1, want_stderr=1, | |
451 timeout=20*60, maxTime=None, logfiles={}, | |
452 usePTY="slave-config", logEnviron=True, **kwargs): | |
453 """ | |
454 @type workdir: string | |
455 @param workdir: directory where the command ought to run, | |
456 relative to the Builder's home directory. Defaults to | |
457 '.': the same as the Builder's homedir. This should | |
458 probably be '.' for the initial 'cvs checkout' | |
459 command (which creates a workdir), and the Build-wide | |
460 workdir for all subsequent commands (including | |
461 compiles and 'cvs update'). | |
462 | |
463 @type command: list of strings (or string) | |
464 @param command: the shell command to run, like 'make all' or | |
465 'cvs update'. This should be a list or tuple | |
466 which can be used directly as the argv array. | |
467 For backwards compatibility, if this is a | |
468 string, the text will be given to '/bin/sh -c | |
469 %s'. | |
470 | |
471 @type env: dict of string->string | |
472 @param env: environment variables to add or change for the | |
473 slave. Each command gets a separate | |
474 environment; all inherit the slave's initial | |
475 one. TODO: make it possible to delete some or | |
476 all of the slave's environment. | |
477 | |
478 @type want_stdout: bool | |
479 @param want_stdout: defaults to True. Set to False if stdout should | |
480 be thrown away. Do this to avoid storing or | |
481 sending large amounts of useless data. | |
482 | |
483 @type want_stderr: bool | |
484 @param want_stderr: False if stderr should be thrown away | |
485 | |
486 @type timeout: int | |
487 @param timeout: tell the remote that if the command fails to | |
488 produce any output for this number of seconds, | |
489 the command is hung and should be killed. Use | |
490 None to disable the timeout. | |
491 | |
492 @param logEnviron: whether to log env vars on the slave side | |
493 | |
494 @type maxTime: int | |
495 @param maxTime: tell the remote that if the command fails to complete | |
496 in this number of seconds, the command should be | |
497 killed. Use None to disable maxTime. | |
498 """ | |
499 | |
500 self.command = command # stash .command, set it later | |
501 if env is not None: | |
502 # avoid mutating the original master.cfg dictionary. Each | |
503 # ShellCommand gets its own copy, any start() methods won't be | |
504 # able to modify the original. | |
505 env = env.copy() | |
506 args = {'workdir': workdir, | |
507 'env': env, | |
508 'want_stdout': want_stdout, | |
509 'want_stderr': want_stderr, | |
510 'logfiles': logfiles, | |
511 'timeout': timeout, | |
512 'maxTime': maxTime, | |
513 'usePTY': usePTY, | |
514 'logEnviron': logEnviron, | |
515 } | |
516 LoggedRemoteCommand.__init__(self, "shell", args) | |
517 | |
518 def start(self): | |
519 self.args['command'] = self.command | |
520 if self.remote_command == "shell": | |
521 # non-ShellCommand slavecommands are responsible for doing this | |
522 # fixup themselves | |
523 if self.step.slaveVersion("shell", "old") == "old": | |
524 self.args['dir'] = self.args['workdir'] | |
525 what = "command '%s' in dir '%s'" % (self.args['command'], | |
526 self.args['workdir']) | |
527 log.msg(what) | |
528 return LoggedRemoteCommand.start(self) | |
529 | |
530 def __repr__(self): | |
531 return "<RemoteShellCommand '%s'>" % repr(self.command) | |
532 | |
533 class BuildStep: | |
534 """ | |
535 I represent a single step of the build process. This step may involve | |
536 zero or more commands to be run in the build slave, as well as arbitrary | |
537 processing on the master side. Regardless of how many slave commands are | |
538 run, the BuildStep will result in a single status value. | |
539 | |
540 The step is started by calling startStep(), which returns a Deferred that | |
541 fires when the step finishes. See C{startStep} for a description of the | |
542 results provided by that Deferred. | |
543 | |
544 __init__ and start are good methods to override. Don't forget to upcall | |
545 BuildStep.__init__ or bad things will happen. | |
546 | |
547 To launch a RemoteCommand, pass it to .runCommand and wait on the | |
548 Deferred it returns. | |
549 | |
550 Each BuildStep generates status as it runs. This status data is fed to | |
551 the L{buildbot.status.builder.BuildStepStatus} listener that sits in | |
552 C{self.step_status}. It can also feed progress data (like how much text | |
553 is output by a shell command) to the | |
554 L{buildbot.status.progress.StepProgress} object that lives in | |
555 C{self.progress}, by calling C{self.setProgress(metric, value)} as it | |
556 runs. | |
557 | |
558 @type build: L{buildbot.process.base.Build} | |
559 @ivar build: the parent Build which is executing this step | |
560 | |
561 @type progress: L{buildbot.status.progress.StepProgress} | |
562 @ivar progress: tracks ETA for the step | |
563 | |
564 @type step_status: L{buildbot.status.builder.BuildStepStatus} | |
565 @ivar step_status: collects output status | |
566 """ | |
567 | |
568 # these parameters are used by the parent Build object to decide how to | |
569 # interpret our results. haltOnFailure will affect the build process | |
570 # immediately, the others will be taken into consideration when | |
571 # determining the overall build status. | |
572 # | |
573 # steps that are makred as alwaysRun will be run regardless of the outcome | |
574 # of previous steps (especially steps with haltOnFailure=True) | |
575 haltOnFailure = False | |
576 flunkOnWarnings = False | |
577 flunkOnFailure = False | |
578 warnOnWarnings = False | |
579 warnOnFailure = False | |
580 alwaysRun = False | |
581 | |
582 # 'parms' holds a list of all the parameters we care about, to allow | |
583 # users to instantiate a subclass of BuildStep with a mixture of | |
584 # arguments, some of which are for us, some of which are for the subclass | |
585 # (or a delegate of the subclass, like how ShellCommand delivers many | |
586 # arguments to the RemoteShellCommand that it creates). Such delegating | |
587 # subclasses will use this list to figure out which arguments are meant | |
588 # for us and which should be given to someone else. | |
589 parms = ['name', 'locks', | |
590 'haltOnFailure', | |
591 'flunkOnWarnings', | |
592 'flunkOnFailure', | |
593 'warnOnWarnings', | |
594 'warnOnFailure', | |
595 'alwaysRun', | |
596 'progressMetrics', | |
597 'doStepIf', | |
598 ] | |
599 | |
600 name = "generic" | |
601 locks = [] | |
602 progressMetrics = () # 'time' is implicit | |
603 useProgress = True # set to False if step is really unpredictable | |
604 build = None | |
605 step_status = None | |
606 progress = None | |
607 # doStepIf can be False, True, or a function that returns False or True | |
608 doStepIf = True | |
609 | |
610 def __init__(self, **kwargs): | |
611 self.factory = (self.__class__, dict(kwargs)) | |
612 for p in self.__class__.parms: | |
613 if kwargs.has_key(p): | |
614 setattr(self, p, kwargs[p]) | |
615 del kwargs[p] | |
616 if kwargs: | |
617 why = "%s.__init__ got unexpected keyword argument(s) %s" \ | |
618 % (self, kwargs.keys()) | |
619 raise TypeError(why) | |
620 self._pendingLogObservers = [] | |
621 | |
622 def setBuild(self, build): | |
623 # subclasses which wish to base their behavior upon qualities of the | |
624 # Build (e.g. use the list of changed files to run unit tests only on | |
625 # code which has been modified) should do so here. The Build is not | |
626 # available during __init__, but setBuild() will be called just | |
627 # afterwards. | |
628 self.build = build | |
629 | |
630 def setBuildSlave(self, buildslave): | |
631 self.buildslave = buildslave | |
632 | |
633 def setDefaultWorkdir(self, workdir): | |
634 # The Build calls this just after __init__(). ShellCommand | |
635 # and variants use a slave-side workdir, but some other steps | |
636 # do not. Subclasses which use a workdir should use the value | |
637 # set by this method unless they were constructed with | |
638 # something more specific. | |
639 pass | |
640 | |
641 def addFactoryArguments(self, **kwargs): | |
642 self.factory[1].update(kwargs) | |
643 | |
644 def getStepFactory(self): | |
645 return self.factory | |
646 | |
647 def setStepStatus(self, step_status): | |
648 self.step_status = step_status | |
649 | |
650 def setupProgress(self): | |
651 if self.useProgress: | |
652 sp = progress.StepProgress(self.name, self.progressMetrics) | |
653 self.progress = sp | |
654 self.step_status.setProgress(sp) | |
655 return sp | |
656 return None | |
657 | |
658 def setProgress(self, metric, value): | |
659 """BuildSteps can call self.setProgress() to announce progress along | |
660 some metric.""" | |
661 if self.progress: | |
662 self.progress.setProgress(metric, value) | |
663 | |
664 def getProperty(self, propname): | |
665 return self.build.getProperty(propname) | |
666 | |
667 def setProperty(self, propname, value, source="Step"): | |
668 self.build.setProperty(propname, value, source) | |
669 | |
670 def startStep(self, remote): | |
671 """Begin the step. This returns a Deferred that will fire when the | |
672 step finishes. | |
673 | |
674 This deferred fires with a tuple of (result, [extra text]), although | |
675 older steps used to return just the 'result' value, so the receiving | |
676 L{base.Build} needs to be prepared to handle that too. C{result} is | |
677 one of the SUCCESS/WARNINGS/FAILURE/SKIPPED constants from | |
678 L{buildbot.status.builder}, and the extra text is a list of short | |
679 strings which should be appended to the Build's text results. This | |
680 text allows a test-case step which fails to append B{17 tests} to the | |
681 Build's status, in addition to marking the build as failing. | |
682 | |
683 The deferred will errback if the step encounters an exception, | |
684 including an exception on the slave side (or if the slave goes away | |
685 altogether). Failures in shell commands (rc!=0) will B{not} cause an | |
686 errback, in general the BuildStep will evaluate the results and | |
687 decide whether to treat it as a WARNING or FAILURE. | |
688 | |
689 @type remote: L{twisted.spread.pb.RemoteReference} | |
690 @param remote: a reference to the slave's | |
691 L{buildbot.slave.bot.SlaveBuilder} instance where any | |
692 RemoteCommands may be run | |
693 """ | |
694 | |
695 self.remote = remote | |
696 self.deferred = defer.Deferred() | |
697 # convert all locks into their real form | |
698 lock_list = [] | |
699 for access in self.locks: | |
700 if not isinstance(access, locks.LockAccess): | |
701 # Buildbot 0.7.7 compability: user did not specify access | |
702 access = access.defaultAccess() | |
703 lock = self.build.builder.botmaster.getLockByID(access.lockid) | |
704 lock_list.append((lock, access)) | |
705 self.locks = lock_list | |
706 # then narrow SlaveLocks down to the slave that this build is being | |
707 # run on | |
708 self.locks = [(l.getLock(self.build.slavebuilder), la) for l, la in self
.locks] | |
709 for l, la in self.locks: | |
710 if l in self.build.locks: | |
711 log.msg("Hey, lock %s is claimed by both a Step (%s) and the" | |
712 " parent Build (%s)" % (l, self, self.build)) | |
713 raise RuntimeError("lock claimed by both Step and Build") | |
714 d = self.acquireLocks() | |
715 d.addCallback(self._startStep_2) | |
716 return self.deferred | |
717 | |
718 def acquireLocks(self, res=None): | |
719 log.msg("acquireLocks(step %s, locks %s)" % (self, self.locks)) | |
720 if not self.locks: | |
721 return defer.succeed(None) | |
722 for lock, access in self.locks: | |
723 if not lock.isAvailable(access): | |
724 log.msg("step %s waiting for lock %s" % (self, lock)) | |
725 d = lock.waitUntilMaybeAvailable(self, access) | |
726 d.addCallback(self.acquireLocks) | |
727 return d | |
728 # all locks are available, claim them all | |
729 for lock, access in self.locks: | |
730 lock.claim(self, access) | |
731 return defer.succeed(None) | |
732 | |
733 def _startStep_2(self, res): | |
734 if self.progress: | |
735 self.progress.start() | |
736 self.step_status.stepStarted() | |
737 try: | |
738 skip = None | |
739 if isinstance(self.doStepIf, bool): | |
740 if not self.doStepIf: | |
741 skip = SKIPPED | |
742 elif not self.doStepIf(self): | |
743 skip = SKIPPED | |
744 | |
745 if skip is None: | |
746 skip = self.start() | |
747 | |
748 if skip == SKIPPED: | |
749 # this return value from self.start is a shortcut | |
750 # to finishing the step immediately | |
751 reactor.callLater(0, self.finished, SKIPPED) | |
752 except: | |
753 log.msg("BuildStep.startStep exception in .start") | |
754 self.failed(Failure()) | |
755 | |
756 def start(self): | |
757 """Begin the step. Override this method and add code to do local | |
758 processing, fire off remote commands, etc. | |
759 | |
760 To spawn a command in the buildslave, create a RemoteCommand instance | |
761 and run it with self.runCommand:: | |
762 | |
763 c = RemoteCommandFoo(args) | |
764 d = self.runCommand(c) | |
765 d.addCallback(self.fooDone).addErrback(self.failed) | |
766 | |
767 As the step runs, it should send status information to the | |
768 BuildStepStatus:: | |
769 | |
770 self.step_status.setText(['compile', 'failed']) | |
771 self.step_status.setText2(['4', 'warnings']) | |
772 | |
773 To have some code parse stdio (or other log stream) in realtime, add | |
774 a LogObserver subclass. This observer can use self.step.setProgress() | |
775 to provide better progress notification to the step.:: | |
776 | |
777 self.addLogObserver('stdio', MyLogObserver()) | |
778 | |
779 To add a LogFile, use self.addLog. Make sure it gets closed when it | |
780 finishes. When giving a Logfile to a RemoteShellCommand, just ask it | |
781 to close the log when the command completes:: | |
782 | |
783 log = self.addLog('output') | |
784 cmd = RemoteShellCommand(args) | |
785 cmd.useLog(log, closeWhenFinished=True) | |
786 | |
787 You can also create complete Logfiles with generated text in a single | |
788 step:: | |
789 | |
790 self.addCompleteLog('warnings', text) | |
791 | |
792 When the step is done, it should call self.finished(result). 'result' | |
793 will be provided to the L{buildbot.process.base.Build}, and should be | |
794 one of the constants defined above: SUCCESS, WARNINGS, FAILURE, or | |
795 SKIPPED. | |
796 | |
797 If the step encounters an exception, it should call self.failed(why). | |
798 'why' should be a Failure object. This automatically fails the whole | |
799 build with an exception. It is a good idea to add self.failed as an | |
800 errback to any Deferreds you might obtain. | |
801 | |
802 If the step decides it does not need to be run, start() can return | |
803 the constant SKIPPED. This fires the callback immediately: it is not | |
804 necessary to call .finished yourself. This can also indicate to the | |
805 status-reporting mechanism that this step should not be displayed. | |
806 | |
807 A step can be configured to only run under certain conditions. To | |
808 do this, set the step's doStepIf to a boolean value, or to a function | |
809 that returns a boolean value. If the value or function result is | |
810 False, then the step will return SKIPPED without doing anything, | |
811 otherwise the step will be executed normally. If you set doStepIf | |
812 to a function, that function should accept one parameter, which will | |
813 be the Step object itself.""" | |
814 | |
815 raise NotImplementedError("your subclass must implement this method") | |
816 | |
817 def interrupt(self, reason): | |
818 """Halt the command, either because the user has decided to cancel | |
819 the build ('reason' is a string), or because the slave has | |
820 disconnected ('reason' is a ConnectionLost Failure). Any further | |
821 local processing should be skipped, and the Step completed with an | |
822 error status. The results text should say something useful like | |
823 ['step', 'interrupted'] or ['remote', 'lost']""" | |
824 pass | |
825 | |
826 def releaseLocks(self): | |
827 log.msg("releaseLocks(%s): %s" % (self, self.locks)) | |
828 for lock, access in self.locks: | |
829 lock.release(self, access) | |
830 | |
831 def finished(self, results): | |
832 if self.progress: | |
833 self.progress.finish() | |
834 self.step_status.stepFinished(results) | |
835 self.releaseLocks() | |
836 self.deferred.callback(results) | |
837 | |
838 def failed(self, why): | |
839 # if isinstance(why, pb.CopiedFailure): # a remote exception might | |
840 # only have short traceback, so formatFailure is not as useful as | |
841 # you'd like (no .frames, so no traceback is displayed) | |
842 log.msg("BuildStep.failed, traceback follows") | |
843 log.err(why) | |
844 try: | |
845 if self.progress: | |
846 self.progress.finish() | |
847 self.addHTMLLog("err.html", formatFailure(why)) | |
848 self.addCompleteLog("err.text", why.getTraceback()) | |
849 # could use why.getDetailedTraceback() for more information | |
850 self.step_status.setText([self.name, "exception"]) | |
851 self.step_status.setText2([self.name]) | |
852 self.step_status.stepFinished(EXCEPTION) | |
853 except: | |
854 log.msg("exception during failure processing") | |
855 log.err() | |
856 # the progress stuff may still be whacked (the StepStatus may | |
857 # think that it is still running), but the build overall will now | |
858 # finish | |
859 try: | |
860 self.releaseLocks() | |
861 except: | |
862 log.msg("exception while releasing locks") | |
863 log.err() | |
864 | |
865 log.msg("BuildStep.failed now firing callback") | |
866 self.deferred.callback(EXCEPTION) | |
867 | |
868 # utility methods that BuildSteps may find useful | |
869 | |
870 def slaveVersion(self, command, oldversion=None): | |
871 """Return the version number of the given slave command. For the | |
872 commands defined in buildbot.slave.commands, this is the value of | |
873 'cvs_ver' at the top of that file. Non-existent commands will return | |
874 a value of None. Buildslaves running buildbot-0.5.0 or earlier did | |
875 not respond to the version query: commands on those slaves will | |
876 return a value of OLDVERSION, so you can distinguish between old | |
877 buildslaves and missing commands. | |
878 | |
879 If you know that <=0.5.0 buildslaves have the command you want (CVS | |
880 and SVN existed back then, but none of the other VC systems), then it | |
881 makes sense to call this with oldversion='old'. If the command you | |
882 want is newer than that, just leave oldversion= unspecified, and the | |
883 command will return None for a buildslave that does not implement the | |
884 command. | |
885 """ | |
886 return self.build.getSlaveCommandVersion(command, oldversion) | |
887 | |
888 def slaveVersionIsOlderThan(self, command, minversion): | |
889 sv = self.build.getSlaveCommandVersion(command, None) | |
890 if sv is None: | |
891 return True | |
892 # the version we get back is a string form of the CVS version number | |
893 # of the slave's buildbot/slave/commands.py, something like 1.39 . | |
894 # This might change in the future (I might move away from CVS), but | |
895 # if so I'll keep updating that string with suitably-comparable | |
896 # values. | |
897 if sv.split(".") < minversion.split("."): | |
898 return True | |
899 return False | |
900 | |
901 def getSlaveName(self): | |
902 return self.build.getSlaveName() | |
903 | |
904 def addLog(self, name): | |
905 loog = self.step_status.addLog(name) | |
906 self._connectPendingLogObservers() | |
907 return loog | |
908 | |
909 def getLog(self, name): | |
910 for l in self.step_status.getLogs(): | |
911 if l.getName() == name: | |
912 return l | |
913 raise KeyError("no log named '%s'" % (name,)) | |
914 | |
915 def addCompleteLog(self, name, text): | |
916 log.msg("addCompleteLog(%s)" % name) | |
917 loog = self.step_status.addLog(name) | |
918 size = loog.chunkSize | |
919 for start in range(0, len(text), size): | |
920 loog.addStdout(text[start:start+size]) | |
921 loog.finish() | |
922 self._connectPendingLogObservers() | |
923 | |
924 def addHTMLLog(self, name, html): | |
925 log.msg("addHTMLLog(%s)" % name) | |
926 self.step_status.addHTMLLog(name, html) | |
927 self._connectPendingLogObservers() | |
928 | |
929 def addLogObserver(self, logname, observer): | |
930 assert interfaces.ILogObserver.providedBy(observer) | |
931 observer.setStep(self) | |
932 self._pendingLogObservers.append((logname, observer)) | |
933 self._connectPendingLogObservers() | |
934 | |
935 def _connectPendingLogObservers(self): | |
936 if not self._pendingLogObservers: | |
937 return | |
938 if not self.step_status: | |
939 return | |
940 current_logs = {} | |
941 for loog in self.step_status.getLogs(): | |
942 current_logs[loog.getName()] = loog | |
943 for logname, observer in self._pendingLogObservers[:]: | |
944 if logname in current_logs: | |
945 observer.setLog(current_logs[logname]) | |
946 self._pendingLogObservers.remove((logname, observer)) | |
947 | |
948 def addURL(self, name, url): | |
949 """Add a BuildStep URL to this step. | |
950 | |
951 An HREF to this URL will be added to any HTML representations of this | |
952 step. This allows a step to provide links to external web pages, | |
953 perhaps to provide detailed HTML code coverage results or other forms | |
954 of build status. | |
955 """ | |
956 self.step_status.addURL(name, url) | |
957 | |
958 def runCommand(self, c): | |
959 c.buildslave = self.buildslave | |
960 d = c.run(self, self.remote) | |
961 return d | |
962 | |
963 | |
964 class OutputProgressObserver(LogObserver): | |
965 length = 0 | |
966 | |
967 def __init__(self, name): | |
968 self.name = name | |
969 | |
970 def logChunk(self, build, step, log, channel, text): | |
971 self.length += len(text) | |
972 self.step.setProgress(self.name, self.length) | |
973 | |
974 class LoggingBuildStep(BuildStep): | |
975 """This is an abstract base class, suitable for inheritance by all | |
976 BuildSteps that invoke RemoteCommands which emit stdout/stderr messages. | |
977 """ | |
978 | |
979 progressMetrics = ('output',) | |
980 logfiles = {} | |
981 | |
982 parms = BuildStep.parms + ['logfiles', 'lazylogfiles'] | |
983 | |
984 def __init__(self, logfiles={}, lazylogfiles=False, *args, **kwargs): | |
985 BuildStep.__init__(self, *args, **kwargs) | |
986 self.addFactoryArguments(logfiles=logfiles, | |
987 lazylogfiles=lazylogfiles) | |
988 # merge a class-level 'logfiles' attribute with one passed in as an | |
989 # argument | |
990 self.logfiles = self.logfiles.copy() | |
991 self.logfiles.update(logfiles) | |
992 self.lazylogfiles = lazylogfiles | |
993 self.addLogObserver('stdio', OutputProgressObserver("output")) | |
994 | |
995 def describe(self, done=False): | |
996 raise NotImplementedError("implement this in a subclass") | |
997 | |
998 def addLogFile(self, logname, filename): | |
999 """ | |
1000 This allows to add logfiles after construction, but before calling | |
1001 startCommand(). | |
1002 """ | |
1003 self.logfiles[logname] = filename | |
1004 | |
1005 def startCommand(self, cmd, errorMessages=[]): | |
1006 """ | |
1007 @param cmd: a suitable RemoteCommand which will be launched, with | |
1008 all output being put into our self.stdio_log LogFile | |
1009 """ | |
1010 log.msg("ShellCommand.startCommand(cmd=%s)" % (cmd,)) | |
1011 args = cmd.args | |
1012 if cmd.args.get("patch", None): | |
1013 # Don't print the patch in the logs, it's often too large and not | |
1014 # useful. | |
1015 args = cmd.args.copy() | |
1016 # This is usually a tuple so convert it to a list to be able to modify | |
1017 # it. | |
1018 patch = list(args['patch'][:]) | |
1019 if patch[1]: | |
1020 patch[1] = "(%s bytes)" % len(patch[1]) | |
1021 args['patch'] = patch | |
1022 log.msg(" cmd.args = %r" % (args)) | |
1023 self.cmd = cmd # so we can interrupt it | |
1024 self.step_status.setText(self.describe(False)) | |
1025 | |
1026 # stdio is the first log | |
1027 self.stdio_log = stdio_log = self.addLog("stdio") | |
1028 cmd.useLog(stdio_log, True) | |
1029 for em in errorMessages: | |
1030 stdio_log.addHeader(em) | |
1031 # TODO: consider setting up self.stdio_log earlier, and have the | |
1032 # code that passes in errorMessages instead call | |
1033 # self.stdio_log.addHeader() directly. | |
1034 | |
1035 # there might be other logs | |
1036 self.setupLogfiles(cmd, self.logfiles) | |
1037 | |
1038 d = self.runCommand(cmd) # might raise ConnectionLost | |
1039 d.addCallback(lambda res: self.commandComplete(cmd)) | |
1040 d.addCallback(lambda res: self.createSummary(cmd.logs['stdio'])) | |
1041 d.addCallback(lambda res: self.evaluateCommand(cmd)) # returns results | |
1042 def _gotResults(results): | |
1043 self.setStatus(cmd, results) | |
1044 return results | |
1045 d.addCallback(_gotResults) # returns results | |
1046 d.addCallbacks(self.finished, self.checkDisconnect) | |
1047 d.addErrback(self.failed) | |
1048 | |
1049 def setupLogfiles(self, cmd, logfiles): | |
1050 """Set up any additional logfiles= logs. | |
1051 """ | |
1052 for logname,remotefilename in logfiles.items(): | |
1053 if self.lazylogfiles: | |
1054 # Ask LoggedRemoteCommand to watch a logfile, but only add | |
1055 # it when/if we see any data. | |
1056 # | |
1057 # The dummy default argument local_logname is a work-around for | |
1058 # Python name binding; default values are bound by value, but | |
1059 # captured variables in the body are bound by name. | |
1060 callback = lambda cmd_arg, local_logname=logname: self.addLog(lo
cal_logname) | |
1061 cmd.useLogDelayed(logname, callback, True) | |
1062 else: | |
1063 # tell the BuildStepStatus to add a LogFile | |
1064 newlog = self.addLog(logname) | |
1065 # and tell the LoggedRemoteCommand to feed it | |
1066 cmd.useLog(newlog, True) | |
1067 | |
1068 def interrupt(self, reason): | |
1069 # TODO: consider adding an INTERRUPTED or STOPPED status to use | |
1070 # instead of FAILURE, might make the text a bit more clear. | |
1071 # 'reason' can be a Failure, or text | |
1072 self.addCompleteLog('interrupt', str(reason)) | |
1073 d = self.cmd.interrupt(reason) | |
1074 return d | |
1075 | |
1076 def checkDisconnect(self, f): | |
1077 f.trap(error.ConnectionLost) | |
1078 self.step_status.setText(self.describe(True) + | |
1079 ["failed", "slave", "lost"]) | |
1080 self.step_status.setText2(["failed", "slave", "lost"]) | |
1081 return self.finished(EXCEPTION) | |
1082 | |
1083 # to refine the status output, override one or more of the following | |
1084 # methods. Change as little as possible: start with the first ones on | |
1085 # this list and only proceed further if you have to | |
1086 # | |
1087 # createSummary: add additional Logfiles with summarized results | |
1088 # evaluateCommand: decides whether the step was successful or not | |
1089 # | |
1090 # getText: create the final per-step text strings | |
1091 # describeText2: create the strings added to the overall build status | |
1092 # | |
1093 # getText2: only adds describeText2() when the step affects build status | |
1094 # | |
1095 # setStatus: handles all status updating | |
1096 | |
1097 # commandComplete is available for general-purpose post-completion work. | |
1098 # It is a good place to do one-time parsing of logfiles, counting | |
1099 # warnings and errors. It should probably stash such counts in places | |
1100 # like self.warnings so they can be picked up later by your getText | |
1101 # method. | |
1102 | |
1103 # TODO: most of this stuff should really be on BuildStep rather than | |
1104 # ShellCommand. That involves putting the status-setup stuff in | |
1105 # .finished, which would make it hard to turn off. | |
1106 | |
1107 def commandComplete(self, cmd): | |
1108 """This is a general-purpose hook method for subclasses. It will be | |
1109 called after the remote command has finished, but before any of the | |
1110 other hook functions are called.""" | |
1111 pass | |
1112 | |
1113 def createSummary(self, log): | |
1114 """To create summary logs, do something like this: | |
1115 warnings = grep('^Warning:', log.getText()) | |
1116 self.addCompleteLog('warnings', warnings) | |
1117 """ | |
1118 pass | |
1119 | |
1120 def evaluateCommand(self, cmd): | |
1121 """Decide whether the command was SUCCESS, WARNINGS, or FAILURE. | |
1122 Override this to, say, declare WARNINGS if there is any stderr | |
1123 activity, or to say that rc!=0 is not actually an error.""" | |
1124 | |
1125 if cmd.rc != 0: | |
1126 return FAILURE | |
1127 # if cmd.log.getStderr(): return WARNINGS | |
1128 return SUCCESS | |
1129 | |
1130 def getText(self, cmd, results): | |
1131 if results == SUCCESS: | |
1132 return self.describe(True) | |
1133 elif results == WARNINGS: | |
1134 return self.describe(True) + ["warnings"] | |
1135 else: | |
1136 return self.describe(True) + ["failed"] | |
1137 | |
1138 def getText2(self, cmd, results): | |
1139 """We have decided to add a short note about ourselves to the overall | |
1140 build description, probably because something went wrong. Return a | |
1141 short list of short strings. If your subclass counts test failures or | |
1142 warnings of some sort, this is a good place to announce the count.""" | |
1143 # return ["%d warnings" % warningcount] | |
1144 # return ["%d tests" % len(failedTests)] | |
1145 return [self.name] | |
1146 | |
1147 def maybeGetText2(self, cmd, results): | |
1148 if results == SUCCESS: | |
1149 # successful steps do not add anything to the build's text | |
1150 pass | |
1151 elif results == WARNINGS: | |
1152 if (self.flunkOnWarnings or self.warnOnWarnings): | |
1153 # we're affecting the overall build, so tell them why | |
1154 return self.getText2(cmd, results) | |
1155 else: | |
1156 if (self.haltOnFailure or self.flunkOnFailure | |
1157 or self.warnOnFailure): | |
1158 # we're affecting the overall build, so tell them why | |
1159 return self.getText2(cmd, results) | |
1160 return [] | |
1161 | |
1162 def setStatus(self, cmd, results): | |
1163 # this is good enough for most steps, but it can be overridden to | |
1164 # get more control over the displayed text | |
1165 self.step_status.setText(self.getText(cmd, results)) | |
1166 self.step_status.setText2(self.maybeGetText2(cmd, results)) | |
1167 | |
1168 # (WithProperties used to be available in this module) | |
1169 from buildbot.process.properties import WithProperties | |
1170 _hush_pyflakes = [WithProperties] | |
1171 del _hush_pyflakes | |
1172 | |
OLD | NEW |