buildbot.process.buildstep

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 import re 18 19 from zope.interface import implements 20 from twisted.internet import reactor, defer, error 21 from twisted.protocols import basic 22 from twisted.spread import pb 23 from twisted.python import log 24 from twisted.python.failure import Failure 25 from twisted.web.util import formatFailure 26 27 from buildbot import interfaces, locks 28 from buildbot.status import progress 29 from buildbot.status.builder import SUCCESS, WARNINGS, FAILURE, SKIPPED, \ 30 EXCEPTION, RETRY, worst_status 31 32 """ 33 BuildStep and RemoteCommand classes for master-side representation of the 34 build process 35 """ 36

37 -class RemoteCommand(pb.Referenceable):

38 """ 39 I represent a single command to be run on the slave. I handle the details 40 of reliably gathering status updates from the slave (acknowledging each), 41 and (eventually, in a future release) recovering from interrupted builds. 42 This is the master-side object that is known to the slave-side 43 L{buildbot.slave.bot.SlaveBuilder}, to which status updates are sent. 44 45 My command should be started by calling .run(), which returns a 46 Deferred that will fire when the command has finished, or will 47 errback if an exception is raised. 48 49 Typically __init__ or run() will set up self.remote_command to be a 50 string which corresponds to one of the SlaveCommands registered in 51 the buildslave, and self.args to a dictionary of arguments that will 52 be passed to the SlaveCommand instance. 53 54 start, remoteUpdate, and remoteComplete are available to be overridden 55 56 @type commandCounter: list of one int 57 @cvar commandCounter: provides a unique value for each 58 RemoteCommand executed across all slaves 59 @type active: boolean 60 @ivar active: whether the command is currently running 61 """ 62 commandCounter = [0] # we use a list as a poor man's singleton 63 active = False 64

65 - def __init__(self, remote_command, args):

66 """ 67 @type remote_command: string 68 @param remote_command: remote command to start. This will be 69 passed to 70 L{buildbot.slave.bot.SlaveBuilder.remote_startCommand} 71 and needs to have been registered 72 slave-side in L{buildbot.slave.registry} 73 @type args: dict 74 @param args: arguments to send to the remote command 75 """ 76 77 self.remote_command = remote_command 78 self.args = args

79

80 - def run(self, step, remote):

81 self.active = True 82 self.step = step 83 self.remote = remote 84 c = self.commandCounter[0] 85 self.commandCounter[0] += 1 86 #self.commandID = "%d %d" % (c, random.randint(0, 1000000)) 87 self.commandID = "%d" % c 88 log.msg("%s: RemoteCommand.run [%s]" % (self, self.commandID)) 89 self.deferred = defer.Deferred() 90 91 d = defer.maybeDeferred(self.start) 92 93 # _finished is called with an error for unknown commands, errors 94 # that occur while the command is starting (including OSErrors in 95 # exec()), StaleBroker (when the connection was lost before we 96 # started), and pb.PBConnectionLost (when the slave isn't responding 97 # over this connection, perhaps it had a power failure, or NAT 98 # weirdness). If this happens, self.deferred is fired right away. 99 d.addErrback(self._finished) 100 101 # Connections which are lost while the command is running are caught 102 # when our parent Step calls our .lostRemote() method. 103 return self.deferred

104

105 - def start(self):

106 """ 107 Tell the slave to start executing the remote command. 108 109 @rtype: L{twisted.internet.defer.Deferred} 110 @returns: a deferred that will fire when the remote command is 111 done (with None as the result) 112 """ 113 114 # Allow use of WithProperties in logfile path names. 115 cmd_args = self.args 116 if cmd_args.has_key("logfiles") and cmd_args["logfiles"]: 117 cmd_args = cmd_args.copy() 118 properties = self.step.build.getProperties() 119 cmd_args["logfiles"] = properties.render(cmd_args["logfiles"]) 120 121 # This method only initiates the remote command. 122 # We will receive remote_update messages as the command runs. 123 # We will get a single remote_complete when it finishes. 124 # We should fire self.deferred when the command is done. 125 d = self.remote.callRemote("startCommand", self, self.commandID, 126 self.remote_command, cmd_args) 127 return d

128

129 - def interrupt(self, why):

130 # TODO: consider separating this into interrupt() and stop(), where 131 # stop() unconditionally calls _finished, but interrupt() merely 132 # asks politely for the command to stop soon. 133 134 log.msg("RemoteCommand.interrupt", self, why) 135 if not self.active: 136 log.msg(" but this RemoteCommand is already inactive") 137 return 138 if not self.remote: 139 log.msg(" but our .remote went away") 140 return 141 if isinstance(why, Failure) and why.check(error.ConnectionLost): 142 log.msg("RemoteCommand.disconnect: lost slave") 143 self.remote = None 144 self._finished(why) 145 return 146 147 # tell the remote command to halt. Returns a Deferred that will fire 148 # when the interrupt command has been delivered. 149 150 d = defer.maybeDeferred(self.remote.callRemote, "interruptCommand", 151 self.commandID, str(why)) 152 # the slave may not have remote_interruptCommand 153 d.addErrback(self._interruptFailed) 154 return d

155

156 - def _interruptFailed(self, why):

157 log.msg("RemoteCommand._interruptFailed", self) 158 # TODO: forcibly stop the Command now, since we can't stop it 159 # cleanly 160 return None

161

162 - def remote_update(self, updates):

163 """ 164 I am called by the slave's L{buildbot.slave.bot.SlaveBuilder} so 165 I can receive updates from the running remote command. 166 167 @type updates: list of [object, int] 168 @param updates: list of updates from the remote command 169 """ 170 self.buildslave.messageReceivedFromSlave() 171 max_updatenum = 0 172 for (update, num) in updates: 173 #log.msg("update[%d]:" % num) 174 try: 175 if self.active: # ignore late updates 176 self.remoteUpdate(update) 177 except: 178 # log failure, terminate build, let slave retire the update 179 self._finished(Failure()) 180 # TODO: what if multiple updates arrive? should 181 # skip the rest but ack them all 182 if num > max_updatenum: 183 max_updatenum = num 184 return max_updatenum

