buildbot.process.buildstep

1 # -*- test-case-name: buildbot.test.test_steps -*- 2 3 import re 4 5 from zope.interface import implements 6 from twisted.internet import reactor, defer, error 7 from twisted.protocols import basic 8 from twisted.spread import pb 9 from twisted.python import log 10 from twisted.python.failure import Failure 11 from twisted.web.util import formatFailure 12 13 from buildbot import interfaces, locks 14 from buildbot.status import progress 15 from buildbot.status.builder import SUCCESS, WARNINGS, FAILURE, SKIPPED, \ 16 EXCEPTION, RETRY, worst_status 17 18 """ 19 BuildStep and RemoteCommand classes for master-side representation of the 20 build process 21 """ 22

23 -class RemoteCommand(pb.Referenceable):

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

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

52 """ 53 @type remote_command: string 54 @param remote_command: remote command to start. This will be 55 passed to 56 L{buildbot.slave.bot.SlaveBuilder.remote_startCommand} 57 and needs to have been registered 58 slave-side in L{buildbot.slave.registry} 59 @type args: dict 60 @param args: arguments to send to the remote command 61 """ 62 63 self.remote_command = remote_command 64 self.args = args

65

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

67 self.active = True 68 self.step = step 69 self.remote = remote 70 c = self.commandCounter[0] 71 self.commandCounter[0] += 1 72 #self.commandID = "%d %d" % (c, random.randint(0, 1000000)) 73 self.commandID = "%d" % c 74 log.msg("%s: RemoteCommand.run [%s]" % (self, self.commandID)) 75 self.deferred = defer.Deferred() 76 77 d = defer.maybeDeferred(self.start) 78 79 # _finished is called with an error for unknown commands, errors 80 # that occur while the command is starting (including OSErrors in 81 # exec()), StaleBroker (when the connection was lost before we 82 # started), and pb.PBConnectionLost (when the slave isn't responding 83 # over this connection, perhaps it had a power failure, or NAT 84 # weirdness). If this happens, self.deferred is fired right away. 85 d.addErrback(self._finished) 86 87 # Connections which are lost while the command is running are caught 88 # when our parent Step calls our .lostRemote() method. 89 return self.deferred

90

91 - def start(self):

92 """ 93 Tell the slave to start executing the remote command. 94 95 @rtype: L{twisted.internet.defer.Deferred} 96 @returns: a deferred that will fire when the remote command is 97 done (with None as the result) 98 """ 99 100 # Allow use of WithProperties in logfile path names. 101 cmd_args = self.args 102 if cmd_args.has_key("logfiles") and cmd_args["logfiles"]: 103 cmd_args = cmd_args.copy() 104 properties = self.step.build.getProperties() 105 cmd_args["logfiles"] = properties.render(cmd_args["logfiles"]) 106 107 # This method only initiates the remote command. 108 # We will receive remote_update messages as the command runs. 109 # We will get a single remote_complete when it finishes. 110 # We should fire self.deferred when the command is done. 111 d = self.remote.callRemote("startCommand", self, self.commandID, 112 self.remote_command, cmd_args) 113 return d

114

115 - def interrupt(self, why):

116 # TODO: consider separating this into interrupt() and stop(), where 117 # stop() unconditionally calls _finished, but interrupt() merely 118 # asks politely for the command to stop soon. 119 120 log.msg("RemoteCommand.interrupt", self, why) 121 if not self.active: 122 log.msg(" but this RemoteCommand is already inactive") 123 return 124 if not self.remote: 125 log.msg(" but our .remote went away") 126 return 127 if isinstance(why, Failure) and why.check(error.ConnectionLost): 128 log.msg("RemoteCommand.disconnect: lost slave") 129 self.remote = None 130 self._finished(why) 131 return 132 133 # tell the remote command to halt. Returns a Deferred that will fire 134 # when the interrupt command has been delivered. 135 136 d = defer.maybeDeferred(self.remote.callRemote, "interruptCommand", 137 self.commandID, str(why)) 138 # the slave may not have remote_interruptCommand 139 d.addErrback(self._interruptFailed) 140 return d

