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 import re 17 18 from zope.interface import implements 19 from twisted.internet import defer, error 20 from twisted.protocols import basic 21 from twisted.spread import pb 22 from twisted.python import log, components 23 from twisted.python.failure import Failure 24 from twisted.web.util import formatFailure 25 from twisted.python.reflect import accumulateClassList 26 27 from buildbot import interfaces, util, config 28 from buildbot.status import progress 29 from buildbot.status.results import SUCCESS, WARNINGS, FAILURE, SKIPPED, \ 30 EXCEPTION, RETRY, worst_status 31 from buildbot.process import metrics, properties 32 from buildbot.util.eventual import eventually 33 from buildbot.interfaces import BuildSlaveTooOldError

34 35 -class BuildStepFailed(Exception):

36 pass

37

38 -class RemoteCommand(pb.Referenceable):

39 40 # class-level unique identifier generator for command ids 41 _commandCounter = 0 42 43 active = False 44 rc = None 45 debug = False 46

47 - def __init__(self, remote_command, args, ignore_updates=False, 48 collectStdout=False, collectStderr=False, decodeRC={0:SUCCESS}):

49 self.logs = {} 50 self.delayedLogs = {} 51 self._closeWhenFinished = {} 52 self.collectStdout = collectStdout 53 self.collectStderr = collectStderr 54 self.stdout = '' 55 self.stderr = '' 56 57 self._startTime = None 58 self._remoteElapsed = None 59 self.remote_command = remote_command 60 self.args = args 61 self.ignore_updates = ignore_updates 62 self.decodeRC = decodeRC

63

64 - def __repr__(self):

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

66

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

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

93

94 - def useLog(self, log, closeWhenFinished=False, logfileName=None):

95 assert interfaces.ILogFile.providedBy(log) 96 if not logfileName: 97 logfileName = log.getName() 98 assert logfileName not in self.logs 99 assert logfileName not in self.delayedLogs 100 self.logs[logfileName] = log 101 self._closeWhenFinished[logfileName] = closeWhenFinished

102

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

104 assert logfileName not in self.logs 105 assert logfileName not in self.delayedLogs 106 self.delayedLogs[logfileName] = (activateCallBack, closeWhenFinished)

107

108 - def _start(self):

109 self.updates = {} 110 self._startTime = util.now() 111 112 # This method only initiates the remote command. 113 # We will receive remote_update messages as the command runs. 114 # We will get a single remote_complete when it finishes. 115 # We should fire self.deferred when the command is done. 116 d = self.remote.callRemote("startCommand", self, self.commandID, 117 self.remote_command, self.args) 118 return d

119

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

121 self.active = False 122 # call .remoteComplete. If it raises an exception, or returns the 123 # Failure that we gave it, our self.deferred will be errbacked. If 124 # it does not (either it ate the Failure or there the step finished 125 # normally and it didn't raise a new exception), self.deferred will 126 # be callbacked. 127 d = defer.maybeDeferred(self.remoteComplete, failure) 128 # arrange for the callback to get this RemoteCommand instance 129 # instead of just None 130 d.addCallback(lambda r: self) 131 # this fires the original deferred we returned from .run(), 132 # with self as the result, or a failure 133 d.addBoth(self.deferred.callback)

134

135 - def interrupt(self, why):

136 log.msg("RemoteCommand.interrupt", self, why) 137 if not self.active: 138 log.msg(" but this RemoteCommand is already inactive") 139 return defer.succeed(None) 140 if not self.remote: 141 log.msg(" but our .remote went away") 142 return defer.succeed(None) 143 if isinstance(why, Failure) and why.check(error.ConnectionLost): 144 log.msg("RemoteCommand.disconnect: lost slave") 145 self.remote = None 146 self._finished(why) 147 return defer.succeed(None) 148 149 # tell the remote command to halt. Returns a Deferred that will fire 150 # when the interrupt command has been delivered. 151 152 d = defer.maybeDeferred(self.remote.callRemote, "interruptCommand", 153 self.commandID, str(why)) 154 # the slave may not have remote_interruptCommand 155 d.addErrback(self._interruptFailed) 156 return d