185

186 - def remoteUpdate(self, update):

187 raise NotImplementedError("You must implement this in a subclass")

188

189 - def remote_complete(self, failure=None):

190 """ 191 Called by the slave's L{buildbot.slave.bot.SlaveBuilder} to 192 notify me the remote command has finished. 193 194 @type failure: L{twisted.python.failure.Failure} or None 195 196 @rtype: None 197 """ 198 self.buildslave.messageReceivedFromSlave() 199 # call the real remoteComplete a moment later, but first return an 200 # acknowledgement so the slave can retire the completion message. 201 if self.active: 202 reactor.callLater(0, self._finished, failure) 203 return None

204

205 - def _finished(self, failure=None):

206 self.active = False 207 # call .remoteComplete. If it raises an exception, or returns the 208 # Failure that we gave it, our self.deferred will be errbacked. If 209 # it does not (either it ate the Failure or there the step finished 210 # normally and it didn't raise a new exception), self.deferred will 211 # be callbacked. 212 d = defer.maybeDeferred(self.remoteComplete, failure) 213 # arrange for the callback to get this RemoteCommand instance 214 # instead of just None 215 d.addCallback(lambda r: self) 216 # this fires the original deferred we returned from .run(), 217 # with self as the result, or a failure 218 d.addBoth(self.deferred.callback)

219

220 - def remoteComplete(self, maybeFailure):

221 """Subclasses can override this. 222 223 This is called when the RemoteCommand has finished. 'maybeFailure' 224 will be None if the command completed normally, or a Failure 225 instance in one of the following situations: 226 227 - the slave was lost before the command was started 228 - the slave didn't respond to the startCommand message 229 - the slave raised an exception while starting the command 230 (bad command name, bad args, OSError from missing executable) 231 - the slave raised an exception while finishing the command 232 (they send back a remote_complete message with a Failure payload) 233 234 and also (for now): 235 - slave disconnected while the command was running 236 237 This method should do cleanup, like closing log files. It should 238 normally return the 'failure' argument, so that any exceptions will 239 be propagated to the Step. If it wants to consume them, return None 240 instead.""" 241 242 return maybeFailure

243

244 -class LoggedRemoteCommand(RemoteCommand):

245 """ 246 247 I am a L{RemoteCommand} which gathers output from the remote command into 248 one or more local log files. My C{self.logs} dictionary contains 249 references to these L{buildbot.status.builder.LogFile} instances. Any 250 stdout/stderr/header updates from the slave will be put into 251 C{self.logs['stdio']}, if it exists. If the remote command uses other log 252 files, they will go into other entries in C{self.logs}. 253 254 If you want to use stdout or stderr, you should create a LogFile named 255 'stdio' and pass it to my useLog() message. Otherwise stdout/stderr will 256 be ignored, which is probably not what you want. 257 258 Unless you tell me otherwise, when my command completes I will close all 259 the LogFiles that I know about. 260 261 @ivar logs: maps logname to a LogFile instance 262 @ivar _closeWhenFinished: maps logname to a boolean. If true, this 263 LogFile will be closed when the RemoteCommand 264 finishes. LogFiles which are shared between 265 multiple RemoteCommands should use False here. 266 267 """ 268 269 rc = None 270 debug = False 271

272 - def __init__(self, *args, **kwargs):

273 self.logs = {} 274 self.delayedLogs = {} 275 self._closeWhenFinished = {} 276 RemoteCommand.__init__(self, *args, **kwargs)

277

278 - def __repr__(self):

279 return "<RemoteCommand '%s' at %d>" % (self.remote_command, id(self))

280

281 - def useLog(self, loog, closeWhenFinished=False, logfileName=None):

282 """Start routing messages from a remote logfile to a local LogFile 283 284 I take a local ILogFile instance in 'loog', and arrange to route 285 remote log messages for the logfile named 'logfileName' into it. By 286 default this logfileName comes from the ILogFile itself (using the 287 name by which the ILogFile will be displayed), but the 'logfileName' 288 argument can be used to override this. For example, if 289 logfileName='stdio', this logfile will collect text from the stdout 290 and stderr of the command. 291 292 @param loog: an instance which implements ILogFile 293 @param closeWhenFinished: a boolean, set to False if the logfile 294 will be shared between multiple 295 RemoteCommands. If True, the logfile will 296 be closed when this ShellCommand is done 297 with it. 298 @param logfileName: a string, which indicates which remote log file 299 should be routed into this ILogFile. This should 300 match one of the keys of the logfiles= argument 301 to ShellCommand. 302 303 """ 304 305 assert interfaces.ILogFile.providedBy(loog) 306 if not logfileName: 307 logfileName = loog.getName() 308 assert logfileName not in self.logs 309 assert logfileName not in self.delayedLogs 310 self.logs[logfileName] = loog 311 self._closeWhenFinished[logfileName] = closeWhenFinished

312

313 - def useLogDelayed(self, logfileName, activateCallBack, closeWhenFinished=False):

314 assert logfileName not in self.logs 315 assert logfileName not in self.delayedLogs 316 self.delayedLogs[logfileName] = (activateCallBack, closeWhenFinished)

317

318 - def start(self):

319 log.msg("LoggedRemoteCommand.start") 320 if 'stdio' not in self.logs: 321 log.msg("LoggedRemoteCommand (%s) is running a command, but " 322 "it isn't being logged to anything. This seems unusual." 323 % self) 324 self.updates = {} 325 return RemoteCommand.start(self)

326

327 - def addStdout(self, data):

328 if 'stdio' in self.logs: 329 self.logs['stdio'].addStdout(data)

330 - def addStderr(self, data):

331 if 'stdio' in self.logs: 332 self.logs['stdio'].addStderr(data)

333 - def addHeader(self, data):