141

142 - def _interruptFailed(self, why):

143 log.msg("RemoteCommand._interruptFailed", self) 144 # TODO: forcibly stop the Command now, since we can't stop it 145 # cleanly 146 return None

147

148 - def remote_update(self, updates):

149 """ 150 I am called by the slave's L{buildbot.slave.bot.SlaveBuilder} so 151 I can receive updates from the running remote command. 152 153 @type updates: list of [object, int] 154 @param updates: list of updates from the remote command 155 """ 156 self.buildslave.messageReceivedFromSlave() 157 max_updatenum = 0 158 for (update, num) in updates: 159 #log.msg("update[%d]:" % num) 160 try: 161 if self.active: # ignore late updates 162 self.remoteUpdate(update) 163 except: 164 # log failure, terminate build, let slave retire the update 165 self._finished(Failure()) 166 # TODO: what if multiple updates arrive? should 167 # skip the rest but ack them all 168 if num > max_updatenum: 169 max_updatenum = num 170 return max_updatenum

171

172 - def remoteUpdate(self, update):

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

174

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

176 """ 177 Called by the slave's L{buildbot.slave.bot.SlaveBuilder} to 178 notify me the remote command has finished. 179 180 @type failure: L{twisted.python.failure.Failure} or None 181 182 @rtype: None 183 """ 184 self.buildslave.messageReceivedFromSlave() 185 # call the real remoteComplete a moment later, but first return an 186 # acknowledgement so the slave can retire the completion message. 187 if self.active: 188 reactor.callLater(0, self._finished, failure) 189 return None

190

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

192 self.active = False 193 # call .remoteComplete. If it raises an exception, or returns the 194 # Failure that we gave it, our self.deferred will be errbacked. If 195 # it does not (either it ate the Failure or there the step finished 196 # normally and it didn't raise a new exception), self.deferred will 197 # be callbacked. 198 d = defer.maybeDeferred(self.remoteComplete, failure) 199 # arrange for the callback to get this RemoteCommand instance 200 # instead of just None 201 d.addCallback(lambda r: self) 202 # this fires the original deferred we returned from .run(), 203 # with self as the result, or a failure 204 d.addBoth(self.deferred.callback)

205

206 - def remoteComplete(self, maybeFailure):

207 """Subclasses can override this. 208 209 This is called when the RemoteCommand has finished. 'maybeFailure' 210 will be None if the command completed normally, or a Failure 211 instance in one of the following situations: 212 213 - the slave was lost before the command was started 214 - the slave didn't respond to the startCommand message 215 - the slave raised an exception while starting the command 216 (bad command name, bad args, OSError from missing executable) 217 - the slave raised an exception while finishing the command 218 (they send back a remote_complete message with a Failure payload) 219 220 and also (for now): 221 - slave disconnected while the command was running 222 223 This method should do cleanup, like closing log files. It should 224 normally return the 'failure' argument, so that any exceptions will 225 be propagated to the Step. If it wants to consume them, return None 226 instead.""" 227 228 return maybeFailure

229

230 -class LoggedRemoteCommand(RemoteCommand):

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

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

259 self.logs = {} 260 self.delayedLogs = {} 261 self._closeWhenFinished = {} 262 RemoteCommand.__init__(self, *args, **kwargs)

263

264 - def __repr__(self):

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

266

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

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

298

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

300 assert logfileName not in self.logs 301 assert logfileName not in self.delayedLogs 302 self.delayedLogs[logfileName] = (activateCallBack, closeWhenFinished)

303

304 - def start(self):