157

158 - def _interruptFailed(self, why):

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

163

164 - def remote_update(self, updates):

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

187

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

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

203

204 - def addStdout(self, data):

205 if 'stdio' in self.logs: 206 self.logs['stdio'].addStdout(data) 207 if self.collectStdout: 208 self.stdout += data

209

210 - def addStderr(self, data):

211 if 'stdio' in self.logs: 212 self.logs['stdio'].addStderr(data) 213 if self.collectStderr: 214 self.stderr += data

215

216 - def addHeader(self, data):

217 if 'stdio' in self.logs: 218 self.logs['stdio'].addHeader(data)

219

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

221 # Activate delayed logs on first data. 222 if logname in self.delayedLogs: 223 (activateCallBack, closeWhenFinished) = self.delayedLogs[logname] 224 del self.delayedLogs[logname] 225 loog = activateCallBack(self) 226 self.logs[logname] = loog 227 self._closeWhenFinished[logname] = closeWhenFinished 228 229 if logname in self.logs: 230 self.logs[logname].addStdout(data) 231 else: 232 log.msg("%s.addToLog: no such log %s" % (self, logname))

233 234 @metrics.countMethod('RemoteCommand.remoteUpdate()')

235 - def remoteUpdate(self, update):

236 if self.debug: 237 for k,v in update.items(): 238 log.msg("Update[%s]: %s" % (k,v)) 239 if update.has_key('stdout'): 240 # 'stdout': data 241 self.addStdout(update['stdout']) 242 if update.has_key('stderr'): 243 # 'stderr': data 244 self.addStderr(update['stderr']) 245 if update.has_key('header'): 246 # 'header': data 247 self.addHeader(update['header']) 248 if update.has_key('log'): 249 # 'log': (logname, data) 250 logname, data = update['log'] 251 self.addToLog(logname, data) 252 if update.has_key('rc'): 253 rc = self.rc = update['rc'] 254 log.msg("%s rc=%s" % (self, rc)) 255 self.addHeader("program finished with exit code %d\n" % rc) 256 if update.has_key('elapsed'): 257 self._remoteElapsed = update['elapsed'] 258 259 # TODO: these should be handled at the RemoteCommand level 260 for k in update: 261 if k not in ('stdout', 'stderr', 'header', 'rc'): 262 if k not in self.updates: 263 self.updates[k] = [] 264 self.updates[k].append(update[k])

265

266 - def remoteComplete(self, maybeFailure):

267 if self._startTime and self._remoteElapsed: 268 delta = (util.now() - self._startTime) - self._remoteElapsed 269 metrics.MetricTimeEvent.log("RemoteCommand.overhead", delta) 270 271 for name,loog in self.logs.items(): 272 if self._closeWhenFinished[name]: 273 if maybeFailure: 274 loog.addHeader("\nremoteFailed: %s" % maybeFailure) 275 else: 276 log.msg("closing log %s" % loog) 277 loog.finish() 278 return maybeFailure

279

280 - def results(self):

281 if self.rc in self.decodeRC: 282 return self.decodeRC[self.rc] 283 return FAILURE

284

285 - def didFail(self):

286 return self.results() == FAILURE

287 LoggedRemoteCommand = RemoteCommand

288 289 290 -class LogObserver:

291 implements(interfaces.ILogObserver) 292

293 - def setStep(self, step):

294 self.step = step

295

296 - def setLog(self, loog):

297 assert interfaces.IStatusLog.providedBy(loog) 298 loog.subscribe(self, True)

299

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

301 if channel == interfaces.LOG_CHANNEL_STDOUT: 302 self.outReceived(text) 303 elif channel == interfaces.LOG_CHANNEL_STDERR: 304 self.errReceived(text)