334 if 'stdio' in self.logs: 335 self.logs['stdio'].addHeader(data)

336

337 - def addToLog(self, logname, data):

338 # Activate delayed logs on first data. 339 if logname in self.delayedLogs: 340 (activateCallBack, closeWhenFinished) = self.delayedLogs[logname] 341 del self.delayedLogs[logname] 342 loog = activateCallBack(self) 343 self.logs[logname] = loog 344 self._closeWhenFinished[logname] = closeWhenFinished 345 346 if logname in self.logs: 347 self.logs[logname].addStdout(data) 348 else: 349 log.msg("%s.addToLog: no such log %s" % (self, logname))

350

351 - def remoteUpdate(self, update):

352 if self.debug: 353 for k,v in update.items(): 354 log.msg("Update[%s]: %s" % (k,v)) 355 if update.has_key('stdout'): 356 # 'stdout': data 357 self.addStdout(update['stdout']) 358 if update.has_key('stderr'): 359 # 'stderr': data 360 self.addStderr(update['stderr']) 361 if update.has_key('header'): 362 # 'header': data 363 self.addHeader(update['header']) 364 if update.has_key('log'): 365 # 'log': (logname, data) 366 logname, data = update['log'] 367 self.addToLog(logname, data) 368 if update.has_key('rc'): 369 rc = self.rc = update['rc'] 370 log.msg("%s rc=%s" % (self, rc)) 371 self.addHeader("program finished with exit code %d\n" % rc) 372 373 for k in update: 374 if k not in ('stdout', 'stderr', 'header', 'rc'): 375 if k not in self.updates: 376 self.updates[k] = [] 377 self.updates[k].append(update[k])

378

379 - def remoteComplete(self, maybeFailure):

380 for name,loog in self.logs.items(): 381 if self._closeWhenFinished[name]: 382 if maybeFailure: 383 loog.addHeader("\nremoteFailed: %s" % maybeFailure) 384 else: 385 log.msg("closing log %s" % loog) 386 loog.finish() 387 return maybeFailure

388 389

390 -class LogObserver:

391 implements(interfaces.ILogObserver) 392

393 - def setStep(self, step):

394 self.step = step

395

396 - def setLog(self, loog):

397 assert interfaces.IStatusLog.providedBy(loog) 398 loog.subscribe(self, True)

399

400 - def logChunk(self, build, step, log, channel, text):

401 if channel == interfaces.LOG_CHANNEL_STDOUT: 402 self.outReceived(text) 403 elif channel == interfaces.LOG_CHANNEL_STDERR: 404 self.errReceived(text)

405 406 # TODO: add a logEnded method? er, stepFinished? 407

408 - def outReceived(self, data):

409 """This will be called with chunks of stdout data. Override this in 410 your observer.""" 411 pass

412

413 - def errReceived(self, data):

414 """This will be called with chunks of stderr data. Override this in 415 your observer.""" 416 pass

417 418

419 -class LogLineObserver(LogObserver):

420 - def __init__(self):

421 self.stdoutParser = basic.LineOnlyReceiver() 422 self.stdoutParser.delimiter = "\n" 423 self.stdoutParser.lineReceived = self.outLineReceived 424 self.stdoutParser.transport = self # for the .disconnecting attribute 425 self.disconnecting = False 426 427 self.stderrParser = basic.LineOnlyReceiver() 428 self.stderrParser.delimiter = "\n" 429 self.stderrParser.lineReceived = self.errLineReceived 430 self.stderrParser.transport = self

431

432 - def setMaxLineLength(self, max_length):

433 """ 434 Set the maximum line length: lines longer than max_length are 435 dropped. Default is 16384 bytes. Use sys.maxint for effective 436 infinity. 437 """ 438 self.stdoutParser.MAX_LENGTH = max_length 439 self.stderrParser.MAX_LENGTH = max_length

440

441 - def outReceived(self, data):

442 self.stdoutParser.dataReceived(data)

443

444 - def errReceived(self, data):

445 self.stderrParser.dataReceived(data)

446

447 - def outLineReceived(self, line):

448 """This will be called with complete stdout lines (not including the 449 delimiter). Override this in your observer.""" 450 pass

451

452 - def errLineReceived(self, line):

453 """This will be called with complete lines of stderr (not including 454 the delimiter). Override this in your observer.""" 455 pass

456 457

458 -class RemoteShellCommand(LoggedRemoteCommand):

459 """This class helps you run a shell command on the build slave. It will 460 accumulate all the command's output into a Log named 'stdio'. When the 461 command is finished, it will fire a Deferred. You can then check the 462 results of the command and parse the output however you like.""" 463

464 - def __init__(self, workdir, command, env=None, 465 want_stdout=1, want_stderr=1, 466 timeout=20*60, maxTime=None, logfiles={}, 467 usePTY="slave-config", logEnviron=True):

468 """ 469 @type workdir: string 470 @param workdir: directory where the command ought to run, 471 relative to the Builder's home directory. Defaults to 472 '.': the same as the Builder's homedir. This should 473 probably be '.' for the initial 'cvs checkout' 474 command (which creates a workdir), and the Build-wide 475 workdir for all subsequent commands (including 476 compiles and 'cvs update'). 477 478 @type command: list of strings (or string) 479 @param command: the shell command to run, like 'make all' or 480 'cvs update'. This should be a list or tuple 481 which can be used directly as the argv array. 482 For backwards compatibility, if this is a 483 string, the text will be given to '/bin/sh -c 484 %s'. 485 486 @type env: dict of string->string 487 @param env: environment variables to add or change for the 488 slave. Each command gets a separate 489 environment; all inherit the slave's initial 490 one. TODO: make it possible to delete some or 491 all of the slave's environment. 492 493 @type want_stdout: bool 494 @param want_stdout: defaults to True. Set to False if stdout should 495 be thrown away. Do this to avoid storing or 496 sending large amounts of useless data. 497 498 @type want_stderr: bool 499 @param want_stderr: False if stderr should be thrown away 500 501 @type timeout: int 502 @param timeout: tell the remote that if the command fails to 503 produce any output for this number of seconds, 504 the command is hung and should be killed. Use 505 None to disable the timeout. 506 507 @param logEnviron: whether to log env vars on the slave side 508 509 @type maxTime: int 510 @param maxTime: tell the remote that if the command fails to complete 511 in this number of seconds, the command should be 512 killed. Use None to disable maxTime. 513 """ 514 515 self.command = command # stash .command, set it later 516 if env is not None: 517 # avoid mutating the original master.cfg dictionary. Each 518 # ShellCommand gets its own copy, any start() methods won't be 519 # able to modify the original. 520 env = env.copy() 521 args = {'workdir': workdir, 522 'env': env, 523 'want_stdout': want_stdout, 524 'want_stderr': want_stderr, 525 'logfiles': logfiles, 526 'timeout': timeout, 527 'maxTime': maxTime, 528 'usePTY': usePTY, 529 'logEnviron': logEnviron, 530 } 531 LoggedRemoteCommand.__init__(self, "shell", args)