305 log.msg("LoggedRemoteCommand.start") 306 if 'stdio' not in self.logs: 307 log.msg("LoggedRemoteCommand (%s) is running a command, but " 308 "it isn't being logged to anything. This seems unusual." 309 % self) 310 self.updates = {} 311 return RemoteCommand.start(self)

312

313 - def addStdout(self, data):

314 if 'stdio' in self.logs: 315 self.logs['stdio'].addStdout(data)

316 - def addStderr(self, data):

317 if 'stdio' in self.logs: 318 self.logs['stdio'].addStderr(data)

319 - def addHeader(self, data):

320 if 'stdio' in self.logs: 321 self.logs['stdio'].addHeader(data)

322

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

324 # Activate delayed logs on first data. 325 if logname in self.delayedLogs: 326 (activateCallBack, closeWhenFinished) = self.delayedLogs[logname] 327 del self.delayedLogs[logname] 328 loog = activateCallBack(self) 329 self.logs[logname] = loog 330 self._closeWhenFinished[logname] = closeWhenFinished 331 332 if logname in self.logs: 333 self.logs[logname].addStdout(data) 334 else: 335 log.msg("%s.addToLog: no such log %s" % (self, logname))

336

337 - def remoteUpdate(self, update):

338 if self.debug: 339 for k,v in update.items(): 340 log.msg("Update[%s]: %s" % (k,v)) 341 if update.has_key('stdout'): 342 # 'stdout': data 343 self.addStdout(update['stdout']) 344 if update.has_key('stderr'): 345 # 'stderr': data 346 self.addStderr(update['stderr']) 347 if update.has_key('header'): 348 # 'header': data 349 self.addHeader(update['header']) 350 if update.has_key('log'): 351 # 'log': (logname, data) 352 logname, data = update['log'] 353 self.addToLog(logname, data) 354 if update.has_key('rc'): 355 rc = self.rc = update['rc'] 356 log.msg("%s rc=%s" % (self, rc)) 357 self.addHeader("program finished with exit code %d\n" % rc) 358 359 for k in update: 360 if k not in ('stdout', 'stderr', 'header', 'rc'): 361 if k not in self.updates: 362 self.updates[k] = [] 363 self.updates[k].append(update[k])

364

365 - def remoteComplete(self, maybeFailure):

366 for name,loog in self.logs.items(): 367 if self._closeWhenFinished[name]: 368 if maybeFailure: 369 loog.addHeader("\nremoteFailed: %s" % maybeFailure) 370 else: 371 log.msg("closing log %s" % loog) 372 loog.finish() 373 return maybeFailure

374 375

376 -class LogObserver:

377 implements(interfaces.ILogObserver) 378

379 - def setStep(self, step):

380 self.step = step

381

382 - def setLog(self, loog):

383 assert interfaces.IStatusLog.providedBy(loog) 384 loog.subscribe(self, True)

385

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

387 if channel == interfaces.LOG_CHANNEL_STDOUT: 388 self.outReceived(text) 389 elif channel == interfaces.LOG_CHANNEL_STDERR: 390 self.errReceived(text)

391 392 # TODO: add a logEnded method? er, stepFinished? 393

394 - def outReceived(self, data):

395 """This will be called with chunks of stdout data. Override this in 396 your observer.""" 397 pass

398

399 - def errReceived(self, data):

400 """This will be called with chunks of stderr data. Override this in 401 your observer.""" 402 pass

403 404

405 -class LogLineObserver(LogObserver):

406 - def __init__(self):

407 self.stdoutParser = basic.LineOnlyReceiver() 408 self.stdoutParser.delimiter = "\n" 409 self.stdoutParser.lineReceived = self.outLineReceived 410 self.stdoutParser.transport = self # for the .disconnecting attribute 411 self.disconnecting = False 412 413 self.stderrParser = basic.LineOnlyReceiver() 414 self.stderrParser.delimiter = "\n" 415 self.stderrParser.lineReceived = self.errLineReceived 416 self.stderrParser.transport = self

417

418 - def setMaxLineLength(self, max_length):