305 306 # TODO: add a logEnded method? er, stepFinished? 307

308 - def outReceived(self, data):

309 """This will be called with chunks of stdout data. Override this in 310 your observer.""" 311 pass

312

313 - def errReceived(self, data):

314 """This will be called with chunks of stderr data. Override this in 315 your observer.""" 316 pass

317

318 319 -class LogLineObserver(LogObserver):

320 - def __init__(self):

321 self.stdoutParser = basic.LineOnlyReceiver() 322 self.stdoutParser.delimiter = "\n" 323 self.stdoutParser.lineReceived = self.outLineReceived 324 self.stdoutParser.transport = self # for the .disconnecting attribute 325 self.disconnecting = False 326 327 self.stderrParser = basic.LineOnlyReceiver() 328 self.stderrParser.delimiter = "\n" 329 self.stderrParser.lineReceived = self.errLineReceived 330 self.stderrParser.transport = self

331

332 - def setMaxLineLength(self, max_length):

333 """ 334 Set the maximum line length: lines longer than max_length are 335 dropped. Default is 16384 bytes. Use sys.maxint for effective 336 infinity. 337 """ 338 self.stdoutParser.MAX_LENGTH = max_length 339 self.stderrParser.MAX_LENGTH = max_length

340

341 - def outReceived(self, data):

342 self.stdoutParser.dataReceived(data)

343

344 - def errReceived(self, data):

345 self.stderrParser.dataReceived(data)

346

347 - def outLineReceived(self, line):

348 """This will be called with complete stdout lines (not including the 349 delimiter). Override this in your observer.""" 350 pass

351

352 - def errLineReceived(self, line):

353 """This will be called with complete lines of stderr (not including 354 the delimiter). Override this in your observer.""" 355 pass

356

357 358 -class RemoteShellCommand(RemoteCommand):

359 - def __init__(self, workdir, command, env=None, 360 want_stdout=1, want_stderr=1, 361 timeout=20*60, maxTime=None, logfiles={}, 362 usePTY="slave-config", logEnviron=True, 363 collectStdout=False,collectStderr=False, 364 interruptSignal=None, 365 initialStdin=None, decodeRC={0:SUCCESS}, 366 user=None):

367 368 self.command = command # stash .command, set it later 369 if env is not None: 370 # avoid mutating the original master.cfg dictionary. Each 371 # ShellCommand gets its own copy, any start() methods won't be 372 # able to modify the original. 373 env = env.copy() 374 args = {'workdir': workdir, 375 'env': env, 376 'want_stdout': want_stdout, 377 'want_stderr': want_stderr, 378 'logfiles': logfiles, 379 'timeout': timeout, 380 'maxTime': maxTime, 381 'usePTY': usePTY, 382 'logEnviron': logEnviron, 383 'initial_stdin': initialStdin 384 } 385 if interruptSignal is not None: 386 args['interruptSignal'] = interruptSignal 387 if user is not None: 388 args['user'] = user 389 RemoteCommand.__init__(self, "shell", args, collectStdout=collectStdout, 390 collectStderr=collectStderr, 391 decodeRC=decodeRC)

392

393 - def _start(self):

394 self.args['command'] = self.command 395 if self.remote_command == "shell": 396 # non-ShellCommand slavecommands are responsible for doing this 397 # fixup themselves 398 if self.step.slaveVersion("shell", "old") == "old": 399 self.args['dir'] = self.args['workdir'] 400 if ('user' in self.args and 401 self.step.slaveVersionIsOlderThan("shell", "2.16")): 402 m = "slave does not support the 'user' parameter" 403 raise BuildSlaveTooOldError(m) 404 what = "command '%s' in dir '%s'" % (self.args['command'], 405 self.args['workdir']) 406 log.msg(what) 407 return RemoteCommand._start(self)

408

409 - def __repr__(self):

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

411

412 -class _BuildStepFactory(util.ComparableMixin):