532

533 - def start(self):

534 self.args['command'] = self.command 535 if self.remote_command == "shell": 536 # non-ShellCommand slavecommands are responsible for doing this 537 # fixup themselves 538 if self.step.slaveVersion("shell", "old") == "old": 539 self.args['dir'] = self.args['workdir'] 540 what = "command '%s' in dir '%s'" % (self.args['command'], 541 self.args['workdir']) 542 log.msg(what) 543 return LoggedRemoteCommand.start(self)

544

545 - def __repr__(self):

546 return "<RemoteShellCommand '%s'>" % repr(self.command)

547

548 -class BuildStep:

549 """ 550 I represent a single step of the build process. This step may involve 551 zero or more commands to be run in the build slave, as well as arbitrary 552 processing on the master side. Regardless of how many slave commands are 553 run, the BuildStep will result in a single status value. 554 555 The step is started by calling startStep(), which returns a Deferred that 556 fires when the step finishes. See C{startStep} for a description of the 557 results provided by that Deferred. 558 559 __init__ and start are good methods to override. Don't forget to upcall 560 BuildStep.__init__ or bad things will happen. 561 562 To launch a RemoteCommand, pass it to .runCommand and wait on the 563 Deferred it returns. 564 565 Each BuildStep generates status as it runs. This status data is fed to 566 the L{buildbot.status.builder.BuildStepStatus} listener that sits in 567 C{self.step_status}. It can also feed progress data (like how much text 568 is output by a shell command) to the 569 L{buildbot.status.progress.StepProgress} object that lives in 570 C{self.progress}, by calling C{self.setProgress(metric, value)} as it 571 runs. 572 573 @type build: L{buildbot.process.base.Build} 574 @ivar build: the parent Build which is executing this step 575 576 @type progress: L{buildbot.status.progress.StepProgress} 577 @ivar progress: tracks ETA for the step 578 579 @type step_status: L{buildbot.status.builder.BuildStepStatus} 580 @ivar step_status: collects output status 581 """ 582 583 # these parameters are used by the parent Build object to decide how to 584 # interpret our results. haltOnFailure will affect the build process 585 # immediately, the others will be taken into consideration when 586 # determining the overall build status. 587 # 588 # steps that are marked as alwaysRun will be run regardless of the outcome 589 # of previous steps (especially steps with haltOnFailure=True) 590 haltOnFailure = False 591 flunkOnWarnings = False 592 flunkOnFailure = False 593 warnOnWarnings = False 594 warnOnFailure = False 595 alwaysRun = False 596 597 # 'parms' holds a list of all the parameters we care about, to allow 598 # users to instantiate a subclass of BuildStep with a mixture of 599 # arguments, some of which are for us, some of which are for the subclass 600 # (or a delegate of the subclass, like how ShellCommand delivers many 601 # arguments to the RemoteShellCommand that it creates). Such delegating 602 # subclasses will use this list to figure out which arguments are meant 603 # for us and which should be given to someone else. 604 parms = ['name', 'locks', 605 'haltOnFailure', 606 'flunkOnWarnings', 607 'flunkOnFailure', 608 'warnOnWarnings', 609 'warnOnFailure', 610 'alwaysRun', 611 'progressMetrics', 612 'doStepIf', 613 ] 614 615 name = "generic" 616 locks = [] 617 progressMetrics = () # 'time' is implicit 618 useProgress = True # set to False if step is really unpredictable 619 build = None 620 step_status = None 621 progress = None 622 # doStepIf can be False, True, or a function that returns False or True 623 doStepIf = True 624

625 - def __init__(self, **kwargs):

626 self.factory = (self.__class__, dict(kwargs)) 627 for p in self.__class__.parms: 628 if kwargs.has_key(p): 629 setattr(self, p, kwargs[p]) 630 del kwargs[p] 631 if kwargs: 632 why = "%s.__init__ got unexpected keyword argument(s) %s" \ 633 % (self, kwargs.keys()) 634 raise TypeError(why) 635 self._pendingLogObservers = [] 636 637 self._acquiringLock = None 638 self.stopped = False

639

640 - def describe(self, done=False):

641 return [self.name]

642

643 - def setBuild(self, build):

644 # subclasses which wish to base their behavior upon qualities of the 645 # Build (e.g. use the list of changed files to run unit tests only on 646 # code which has been modified) should do so here. The Build is not 647 # available during __init__, but setBuild() will be called just 648 # afterwards. 649 self.build = build

650

651 - def setBuildSlave(self, buildslave):

652 self.buildslave = buildslave

653

654 - def setDefaultWorkdir(self, workdir):

655 # The Build calls this just after __init__(). ShellCommand 656 # and variants use a slave-side workdir, but some other steps 657 # do not. Subclasses which use a workdir should use the value 658 # set by this method unless they were constructed with 659 # something more specific. 660 pass

661