419 """ 420 Set the maximum line length: lines longer than max_length are 421 dropped. Default is 16384 bytes. Use sys.maxint for effective 422 infinity. 423 """ 424 self.stdoutParser.MAX_LENGTH = max_length 425 self.stderrParser.MAX_LENGTH = max_length

426

427 - def outReceived(self, data):

428 self.stdoutParser.dataReceived(data)

429

430 - def errReceived(self, data):

431 self.stderrParser.dataReceived(data)

432

433 - def outLineReceived(self, line):

434 """This will be called with complete stdout lines (not including the 435 delimiter). Override this in your observer.""" 436 pass

437

438 - def errLineReceived(self, line):

439 """This will be called with complete lines of stderr (not including 440 the delimiter). Override this in your observer.""" 441 pass

442 443

444 -class RemoteShellCommand(LoggedRemoteCommand):

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

450 - def __init__(self, workdir, command, env=None, 451 want_stdout=1, want_stderr=1, 452 timeout=20*60, maxTime=None, logfiles={}, 453 usePTY="slave-config", logEnviron=True):

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

518

519 - def start(self):

520 self.args['command'] = self.command 521 if self.remote_command == "shell": 522 # non-ShellCommand slavecommands are responsible for doing this 523 # fixup themselves 524 if self.step.slaveVersion("shell", "old") == "old": 525 self.args['dir'] = self.args['workdir'] 526 what = "command '%s' in dir '%s'" % (self.args['command'], 527 self.args['workdir']) 528 log.msg(what) 529 return LoggedRemoteCommand.start(self)

530

531 - def __repr__(self):

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

533

534 -class BuildStep:

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

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

612 self.factory = (self.__class__, dict(kwargs)) 613 for p in self.__class__.parms: 614 if kwargs.has_key(p): 615 setattr(self, p, kwargs[p]) 616 del kwargs[p] 617 if kwargs: 618 why = "%s.__init__ got unexpected keyword argument(s) %s" \ 619 % (self, kwargs.keys()) 620 raise TypeError(why) 621 self._pendingLogObservers = [] 622 623 self._acquiringLock = None 624 self.stopped = False

625

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

627 return [self.name]

628

629 - def setBuild(self, build):

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

636

637 - def setBuildSlave(self, buildslave):

638 self.buildslave = buildslave

639

640 - def setDefaultWorkdir(self, workdir):

641 # The Build calls this just after __init__(). ShellCommand 642 # and variants use a slave-side workdir, but some other steps 643 # do not. Subclasses which use a workdir should use the value 644 # set by this method unless they were constructed with 645 # something more specific. 646 pass

647

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

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

650

651 - def getStepFactory(self):

652 return self.factory

653

654 - def setStepStatus(self, step_status):

655 self.step_status = step_status

656

657 - def setupProgress(self):

658 if self.useProgress: 659 sp = progress.StepProgress(self.name, self.progressMetrics) 660 self.progress = sp 661 self.step_status.setProgress(sp) 662 return sp 663 return None

664

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

666 """BuildSteps can call self.setProgress() to announce progress along 667 some metric.""" 668 if self.progress: 669 self.progress.setProgress(metric, value)

670

671 - def getProperty(self, propname):

672 return self.build.getProperty(propname)

673

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

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

676

677 - def startStep(self, remote):

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

730

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

732 self._acquiringLock = None 733 if not self.locks: 734 return defer.succeed(None) 735 if self.stopped: 736 return defer.succeed(None) 737 log.msg("acquireLocks(step %s, locks %s)" % (self, self.locks)) 738 for lock, access in self.locks: 739 if not lock.isAvailable(access): 740 self.step_status.setWaitingForLocks(True) 741 log.msg("step %s waiting for lock %s" % (self, lock)) 742 d = lock.waitUntilMaybeAvailable(self, access) 743 d.addCallback(self.acquireLocks) 744 self._acquiringLock = (lock, access, d) 745 return d 746 # all locks are available, claim them all 747 for lock, access in self.locks: 748 lock.claim(self, access) 749 self.step_status.setWaitingForLocks(False) 750 return defer.succeed(None)