413 """ 414 This is a wrapper to record the arguments passed to as BuildStep subclass. 415 We use an instance of this class, rather than a closure mostly to make it 416 easier to test that the right factories are getting created. 417 """ 418 compare_attrs = ['factory', 'args', 'kwargs' ] 419 implements(interfaces.IBuildStepFactory) 420

421 - def __init__(self, factory, *args, **kwargs):

422 self.factory = factory 423 self.args = args 424 self.kwargs = kwargs

425

426 - def buildStep(self):

427 try: 428 return self.factory(*self.args, **self.kwargs) 429 except: 430 log.msg("error while creating step, factory=%s, args=%s, kwargs=%s" 431 % (self.factory, self.args, self.kwargs)) 432 raise

433

434 -class BuildStep(object, properties.PropertiesMixin):

435 436 haltOnFailure = False 437 flunkOnWarnings = False 438 flunkOnFailure = False 439 warnOnWarnings = False 440 warnOnFailure = False 441 alwaysRun = False 442 doStepIf = True 443 hideStepIf = False 444 445 # properties set on a build step are, by nature, always runtime properties 446 set_runtime_properties = True 447 448 # 'parms' holds a list of all the parameters we care about, to allow 449 # users to instantiate a subclass of BuildStep with a mixture of 450 # arguments, some of which are for us, some of which are for the subclass 451 # (or a delegate of the subclass, like how ShellCommand delivers many 452 # arguments to the RemoteShellCommand that it creates). Such delegating 453 # subclasses will use this list to figure out which arguments are meant 454 # for us and which should be given to someone else. 455 parms = ['name', 'locks', 456 'haltOnFailure', 457 'flunkOnWarnings', 458 'flunkOnFailure', 459 'warnOnWarnings', 460 'warnOnFailure', 461 'alwaysRun', 462 'progressMetrics', 463 'useProgress', 464 'doStepIf', 465 'hideStepIf', 466 ] 467 468 name = "generic" 469 locks = [] 470 progressMetrics = () # 'time' is implicit 471 useProgress = True # set to False if step is really unpredictable 472 build = None 473 step_status = None 474 progress = None 475

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

477 for p in self.__class__.parms: 478 if kwargs.has_key(p): 479 setattr(self, p, kwargs[p]) 480 del kwargs[p] 481 if kwargs: 482 config.error("%s.__init__ got unexpected keyword argument(s) %s" \ 483 % (self.__class__, kwargs.keys())) 484 self._pendingLogObservers = [] 485 486 if not isinstance(self.name, str): 487 config.error("BuildStep name must be a string: %r" % (self.name,)) 488 489 self._acquiringLock = None 490 self.stopped = False

491

492 - def __new__(klass, *args, **kwargs):

493 self = object.__new__(klass) 494 self._factory = _BuildStepFactory(klass, *args, **kwargs) 495 return self

496

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

498 return [self.name]

499

500 - def setBuild(self, build):

501 self.build = build

502

503 - def setBuildSlave(self, buildslave):

504 self.buildslave = buildslave

505

506 - def setDefaultWorkdir(self, workdir):

507 pass

508

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

510 # this is here for backwards compatability 511 pass

512

513 - def _getStepFactory(self):

514 return self._factory

515

516 - def setStepStatus(self, step_status):

517 self.step_status = step_status

518

519 - def setupProgress(self):

520 if self.useProgress: 521 sp = progress.StepProgress(self.name, self.progressMetrics) 522 self.progress = sp 523 self.step_status.setProgress(sp) 524 return sp 525 return None

526

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

528 if self.progress: 529 self.progress.setProgress(metric, value)

530

531 - def startStep(self, remote):