662 - def addFactoryArguments(self, **kwargs):

663 self.factory[1].update(kwargs)

664

665 - def getStepFactory(self):

666 return self.factory

667

668 - def setStepStatus(self, step_status):

669 self.step_status = step_status

670

671 - def setupProgress(self):

672 if self.useProgress: 673 sp = progress.StepProgress(self.name, self.progressMetrics) 674 self.progress = sp 675 self.step_status.setProgress(sp) 676 return sp 677 return None

678

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

680 """BuildSteps can call self.setProgress() to announce progress along 681 some metric.""" 682 if self.progress: 683 self.progress.setProgress(metric, value)

684

685 - def getProperty(self, propname):

686 return self.build.getProperty(propname)

687

688 - def setProperty(self, propname, value, source="Step", runtime=True):

689 self.build.setProperty(propname, value, source, runtime=runtime)

690

691 - def startStep(self, remote):

692 """Begin the step. This returns a Deferred that will fire when the 693 step finishes. 694 695 This deferred fires with a tuple of (result, [extra text]), although 696 older steps used to return just the 'result' value, so the receiving 697 L{base.Build} needs to be prepared to handle that too. C{result} is 698 one of the SUCCESS/WARNINGS/FAILURE/SKIPPED constants from 699 L{buildbot.status.builder}, and the extra text is a list of short 700 strings which should be appended to the Build's text results. This 701 text allows a test-case step which fails to append B{17 tests} to the 702 Build's status, in addition to marking the build as failing. 703 704 The deferred will errback if the step encounters an exception, 705 including an exception on the slave side (or if the slave goes away 706 altogether). Failures in shell commands (rc!=0) will B{not} cause an 707 errback, in general the BuildStep will evaluate the results and 708 decide whether to treat it as a WARNING or FAILURE. 709 710 @type remote: L{twisted.spread.pb.RemoteReference} 711 @param remote: a reference to the slave's 712 L{buildbot.slave.bot.SlaveBuilder} instance where any 713 RemoteCommands may be run 714 """ 715 716 self.remote = remote 717 self.deferred = defer.Deferred() 718 # convert all locks into their real form 719 lock_list = [] 720 for access in self.locks: 721 if not isinstance(access, locks.LockAccess): 722 # Buildbot 0.7.7 compability: user did not specify access 723 access = access.defaultAccess() 724 lock = self.build.builder.botmaster.getLockByID(access.lockid) 725 lock_list.append((lock, access)) 726 self.locks = lock_list 727 # then narrow SlaveLocks down to the slave that this build is being 728 # run on 729 self.locks = [(l.getLock(self.build.slavebuilder), la) for l, la in self.locks] 730 for l, la in self.locks: 731 if l in self.build.locks: 732 log.msg("Hey, lock %s is claimed by both a Step (%s) and the" 733 " parent Build (%s)" % (l, self, self.build)) 734 raise RuntimeError("lock claimed by both Step and Build") 735 736 # Set the step's text here so that the stepStarted notification sees 737 # the correct description 738 self.step_status.setText(self.describe(False)) 739 self.step_status.stepStarted() 740 741 d = self.acquireLocks() 742 d.addCallback(self._startStep_2) 743 return self.deferred

744

745 - def acquireLocks(self, res=None):

746 self._acquiringLock = None 747 if not self.locks: 748 return defer.succeed(None) 749 if self.stopped: 750 return defer.succeed(None) 751 log.msg("acquireLocks(step %s, locks %s)" % (self, self.locks)) 752 for lock, access in self.locks: 753 if not lock.isAvailable(access): 754 self.step_status.setWaitingForLocks(True) 755 log.msg("step %s waiting for lock %s" % (self, lock)) 756 d = lock.waitUntilMaybeAvailable(self, access) 757 d.addCallback(self.acquireLocks) 758 self._acquiringLock = (lock, access, d) 759 return d 760 # all locks are available, claim them all 761 for lock, access in self.locks: 762 lock.claim(self, access) 763 self.step_status.setWaitingForLocks(False) 764 return defer.succeed(None)

765

766 - def _startStep_2(self, res):

767 if self.stopped: 768 self.finished(EXCEPTION) 769 return 770 771 if self.progress: 772 self.progress.start() 773 774 try: 775 skip = None 776 if isinstance(self.doStepIf, bool): 777 if not self.doStepIf: 778 skip = SKIPPED 779 elif not self.doStepIf(self): 780 skip = SKIPPED 781 782 if skip is None: 783 skip = self.start() 784 785 if skip == SKIPPED: 786 self.step_status.setText(self.describe(True) + ['skipped']) 787 self.step_status.setSkipped(True) 788 # this return value from self.start is a shortcut to finishing 789 # the step immediately; we skip calling finished() as 790 # subclasses may have overridden that an expect it to be called 791 # after start() (bug #837) 792 reactor.callLater(0, self._finishFinished, SKIPPED) 793 except: 794 log.msg("BuildStep.startStep exception in .start") 795 self.failed(Failure())

796

797 - def start(self):