751

752 - def _startStep_2(self, res):

753 if self.stopped: 754 self.finished(FAILURE) 755 return 756 757 if self.progress: 758 self.progress.start() 759 760 try: 761 skip = None 762 if isinstance(self.doStepIf, bool): 763 if not self.doStepIf: 764 skip = SKIPPED 765 elif not self.doStepIf(self): 766 skip = SKIPPED 767 768 if skip is None: 769 skip = self.start() 770 771 if skip == SKIPPED: 772 self.step_status.setText(self.describe(True) + ['skipped']) 773 self.step_status.setSkipped(True) 774 # this return value from self.start is a shortcut 775 # to finishing the step immediately 776 reactor.callLater(0, self.finished, SKIPPED) 777 except: 778 log.msg("BuildStep.startStep exception in .start") 779 self.failed(Failure())

780

781 - def start(self):

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

841

842 - def interrupt(self, reason):

843 """Halt the command, either because the user has decided to cancel 844 the build ('reason' is a string), or because the slave has 845 disconnected ('reason' is a ConnectionLost Failure). Any further 846 local processing should be skipped, and the Step completed with an 847 error status. The results text should say something useful like 848 ['step', 'interrupted'] or ['remote', 'lost']""" 849 self.stopped = True 850 if self._acquiringLock: 851 lock, access, d = self._acquiringLock 852 lock.stopWaitingUntilAvailable(self, access, d) 853 d.callback(None)

854

855 - def releaseLocks(self):

856 log.msg("releaseLocks(%s): %s" % (self, self.locks)) 857 for lock, access in self.locks: 858 if lock.isOwner(self, access): 859 lock.release(self, access) 860 else: 861 # This should only happen if we've been interrupted 862 assert self.stopped

863

864 - def finished(self, results):

865 if self.progress: 866 self.progress.finish() 867 self.step_status.stepFinished(results) 868 self.releaseLocks() 869 self.deferred.callback(results)

870

871 - def failed(self, why):

872 # if isinstance(why, pb.CopiedFailure): # a remote exception might 873 # only have short traceback, so formatFailure is not as useful as 874 # you'd like (no .frames, so no traceback is displayed) 875 log.msg("BuildStep.failed, traceback follows") 876 log.err(why) 877 try: 878 if self.progress: 879 self.progress.finish() 880 self.addHTMLLog("err.html", formatFailure(why)) 881 self.addCompleteLog("err.text", why.getTraceback()) 882 # could use why.getDetailedTraceback() for more information 883 self.step_status.setText([self.name, "exception"]) 884 self.step_status.setText2([self.name]) 885 self.step_status.stepFinished(EXCEPTION) 886 except: 887 log.msg("exception during failure processing") 888 log.err() 889 # the progress stuff may still be whacked (the StepStatus may 890 # think that it is still running), but the build overall will now 891 # finish 892 try: 893 self.releaseLocks() 894 except: 895 log.msg("exception while releasing locks") 896 log.err() 897 898 log.msg("BuildStep.failed now firing callback") 899 self.deferred.callback(EXCEPTION)

900 901 # utility methods that BuildSteps may find useful 902

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

904 """Return the version number of the given slave command. For the 905 commands defined in buildbot.slave.commands, this is the value of 906 'cvs_ver' at the top of that file. Non-existent commands will return 907 a value of None. Buildslaves running buildbot-0.5.0 or earlier did 908 not respond to the version query: commands on those slaves will 909 return a value of OLDVERSION, so you can distinguish between old 910 buildslaves and missing commands. 911 912 If you know that <=0.5.0 buildslaves have the command you want (CVS 913 and SVN existed back then, but none of the other VC systems), then it 914 makes sense to call this with oldversion='old'. If the command you 915 want is newer than that, just leave oldversion= unspecified, and the 916 command will return None for a buildslave that does not implement the 917 command. 918 """ 919 return self.build.getSlaveCommandVersion(command, oldversion)