532 self.remote = remote 533 self.deferred = defer.Deferred() 534 # convert all locks into their real form 535 self.locks = [(self.build.builder.botmaster.getLockByID(access.lockid), access) 536 for access in self.locks ] 537 # then narrow SlaveLocks down to the slave that this build is being 538 # run on 539 self.locks = [(l.getLock(self.build.slavebuilder.slave), la) 540 for l, la in self.locks ] 541 542 for l, la in self.locks: 543 if l in self.build.locks: 544 log.msg("Hey, lock %s is claimed by both a Step (%s) and the" 545 " parent Build (%s)" % (l, self, self.build)) 546 raise RuntimeError("lock claimed by both Step and Build") 547 548 # Set the step's text here so that the stepStarted notification sees 549 # the correct description 550 self.step_status.setText(self.describe(False)) 551 self.step_status.stepStarted() 552 553 d = self.acquireLocks() 554 d.addCallback(self._startStep_2) 555 d.addErrback(self.failed) 556 return self.deferred

557

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

559 self._acquiringLock = None 560 if not self.locks: 561 return defer.succeed(None) 562 if self.stopped: 563 return defer.succeed(None) 564 log.msg("acquireLocks(step %s, locks %s)" % (self, self.locks)) 565 for lock, access in self.locks: 566 if not lock.isAvailable(self, access): 567 self.step_status.setWaitingForLocks(True) 568 log.msg("step %s waiting for lock %s" % (self, lock)) 569 d = lock.waitUntilMaybeAvailable(self, access) 570 d.addCallback(self.acquireLocks) 571 self._acquiringLock = (lock, access, d) 572 return d 573 # all locks are available, claim them all 574 for lock, access in self.locks: 575 lock.claim(self, access) 576 self.step_status.setWaitingForLocks(False) 577 return defer.succeed(None)

578

579 - def _startStep_2(self, res):

580 if self.stopped: 581 self.finished(EXCEPTION) 582 return 583 584 if self.progress: 585 self.progress.start() 586 587 if isinstance(self.doStepIf, bool): 588 doStep = defer.succeed(self.doStepIf) 589 else: 590 doStep = defer.maybeDeferred(self.doStepIf, self) 591 592 renderables = [] 593 accumulateClassList(self.__class__, 'renderables', renderables) 594 595 def setRenderable(res, attr): 596 setattr(self, attr, res)

597 598 dl = [ doStep ] 599 for renderable in renderables: 600 d = self.build.render(getattr(self, renderable)) 601 d.addCallback(setRenderable, renderable) 602 dl.append(d) 603 dl = defer.gatherResults(dl) 604 605 dl.addCallback(self._startStep_3) 606 return dl

607 608 @defer.inlineCallbacks

609 - def _startStep_3(self, doStep):

610 doStep = doStep[0] 611 try: 612 if doStep: 613 result = yield defer.maybeDeferred(self.start) 614 if result == SKIPPED: 615 doStep = False 616 except: 617 log.msg("BuildStep.startStep exception in .start") 618 self.failed(Failure()) 619 620 if not doStep: 621 self.step_status.setText(self.describe(True) + ['skipped']) 622 self.step_status.setSkipped(True) 623 # this return value from self.start is a shortcut to finishing 624 # the step immediately; we skip calling finished() as 625 # subclasses may have overridden that an expect it to be called 626 # after start() (bug #837) 627 eventually(self._finishFinished, SKIPPED)

628

629 - def start(self):

630 raise NotImplementedError("your subclass must implement this method")

631

632 - def interrupt(self, reason):

633 self.stopped = True 634 if self._acquiringLock: 635 lock, access, d = self._acquiringLock 636 lock.stopWaitingUntilAvailable(self, access, d) 637 d.callback(None)

638

639 - def releaseLocks(self):

640 log.msg("releaseLocks(%s): %s" % (self, self.locks)) 641 for lock, access in self.locks: 642 if lock.isOwner(self, access): 643 lock.release(self, access) 644 else: 645 # This should only happen if we've been interrupted 646 assert self.stopped

647

648 - def finished(self, results):