798 """Begin the step. Override this method and add code to do local 799 processing, fire off remote commands, etc. 800 801 To spawn a command in the buildslave, create a RemoteCommand instance 802 and run it with self.runCommand:: 803 804 c = RemoteCommandFoo(args) 805 d = self.runCommand(c) 806 d.addCallback(self.fooDone).addErrback(self.failed) 807 808 As the step runs, it should send status information to the 809 BuildStepStatus:: 810 811 self.step_status.setText(['compile', 'failed']) 812 self.step_status.setText2(['4', 'warnings']) 813 814 To have some code parse stdio (or other log stream) in realtime, add 815 a LogObserver subclass. This observer can use self.step.setProgress() 816 to provide better progress notification to the step.:: 817 818 self.addLogObserver('stdio', MyLogObserver()) 819 820 To add a LogFile, use self.addLog. Make sure it gets closed when it 821 finishes. When giving a Logfile to a RemoteShellCommand, just ask it 822 to close the log when the command completes:: 823 824 log = self.addLog('output') 825 cmd = RemoteShellCommand(args) 826 cmd.useLog(log, closeWhenFinished=True) 827 828 You can also create complete Logfiles with generated text in a single 829 step:: 830 831 self.addCompleteLog('warnings', text) 832 833 When the step is done, it should call self.finished(result). 'result' 834 will be provided to the L{buildbot.process.base.Build}, and should be 835 one of the constants defined above: SUCCESS, WARNINGS, FAILURE, or 836 SKIPPED. 837 838 If the step encounters an exception, it should call self.failed(why). 839 'why' should be a Failure object. This automatically fails the whole 840 build with an exception. It is a good idea to add self.failed as an 841 errback to any Deferreds you might obtain. 842 843 If the step decides it does not need to be run, start() can return 844 the constant SKIPPED. This fires the callback immediately: it is not 845 necessary to call .finished yourself. This can also indicate to the 846 status-reporting mechanism that this step should not be displayed. 847 848 A step can be configured to only run under certain conditions. To 849 do this, set the step's doStepIf to a boolean value, or to a function 850 that returns a boolean value. If the value or function result is 851 False, then the step will return SKIPPED without doing anything, 852 otherwise the step will be executed normally. If you set doStepIf 853 to a function, that function should accept one parameter, which will 854 be the Step object itself.""" 855 856 raise NotImplementedError("your subclass must implement this method")

857

858 - def interrupt(self, reason):

859 """Halt the command, either because the user has decided to cancel 860 the build ('reason' is a string), or because the slave has 861 disconnected ('reason' is a ConnectionLost Failure). Any further 862 local processing should be skipped, and the Step completed with an 863 error status. The results text should say something useful like 864 ['step', 'interrupted'] or ['remote', 'lost']""" 865 self.stopped = True 866 if self._acquiringLock: 867 lock, access, d = self._acquiringLock 868 lock.stopWaitingUntilAvailable(self, access, d) 869 d.callback(None)

870

871 - def releaseLocks(self):

872 log.msg("releaseLocks(%s): %s" % (self, self.locks)) 873 for lock, access in self.locks: 874 if lock.isOwner(self, access): 875 lock.release(self, access) 876 else: 877 # This should only happen if we've been interrupted 878 assert self.stopped

879

880 - def finished(self, results):

881 if self.stopped: 882 # We handle this specially because we don't care about 883 # the return code of an interrupted command; we know 884 # that this should just be exception due to interrupt 885 results = EXCEPTION 886 self.step_status.setText(self.describe(True) + 887 ["interrupted"]) 888 self.step_status.setText2(["interrupted"]) 889 self._finishFinished(results)

890

891 - def _finishFinished(self, results):

892 # internal function to indicate that this step is done; this is separated 893 # from finished() so that subclasses can override finished() 894 if self.progress: 895 self.progress.finish() 896 self.step_status.stepFinished(results) 897 self.releaseLocks() 898 self.deferred.callback(results)

899

900 - def failed(self, why):

901 # if isinstance(why, pb.CopiedFailure): # a remote exception might 902 # only have short traceback, so formatFailure is not as useful as 903 # you'd like (no .frames, so no traceback is displayed) 904 log.msg("BuildStep.failed, traceback follows") 905 log.err(why) 906 try: 907 if self.progress: 908 self.progress.finish() 909 self.addHTMLLog("err.html", formatFailure(why)) 910 self.addCompleteLog("err.text", why.getTraceback()) 911 # could use why.getDetailedTraceback() for more information 912 self.step_status.setText([self.name, "exception"]) 913 self.step_status.setText2([self.name]) 914 self.step_status.stepFinished(EXCEPTION) 915 except: 916 log.msg("exception during failure processing") 917 log.err() 918 # the progress stuff may still be whacked (the StepStatus may 919 # think that it is still running), but the build overall will now 920 # finish 921 try: 922 self.releaseLocks() 923 except: 924 log.msg("exception while releasing locks") 925 log.err() 926 927 log.msg("BuildStep.failed now firing callback") 928 self.deferred.callback(EXCEPTION)

929 930 # utility methods that BuildSteps may find useful 931

932 - def slaveVersion(self, command, oldversion=None):

933 """Return the version number of the given slave command. For the 934 commands defined in buildbot.slave.commands, this is the value of 935 'cvs_ver' at the top of that file. Non-existent commands will return 936 a value of None. Buildslaves running buildbot-0.5.0 or earlier did 937 not respond to the version query: commands on those slaves will 938 return a value of OLDVERSION, so you can distinguish between old 939 buildslaves and missing commands. 940 941 If you know that <=0.5.0 buildslaves have the command you want (CVS 942 and SVN existed back then, but none of the other VC systems), then it 943 makes sense to call this with oldversion='old'. If the command you 944 want is newer than that, just leave oldversion= unspecified, and the 945 command will return None for a buildslave that does not implement the 946 command. 947 """ 948 return self.build.getSlaveCommandVersion(command, oldversion)

949

950 - def slaveVersionIsOlderThan(self, command, minversion):

951 sv = self.build.getSlaveCommandVersion(command, None) 952 if sv is None: 953 return True 954 # the version we get back is a string form of the CVS version number 955 # of the slave's buildbot/slave/commands.py, something like 1.39 . 956 # This might change in the future (I might move away from CVS), but 957 # if so I'll keep updating that string with suitably-comparable 958 # values. 959 if map(int, sv.split(".")) < map(int, minversion.split(".")): 960 return True 961 return False

962

963 - def getSlaveName(self):

964 return self.build.getSlaveName()

965

966 - def addLog(self, name):

967 loog = self.step_status.addLog(name) 968 self._connectPendingLogObservers() 969 return loog

970

971 - def getLog(self, name):

972 for l in self.step_status.getLogs(): 973 if l.getName() == name: 974 return l 975 raise KeyError("no log named '%s'" % (name,))

976

977 - def addCompleteLog(self, name, text):