920

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

922 sv = self.build.getSlaveCommandVersion(command, None) 923 if sv is None: 924 return True 925 # the version we get back is a string form of the CVS version number 926 # of the slave's buildbot/slave/commands.py, something like 1.39 . 927 # This might change in the future (I might move away from CVS), but 928 # if so I'll keep updating that string with suitably-comparable 929 # values. 930 if map(int, sv.split(".")) < map(int, minversion.split(".")): 931 return True 932 return False

933

934 - def getSlaveName(self):

935 return self.build.getSlaveName()

936

937 - def addLog(self, name):

938 loog = self.step_status.addLog(name) 939 self._connectPendingLogObservers() 940 return loog

941

942 - def getLog(self, name):

943 for l in self.step_status.getLogs(): 944 if l.getName() == name: 945 return l 946 raise KeyError("no log named '%s'" % (name,))

947

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

949 log.msg("addCompleteLog(%s)" % name) 950 loog = self.step_status.addLog(name) 951 size = loog.chunkSize 952 for start in range(0, len(text), size): 953 loog.addStdout(text[start:start+size]) 954 loog.finish() 955 self._connectPendingLogObservers()

956

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

958 log.msg("addHTMLLog(%s)" % name) 959 self.step_status.addHTMLLog(name, html) 960 self._connectPendingLogObservers()

961

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

963 assert interfaces.ILogObserver.providedBy(observer) 964 observer.setStep(self) 965 self._pendingLogObservers.append((logname, observer)) 966 self._connectPendingLogObservers()

967

968 - def _connectPendingLogObservers(self):

969 if not self._pendingLogObservers: 970 return 971 if not self.step_status: 972 return 973 current_logs = {} 974 for loog in self.step_status.getLogs(): 975 current_logs[loog.getName()] = loog 976 for logname, observer in self._pendingLogObservers[:]: 977 if logname in current_logs: 978 observer.setLog(current_logs[logname]) 979 self._pendingLogObservers.remove((logname, observer))

980

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

982 """Add a BuildStep URL to this step. 983 984 An HREF to this URL will be added to any HTML representations of this 985 step. This allows a step to provide links to external web pages, 986 perhaps to provide detailed HTML code coverage results or other forms 987 of build status. 988 """ 989 self.step_status.addURL(name, url)

990

991 - def runCommand(self, c):

992 c.buildslave = self.buildslave 993 d = c.run(self, self.remote) 994 return d

995 996

997 -class OutputProgressObserver(LogObserver):

998 length = 0 999

1000 - def __init__(self, name):

1001 self.name = name

1002

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

1004 self.length += len(text) 1005 self.step.setProgress(self.name, self.length)

1006

1007 -class LoggingBuildStep(BuildStep):

1008 """This is an abstract base class, suitable for inheritance by all 1009 BuildSteps that invoke RemoteCommands which emit stdout/stderr messages. 1010 """ 1011 1012 progressMetrics = ('output',) 1013 logfiles = {} 1014 1015 parms = BuildStep.parms + ['logfiles', 'lazylogfiles', 'log_eval_func'] 1016 cmd = None 1017

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

1020 BuildStep.__init__(self, *args, **kwargs) 1021 self.addFactoryArguments(logfiles=logfiles, 1022 lazylogfiles=lazylogfiles, 1023 log_eval_func=log_eval_func) 1024 # merge a class-level 'logfiles' attribute with one passed in as an 1025 # argument 1026 self.logfiles = self.logfiles.copy() 1027 self.logfiles.update(logfiles) 1028 self.lazylogfiles = lazylogfiles 1029 assert not log_eval_func or callable(log_eval_func) 1030 self.log_eval_func = log_eval_func 1031 self.addLogObserver('stdio', OutputProgressObserver("output"))