649 if self.stopped and results != RETRY: 650 # We handle this specially because we don't care about 651 # the return code of an interrupted command; we know 652 # that this should just be exception due to interrupt 653 # At the same time we must respect RETRY status because it's used 654 # to retry interrupted build due to some other issues for example 655 # due to slave lost 656 results = EXCEPTION 657 self.step_status.setText(self.describe(True) + 658 ["interrupted"]) 659 self.step_status.setText2(["interrupted"]) 660 self._finishFinished(results)

661

662 - def _finishFinished(self, results):

663 # internal function to indicate that this step is done; this is separated 664 # from finished() so that subclasses can override finished() 665 if self.progress: 666 self.progress.finish() 667 668 try: 669 hidden = self._maybeEvaluate(self.hideStepIf, results, self) 670 except Exception: 671 why = Failure() 672 self.addHTMLLog("err.html", formatFailure(why)) 673 self.addCompleteLog("err.text", why.getTraceback()) 674 results = EXCEPTION 675 hidden = False 676 677 self.step_status.stepFinished(results) 678 self.step_status.setHidden(hidden) 679 680 self.releaseLocks() 681 self.deferred.callback(results)

682

683 - def failed(self, why):

684 # This can either be a BuildStepFailed exception/failure, meaning we 685 # should call self.finished, or it can be a real exception, which should 686 # be recorded as such. 687 if why.check(BuildStepFailed): 688 self.finished(FAILURE) 689 return 690 691 log.err(why, "BuildStep.failed; traceback follows") 692 try: 693 if self.progress: 694 self.progress.finish() 695 try: 696 self.addCompleteLog("err.text", why.getTraceback()) 697 self.addHTMLLog("err.html", formatFailure(why)) 698 except Exception: 699 log.err(Failure(), "error while formatting exceptions") 700 701 # could use why.getDetailedTraceback() for more information 702 self.step_status.setText([self.name, "exception"]) 703 self.step_status.setText2([self.name]) 704 self.step_status.stepFinished(EXCEPTION) 705 706 hidden = self._maybeEvaluate(self.hideStepIf, EXCEPTION, self) 707 self.step_status.setHidden(hidden) 708 except Exception: 709 log.err(Failure(), "exception during failure processing") 710 # the progress stuff may still be whacked (the StepStatus may 711 # think that it is still running), but the build overall will now 712 # finish 713 714 try: 715 self.releaseLocks() 716 except Exception: 717 log.err(Failure(), "exception while releasing locks") 718 719 log.msg("BuildStep.failed now firing callback") 720 self.deferred.callback(EXCEPTION)

721 722 # utility methods that BuildSteps may find useful 723

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

725 return self.build.getSlaveCommandVersion(command, oldversion)

726

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

728 sv = self.build.getSlaveCommandVersion(command, None) 729 if sv is None: 730 return True 731 if map(int, sv.split(".")) < map(int, minversion.split(".")): 732 return True 733 return False

734

735 - def getSlaveName(self):

736 return self.build.getSlaveName()

737

738 - def addLog(self, name):

739 loog = self.step_status.addLog(name) 740 self._connectPendingLogObservers() 741 return loog

742

743 - def getLog(self, name):

744 for l in self.step_status.getLogs(): 745 if l.getName() == name: 746 return l 747 raise KeyError("no log named '%s'" % (name,))

748

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

750 log.msg("addCompleteLog(%s)" % name) 751 loog = self.step_status.addLog(name) 752 size = loog.chunkSize 753 for start in range(0, len(text), size): 754 loog.addStdout(text[start:start+size]) 755 loog.finish() 756 self._connectPendingLogObservers()

757

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

759 log.msg("addHTMLLog(%s)" % name) 760 self.step_status.addHTMLLog(name, html) 761 self._connectPendingLogObservers()

762

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

764 assert interfaces.ILogObserver.providedBy(observer) 765 observer.setStep(self) 766 self._pendingLogObservers.append((logname, observer)) 767 self._connectPendingLogObservers()

768

769 - def _connectPendingLogObservers(self):