978 log.msg("addCompleteLog(%s)" % name) 979 loog = self.step_status.addLog(name) 980 size = loog.chunkSize 981 for start in range(0, len(text), size): 982 loog.addStdout(text[start:start+size]) 983 loog.finish() 984 self._connectPendingLogObservers()

985

986 - def addHTMLLog(self, name, html):

987 log.msg("addHTMLLog(%s)" % name) 988 self.step_status.addHTMLLog(name, html) 989 self._connectPendingLogObservers()

990

991 - def addLogObserver(self, logname, observer):

992 assert interfaces.ILogObserver.providedBy(observer) 993 observer.setStep(self) 994 self._pendingLogObservers.append((logname, observer)) 995 self._connectPendingLogObservers()

996

997 - def _connectPendingLogObservers(self):

998 if not self._pendingLogObservers: 999 return 1000 if not self.step_status: 1001 return 1002 current_logs = {} 1003 for loog in self.step_status.getLogs(): 1004 current_logs[loog.getName()] = loog 1005 for logname, observer in self._pendingLogObservers[:]: 1006 if logname in current_logs: 1007 observer.setLog(current_logs[logname]) 1008 self._pendingLogObservers.remove((logname, observer))

1009

1010 - def addURL(self, name, url):

1011 """Add a BuildStep URL to this step. 1012 1013 An HREF to this URL will be added to any HTML representations of this 1014 step. This allows a step to provide links to external web pages, 1015 perhaps to provide detailed HTML code coverage results or other forms 1016 of build status. 1017 """ 1018 self.step_status.addURL(name, url)

1019

1020 - def runCommand(self, c):

1021 c.buildslave = self.buildslave 1022 d = c.run(self, self.remote) 1023 return d

1024 1025

1026 -class OutputProgressObserver(LogObserver):

1027 length = 0 1028

1029 - def __init__(self, name):

1030 self.name = name

1031

1032 - def logChunk(self, build, step, log, channel, text):

1033 self.length += len(text) 1034 self.step.setProgress(self.name, self.length)

1035

1036 -class LoggingBuildStep(BuildStep):

1037 """This is an abstract base class, suitable for inheritance by all 1038 BuildSteps that invoke RemoteCommands which emit stdout/stderr messages. 1039 """ 1040 1041 progressMetrics = ('output',) 1042 logfiles = {} 1043 1044 parms = BuildStep.parms + ['logfiles', 'lazylogfiles', 'log_eval_func'] 1045 cmd = None 1046

1047 - def __init__(self, logfiles={}, lazylogfiles=False, log_eval_func=None, 1048 *args, **kwargs):

1049 BuildStep.__init__(self, *args, **kwargs) 1050 self.addFactoryArguments(logfiles=logfiles, 1051 lazylogfiles=lazylogfiles, 1052 log_eval_func=log_eval_func) 1053 # merge a class-level 'logfiles' attribute with one passed in as an 1054 # argument 1055 self.logfiles = self.logfiles.copy() 1056 self.logfiles.update(logfiles) 1057 self.lazylogfiles = lazylogfiles 1058 assert not log_eval_func or callable(log_eval_func) 1059 self.log_eval_func = log_eval_func 1060 self.addLogObserver('stdio', OutputProgressObserver("output"))

1061

1062 - def addLogFile(self, logname, filename):

1063 """ 1064 This allows to add logfiles after construction, but before calling 1065 startCommand(). 1066 """ 1067 self.logfiles[logname] = filename

1068

1069 - def startCommand(self, cmd, errorMessages=[]):

1070 """ 1071 @param cmd: a suitable RemoteCommand which will be launched, with 1072 all output being put into our self.stdio_log LogFile 1073 """ 1074 log.msg("ShellCommand.startCommand(cmd=%s)" % (cmd,)) 1075 log.msg(" cmd.args = %r" % (cmd.args)) 1076 self.cmd = cmd # so we can interrupt it 1077 self.step_status.setText(self.describe(False)) 1078 1079 # stdio is the first log 1080 self.stdio_log = stdio_log = self.addLog("stdio") 1081 cmd.useLog(stdio_log, True) 1082 for em in errorMessages: 1083 stdio_log.addHeader(em) 1084 # TODO: consider setting up self.stdio_log earlier, and have the 1085 # code that passes in errorMessages instead call 1086 # self.stdio_log.addHeader() directly. 1087 1088 # there might be other logs 1089 self.setupLogfiles(cmd, self.logfiles) 1090 1091 d = self.runCommand(cmd) # might raise ConnectionLost 1092 d.addCallback(lambda res: self.commandComplete(cmd)) 1093 d.addCallback(lambda res: self.createSummary(cmd.logs['stdio'])) 1094 d.addCallback(lambda res: self.evaluateCommand(cmd)) # returns results 1095 def _gotResults(results): 1096 self.setStatus(cmd, results) 1097 return results

1098 d.addCallback(_gotResults) # returns results 1099 d.addCallbacks(self.finished, self.checkDisconnect) 1100 d.addErrback(self.failed)

1101

1102 - def setupLogfiles(self, cmd, logfiles):

1103 """Set up any additional logfiles= logs. 1104 1105 @param cmd: the LoggedRemoteCommand to add additional logs to. 1106 1107 @param logfiles: a dict of tuples (logname,remotefilename) 1108 specifying additional logs to watch. (note: 1109 the remotefilename component is currently 1110 ignored) 1111 """ 1112 for logname,remotefilename in logfiles.items(): 1113 if self.lazylogfiles: 1114 # Ask LoggedRemoteCommand to watch a logfile, but only add 1115 # it when/if we see any data. 1116 # 1117 # The dummy default argument local_logname is a work-around for 1118 # Python name binding; default values are bound by value, but 1119 # captured variables in the body are bound by name. 1120 callback = lambda cmd_arg, local_logname=logname: self.addLog(local_logname) 1121 cmd.useLogDelayed(logname, callback, True) 1122 else: 1123 # tell the BuildStepStatus to add a LogFile 1124 newlog = self.addLog(logname) 1125 # and tell the LoggedRemoteCommand to feed it 1126 cmd.useLog(newlog, True)