1032

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

1034 """ 1035 This allows to add logfiles after construction, but before calling 1036 startCommand(). 1037 """ 1038 self.logfiles[logname] = filename

1039

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

1041 """ 1042 @param cmd: a suitable RemoteCommand which will be launched, with 1043 all output being put into our self.stdio_log LogFile 1044 """ 1045 log.msg("ShellCommand.startCommand(cmd=%s)" % (cmd,)) 1046 log.msg(" cmd.args = %r" % (cmd.args)) 1047 self.cmd = cmd # so we can interrupt it 1048 self.step_status.setText(self.describe(False)) 1049 1050 # stdio is the first log 1051 self.stdio_log = stdio_log = self.addLog("stdio") 1052 cmd.useLog(stdio_log, True) 1053 for em in errorMessages: 1054 stdio_log.addHeader(em) 1055 # TODO: consider setting up self.stdio_log earlier, and have the 1056 # code that passes in errorMessages instead call 1057 # self.stdio_log.addHeader() directly. 1058 1059 # there might be other logs 1060 self.setupLogfiles(cmd, self.logfiles) 1061 1062 d = self.runCommand(cmd) # might raise ConnectionLost 1063 d.addCallback(lambda res: self.commandComplete(cmd)) 1064 d.addCallback(lambda res: self.createSummary(cmd.logs['stdio'])) 1065 d.addCallback(lambda res: self.evaluateCommand(cmd)) # returns results 1066 def _gotResults(results): 1067 self.setStatus(cmd, results) 1068 return results

1069 d.addCallback(_gotResults) # returns results 1070 d.addCallbacks(self.finished, self.checkDisconnect) 1071 d.addErrback(self.failed)

1072

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

1074 """Set up any additional logfiles= logs. 1075 1076 @param cmd: the LoggedRemoteCommand to add additional logs to. 1077 1078 @param logfiles: a dict of tuples (logname,remotefilename) 1079 specifying additional logs to watch. (note: 1080 the remotefilename component is currently 1081 ignored) 1082 """ 1083 for logname,remotefilename in logfiles.items(): 1084 if self.lazylogfiles: 1085 # Ask LoggedRemoteCommand to watch a logfile, but only add 1086 # it when/if we see any data. 1087 # 1088 # The dummy default argument local_logname is a work-around for 1089 # Python name binding; default values are bound by value, but 1090 # captured variables in the body are bound by name. 1091 callback = lambda cmd_arg, local_logname=logname: self.addLog(local_logname) 1092 cmd.useLogDelayed(logname, callback, True) 1093 else: 1094 # tell the BuildStepStatus to add a LogFile 1095 newlog = self.addLog(logname) 1096 # and tell the LoggedRemoteCommand to feed it 1097 cmd.useLog(newlog, True)

1098

1099 - def interrupt(self, reason):

1100 # TODO: consider adding an INTERRUPTED or STOPPED status to use 1101 # instead of FAILURE, might make the text a bit more clear. 1102 # 'reason' can be a Failure, or text 1103 BuildStep.interrupt(self, reason) 1104 if self.step_status.isWaitingForLocks(): 1105 self.addCompleteLog('interrupt while waiting for locks', str(reason)) 1106 else: 1107 self.addCompleteLog('interrupt', str(reason)) 1108 1109 if self.cmd: 1110 d = self.cmd.interrupt(reason) 1111 return d

1112

1113 - def checkDisconnect(self, f):

1114 f.trap(error.ConnectionLost) 1115 self.step_status.setText(self.describe(True) + 1116 ["failed", "slave", "lost"]) 1117 self.step_status.setText2(["failed", "slave", "lost"]) 1118 return self.finished(RETRY)