770 if not self._pendingLogObservers: 771 return 772 if not self.step_status: 773 return 774 current_logs = {} 775 for loog in self.step_status.getLogs(): 776 current_logs[loog.getName()] = loog 777 for logname, observer in self._pendingLogObservers[:]: 778 if logname in current_logs: 779 observer.setLog(current_logs[logname]) 780 self._pendingLogObservers.remove((logname, observer))

781

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

783 self.step_status.addURL(name, url)

784

785 - def runCommand(self, c):

786 c.buildslave = self.buildslave 787 d = c.run(self, self.remote) 788 return d

789 790 @staticmethod

791 - def _maybeEvaluate(value, *args, **kwargs):

792 if callable(value): 793 value = value(*args, **kwargs) 794 return value

795 796 components.registerAdapter( 797 BuildStep._getStepFactory, 798 BuildStep, interfaces.IBuildStepFactory) 799 components.registerAdapter( 800 lambda step : interfaces.IProperties(step.build), 801 BuildStep, interfaces.IProperties)

802 803 804 -class OutputProgressObserver(LogObserver):

805 length = 0 806

807 - def __init__(self, name):

808 self.name = name

809

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

811 self.length += len(text) 812 self.step.setProgress(self.name, self.length)

813

814 -class LoggingBuildStep(BuildStep):

815 816 progressMetrics = ('output',) 817 logfiles = {} 818 819 parms = BuildStep.parms + ['logfiles', 'lazylogfiles', 'log_eval_func'] 820 cmd = None 821 822 renderables = [ 'logfiles', 'lazylogfiles' ] 823

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

826 BuildStep.__init__(self, *args, **kwargs) 827 828 if logfiles and not isinstance(logfiles, dict): 829 config.error( 830 "the ShellCommand 'logfiles' parameter must be a dictionary") 831 832 # merge a class-level 'logfiles' attribute with one passed in as an 833 # argument 834 self.logfiles = self.logfiles.copy() 835 self.logfiles.update(logfiles) 836 self.lazylogfiles = lazylogfiles 837 if log_eval_func and not callable(log_eval_func): 838 config.error( 839 "the 'log_eval_func' paramater must be a callable") 840 self.log_eval_func = log_eval_func 841 self.addLogObserver('stdio', OutputProgressObserver("output"))

842

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

844 self.logfiles[logname] = filename

845

846 - def buildCommandKwargs(self):

847 kwargs = dict() 848 kwargs['logfiles'] = self.logfiles 849 return kwargs

850

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

852 """ 853 @param cmd: a suitable RemoteCommand which will be launched, with 854 all output being put into our self.stdio_log LogFile 855 """ 856 log.msg("ShellCommand.startCommand(cmd=%s)" % (cmd,)) 857 log.msg(" cmd.args = %r" % (cmd.args)) 858 self.cmd = cmd # so we can interrupt it 859 self.step_status.setText(self.describe(False)) 860 861 # stdio is the first log 862 self.stdio_log = stdio_log = self.addLog("stdio") 863 cmd.useLog(stdio_log, True) 864 for em in errorMessages: 865 stdio_log.addHeader(em) 866 # TODO: consider setting up self.stdio_log earlier, and have the 867 # code that passes in errorMessages instead call 868 # self.stdio_log.addHeader() directly. 869 870 # there might be other logs 871 self.setupLogfiles(cmd, self.logfiles) 872 873 d = self.runCommand(cmd) # might raise ConnectionLost 874 d.addCallback(lambda res: self.commandComplete(cmd)) 875 d.addCallback(lambda res: self.createSummary(cmd.logs['stdio'])) 876 d.addCallback(lambda res: self.evaluateCommand(cmd)) # returns results 877 def _gotResults(results): 878 self.setStatus(cmd, results) 879 return results

880 d.addCallback(_gotResults) # returns results 881 d.addCallbacks(self.finished, self.checkDisconnect) 882 d.addErrback(self.failed)