1127

1128 - def interrupt(self, reason):

1129 # TODO: consider adding an INTERRUPTED or STOPPED status to use 1130 # instead of FAILURE, might make the text a bit more clear. 1131 # 'reason' can be a Failure, or text 1132 BuildStep.interrupt(self, reason) 1133 if self.step_status.isWaitingForLocks(): 1134 self.addCompleteLog('interrupt while waiting for locks', str(reason)) 1135 else: 1136 self.addCompleteLog('interrupt', str(reason)) 1137 1138 if self.cmd: 1139 d = self.cmd.interrupt(reason) 1140 return d

1141

1142 - def checkDisconnect(self, f):

1143 f.trap(error.ConnectionLost) 1144 self.step_status.setText(self.describe(True) + 1145 ["exception", "slave", "lost"]) 1146 self.step_status.setText2(["exception", "slave", "lost"]) 1147 return self.finished(RETRY)

1148 1149 # to refine the status output, override one or more of the following 1150 # methods. Change as little as possible: start with the first ones on 1151 # this list and only proceed further if you have to 1152 # 1153 # createSummary: add additional Logfiles with summarized results 1154 # evaluateCommand: decides whether the step was successful or not 1155 # 1156 # getText: create the final per-step text strings 1157 # describeText2: create the strings added to the overall build status 1158 # 1159 # getText2: only adds describeText2() when the step affects build status 1160 # 1161 # setStatus: handles all status updating 1162 1163 # commandComplete is available for general-purpose post-completion work. 1164 # It is a good place to do one-time parsing of logfiles, counting 1165 # warnings and errors. It should probably stash such counts in places 1166 # like self.warnings so they can be picked up later by your getText 1167 # method. 1168 1169 # TODO: most of this stuff should really be on BuildStep rather than 1170 # ShellCommand. That involves putting the status-setup stuff in 1171 # .finished, which would make it hard to turn off. 1172

1173 - def commandComplete(self, cmd):

1174 """This is a general-purpose hook method for subclasses. It will be 1175 called after the remote command has finished, but before any of the 1176 other hook functions are called.""" 1177 pass

1178

1179 - def createSummary(self, log):

1180 """To create summary logs, do something like this: 1181 warnings = grep('^Warning:', log.getText()) 1182 self.addCompleteLog('warnings', warnings) 1183 """ 1184 pass

1185

1186 - def evaluateCommand(self, cmd):

1187 """Decide whether the command was SUCCESS, WARNINGS, or FAILURE. 1188 Override this to, say, declare WARNINGS if there is any stderr 1189 activity, or to say that rc!=0 is not actually an error.""" 1190 1191 if self.log_eval_func: 1192 return self.log_eval_func(cmd, self.step_status) 1193 if cmd.rc != 0: 1194 return FAILURE 1195 return SUCCESS

1196

1197 - def getText(self, cmd, results):

1198 if results == SUCCESS: 1199 return self.describe(True) 1200 elif results == WARNINGS: 1201 return self.describe(True) + ["warnings"] 1202 elif results == EXCEPTION: 1203 return self.describe(True) + ["exception"] 1204 else: 1205 return self.describe(True) + ["failed"]

1206

1207 - def getText2(self, cmd, results):

1208 """We have decided to add a short note about ourselves to the overall 1209 build description, probably because something went wrong. Return a 1210 short list of short strings. If your subclass counts test failures or 1211 warnings of some sort, this is a good place to announce the count.""" 1212 # return ["%d warnings" % warningcount] 1213 # return ["%d tests" % len(failedTests)] 1214 return [self.name]

1215

1216 - def maybeGetText2(self, cmd, results):

1217 if results == SUCCESS: 1218 # successful steps do not add anything to the build's text 1219 pass 1220 elif results == WARNINGS: 1221 if (self.flunkOnWarnings or self.warnOnWarnings): 1222 # we're affecting the overall build, so tell them why 1223 return self.getText2(cmd, results) 1224 else: 1225 if (self.haltOnFailure or self.flunkOnFailure 1226 or self.warnOnFailure): 1227 # we're affecting the overall build, so tell them why 1228 return self.getText2(cmd, results) 1229 return []

1230

1231 - def setStatus(self, cmd, results):

1232 # this is good enough for most steps, but it can be overridden to 1233 # get more control over the displayed text 1234 self.step_status.setText(self.getText(cmd, results)) 1235 self.step_status.setText2(self.maybeGetText2(cmd, results))

1236 1237 1238 # Parses the logs for a list of regexs. Meant to be invoked like: 1239 # regexes = ((re.compile(...), FAILURE), (re.compile(...), WARNINGS)) 1240 # self.addStep(ShellCommand, 1241 # command=..., 1242 # ..., 1243 # log_eval_func=lambda c,s: regex_log_evaluator(c, s, regexs) 1244 # )

1245 -def regex_log_evaluator(cmd, step_status, regexes):

1246 worst = SUCCESS 1247 if cmd.rc != 0: 1248 worst = FAILURE 1249 for err, possible_status in regexes: 1250 # worst_status returns the worse of the two status' passed to it. 1251 # we won't be changing "worst" unless possible_status is worse than it, 1252 # so we don't even need to check the log if that's the case 1253 if worst_status(worst, possible_status) == possible_status: 1254 if isinstance(err, (basestring)): 1255 err = re.compile(".*%s.*" % err, re.DOTALL) 1256 for l in cmd.logs.values(): 1257 if err.search(l.getText()): 1258 worst = possible_status 1259 return worst

1260 1261 1262 # (WithProperties used to be available in this module) 1263 from buildbot.process.properties import WithProperties 1264 _hush_pyflakes = [WithProperties] 1265 del _hush_pyflakes 1266

Source Code for Module buildbot.process.buildstep