1119 1120 # to refine the status output, override one or more of the following 1121 # methods. Change as little as possible: start with the first ones on 1122 # this list and only proceed further if you have to 1123 # 1124 # createSummary: add additional Logfiles with summarized results 1125 # evaluateCommand: decides whether the step was successful or not 1126 # 1127 # getText: create the final per-step text strings 1128 # describeText2: create the strings added to the overall build status 1129 # 1130 # getText2: only adds describeText2() when the step affects build status 1131 # 1132 # setStatus: handles all status updating 1133 1134 # commandComplete is available for general-purpose post-completion work. 1135 # It is a good place to do one-time parsing of logfiles, counting 1136 # warnings and errors. It should probably stash such counts in places 1137 # like self.warnings so they can be picked up later by your getText 1138 # method. 1139 1140 # TODO: most of this stuff should really be on BuildStep rather than 1141 # ShellCommand. That involves putting the status-setup stuff in 1142 # .finished, which would make it hard to turn off. 1143

1144 - def commandComplete(self, cmd):

1145 """This is a general-purpose hook method for subclasses. It will be 1146 called after the remote command has finished, but before any of the 1147 other hook functions are called.""" 1148 pass

1149

1150 - def createSummary(self, log):

1151 """To create summary logs, do something like this: 1152 warnings = grep('^Warning:', log.getText()) 1153 self.addCompleteLog('warnings', warnings) 1154 """ 1155 pass

1156

1157 - def evaluateCommand(self, cmd):

1158 """Decide whether the command was SUCCESS, WARNINGS, or FAILURE. 1159 Override this to, say, declare WARNINGS if there is any stderr 1160 activity, or to say that rc!=0 is not actually an error.""" 1161 1162 if self.log_eval_func: 1163 return self.log_eval_func(cmd, self.step_status) 1164 if cmd.rc != 0: 1165 return FAILURE 1166 return SUCCESS

1167

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

1169 if results == SUCCESS: 1170 return self.describe(True) 1171 elif results == WARNINGS: 1172 return self.describe(True) + ["warnings"] 1173 else: 1174 return self.describe(True) + ["failed"]

1175

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

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

1184

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

1186 if results == SUCCESS: 1187 # successful steps do not add anything to the build's text 1188 pass 1189 elif results == WARNINGS: 1190 if (self.flunkOnWarnings or self.warnOnWarnings): 1191 # we're affecting the overall build, so tell them why 1192 return self.getText2(cmd, results) 1193 else: 1194 if (self.haltOnFailure or self.flunkOnFailure 1195 or self.warnOnFailure): 1196 # we're affecting the overall build, so tell them why 1197 return self.getText2(cmd, results) 1198 return []

1199

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

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

1205 1206 1207 # Parses the logs for a list of regexs. Meant to be invoked like: 1208 # regexes = ((re.compile(...), FAILURE), (re.compile(...), WARNINGS)) 1209 # self.addStep(ShellCommand, 1210 # command=..., 1211 # ..., 1212 # log_eval_func=lambda c,s: regex_log_evaluator(c, s, regexs) 1213 # )

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

1215 worst = SUCCESS 1216 if cmd.rc != 0: 1217 worst = FAILURE 1218 for err, possible_status in regexes: 1219 # worst_status returns the worse of the two status' passed to it. 1220 # we won't be changing "worst" unless possible_status is worse than it, 1221 # so we don't even need to check the log if that's the case 1222 if worst_status(worst, possible_status) == possible_status: 1223 if isinstance(err, (basestring)): 1224 err = re.compile(".*%s.*" % err, re.DOTALL) 1225 for l in cmd.logs.values(): 1226 if err.search(l.getText()): 1227 worst = possible_status 1228 return worst

1229 1230 1231 # (WithProperties used to be available in this module) 1232 from buildbot.process.properties import WithProperties 1233 _hush_pyflakes = [WithProperties] 1234 del _hush_pyflakes 1235

Source Code for Module buildbot.process.buildstep