883

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

885 for logname,remotefilename in logfiles.items(): 886 if self.lazylogfiles: 887 # Ask RemoteCommand to watch a logfile, but only add 888 # it when/if we see any data. 889 # 890 # The dummy default argument local_logname is a work-around for 891 # Python name binding; default values are bound by value, but 892 # captured variables in the body are bound by name. 893 callback = lambda cmd_arg, local_logname=logname: self.addLog(local_logname) 894 cmd.useLogDelayed(logname, callback, True) 895 else: 896 # tell the BuildStepStatus to add a LogFile 897 newlog = self.addLog(logname) 898 # and tell the RemoteCommand to feed it 899 cmd.useLog(newlog, True)

900

901 - def interrupt(self, reason):

902 # TODO: consider adding an INTERRUPTED or STOPPED status to use 903 # instead of FAILURE, might make the text a bit more clear. 904 # 'reason' can be a Failure, or text 905 BuildStep.interrupt(self, reason) 906 if self.step_status.isWaitingForLocks(): 907 self.addCompleteLog('interrupt while waiting for locks', str(reason)) 908 else: 909 self.addCompleteLog('interrupt', str(reason)) 910 911 if self.cmd: 912 d = self.cmd.interrupt(reason) 913 d.addErrback(log.err, 'while interrupting command')

914

915 - def checkDisconnect(self, f):

916 f.trap(error.ConnectionLost) 917 self.step_status.setText(self.describe(True) + 918 ["exception", "slave", "lost"]) 919 self.step_status.setText2(["exception", "slave", "lost"]) 920 return self.finished(RETRY)

921

922 - def commandComplete(self, cmd):

923 pass

924

925 - def createSummary(self, stdio):

926 pass

927

928 - def evaluateCommand(self, cmd):

929 if self.log_eval_func: 930 return self.log_eval_func(cmd, self.step_status) 931 return cmd.results()

932

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

934 if results == SUCCESS: 935 return self.describe(True) 936 elif results == WARNINGS: 937 return self.describe(True) + ["warnings"] 938 elif results == EXCEPTION: 939 return self.describe(True) + ["exception"] 940 else: 941 return self.describe(True) + ["failed"]

942

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

944 return [self.name]

945

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

947 if results == SUCCESS: 948 # successful steps do not add anything to the build's text 949 pass 950 elif results == WARNINGS: 951 if (self.flunkOnWarnings or self.warnOnWarnings): 952 # we're affecting the overall build, so tell them why 953 return self.getText2(cmd, results) 954 else: 955 if (self.haltOnFailure or self.flunkOnFailure 956 or self.warnOnFailure): 957 # we're affecting the overall build, so tell them why 958 return self.getText2(cmd, results) 959 return []

960

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

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

966

967 968 # Parses the logs for a list of regexs. Meant to be invoked like: 969 # regexes = ((re.compile(...), FAILURE), (re.compile(...), WARNINGS)) 970 # self.addStep(ShellCommand, 971 # command=..., 972 # ..., 973 # log_eval_func=lambda c,s: regex_log_evaluator(c, s, regexs) 974 # ) 975 -def regex_log_evaluator(cmd, step_status, regexes):

976 worst = cmd.results() 977 for err, possible_status in regexes: 978 # worst_status returns the worse of the two status' passed to it. 979 # we won't be changing "worst" unless possible_status is worse than it, 980 # so we don't even need to check the log if that's the case 981 if worst_status(worst, possible_status) == possible_status: 982 if isinstance(err, (basestring)): 983 err = re.compile(".*%s.*" % err, re.DOTALL) 984 for l in cmd.logs.values(): 985 if err.search(l.getText()): 986 worst = possible_status 987 return worst

988 989 # (WithProperties used to be available in this module) 990 from buildbot.process.properties import WithProperties 991 _hush_pyflakes = [WithProperties] 992 del _hush_pyflakes 993

Source Code for Module buildbot.process.buildstep