GoogleGit

blob: 497f7c131169bc12dee48772604c91ab43f6ed04 [file] [log] [blame]
  1. #!/usr/bin/env python
  2. # Copyright (c) 2013 The Chromium Authors. All rights reserved.
  3. # Use of this source code is governed by a BSD-style license that can be
  4. # found in the LICENSE file.
  5. """Contains generating and parsing systems of the Chromium Buildbot Annotator.
  6. When executed as a script, this reads step name / command pairs from a file and
  7. executes those lines while annotating the output. The input is json:
  8. [{"name": "step_name", "cmd": ["command", "arg1", "arg2"]},
  9. {"name": "step_name2", "cmd": ["command2", "arg1"]}]
  10. """
  11. import calendar
  12. import contextlib
  13. import datetime
  14. import json
  15. import optparse
  16. import os
  17. import subprocess
  18. import sys
  19. import threading
  20. import traceback
  21. # These are maps of annotation key -> number of expected arguments.
  22. STEP_ANNOTATIONS = {
  23. 'SET_BUILD_PROPERTY': 2,
  24. 'STEP_CLEAR': 0,
  25. 'STEP_EXCEPTION': 0,
  26. 'STEP_FAILURE': 0,
  27. 'STEP_LINK': 2,
  28. 'STEP_LOG_END': 1,
  29. 'STEP_LOG_END_PERF': 2,
  30. 'STEP_LOG_LINE': 2,
  31. 'STEP_SUMMARY_CLEAR': 0,
  32. 'STEP_SUMMARY_TEXT': 1,
  33. 'STEP_TEXT': 1,
  34. 'STEP_TRIGGER': 1,
  35. 'STEP_WARNINGS': 0,
  36. }
  37. CONTROL_ANNOTATIONS = {
  38. 'STEP_CLOSED': 0,
  39. 'STEP_STARTED': 0,
  40. }
  41. STREAM_ANNOTATIONS = {
  42. 'HALT_ON_FAILURE': 0,
  43. 'HONOR_ZERO_RETURN_CODE': 0,
  44. 'SEED_STEP': 1,
  45. 'SEED_STEP_TEXT': 2,
  46. 'STEP_CURSOR': 1,
  47. }
  48. DEPRECATED_ANNOTATIONS = {
  49. 'BUILD_STEP': 1,
  50. }
  51. ALL_ANNOTATIONS = {}
  52. ALL_ANNOTATIONS.update(STEP_ANNOTATIONS)
  53. ALL_ANNOTATIONS.update(CONTROL_ANNOTATIONS)
  54. ALL_ANNOTATIONS.update(STREAM_ANNOTATIONS)
  55. ALL_ANNOTATIONS.update(DEPRECATED_ANNOTATIONS)
  56. # This is a mapping of old_annotation_name -> new_annotation_name.
  57. # Theoretically all annotator scripts should use the new names, but it's hard
  58. # to tell due to the decentralized nature of the annotator.
  59. DEPRECATED_ALIASES = {
  60. 'BUILD_FAILED': 'STEP_FAILURE',
  61. 'BUILD_WARNINGS': 'STEP_WARNINGS',
  62. 'BUILD_EXCEPTION': 'STEP_EXCEPTION',
  63. 'link': 'STEP_LINK',
  64. }
  65. # A couple of the annotations have the format:
  66. # @@@THING arg@@@
  67. # for reasons no one knows. We only need this case until all masters have been
  68. # restarted to pick up the new master-side parsing code.
  69. OLD_STYLE_ANNOTATIONS = set((
  70. 'SEED_STEP',
  71. 'STEP_CURSOR',
  72. ))
  73. def emit(line, stream, flush_before=None):
  74. if flush_before:
  75. flush_before.flush()
  76. print >> stream
  77. # WinDOS can only handle 64kb of output to the console at a time, per process.
  78. if sys.platform.startswith('win'):
  79. lim = 2**15
  80. while line:
  81. to_print, line = line[:lim], line[lim:]
  82. stream.write(to_print)
  83. stream.write('\n')
  84. else:
  85. print >> stream, line
  86. stream.flush()
  87. class MetaAnnotationPrinter(type):
  88. def __new__(mcs, name, bases, dct):
  89. annotation_map = dct.get('ANNOTATIONS')
  90. if annotation_map:
  91. for key, v in annotation_map.iteritems():
  92. key = key.lower()
  93. dct[key] = mcs.make_printer_fn(key, v)
  94. return type.__new__(mcs, name, bases, dct)
  95. @staticmethod
  96. def make_printer_fn(name, n_args):
  97. """Generates a method which emits an annotation to the log stream."""
  98. upname = name.upper()
  99. if upname in OLD_STYLE_ANNOTATIONS:
  100. assert n_args >= 1
  101. fmt = '@@@%s %%s%s@@@' % (upname, '@%s' * (n_args - 1))
  102. else:
  103. fmt = '@@@%s%s@@@' % (upname, '@%s' * n_args)
  104. inner_args = n_args + 1 # self counts
  105. infix = '1 argument' if inner_args == 1 else ('%d arguments' % inner_args)
  106. err = '%s() takes %s (%%d given)' % (name, infix)
  107. def printer(self, *args):
  108. if len(args) != n_args:
  109. raise TypeError(err % (len(args) + 1))
  110. self.emit(fmt % args)
  111. printer.__name__ = name
  112. printer.__doc__ = """Emits an annotation for %s.""" % name.upper()
  113. return printer
  114. class AnnotationPrinter(object):
  115. """A derivable class which will inject annotation-printing methods into the
  116. subclass.
  117. A subclass should define a class variable ANNOTATIONS equal to a
  118. dictionary of the form { '<ANNOTATION_NAME>': <# args> }. This class will
  119. then inject methods whose names are the undercased version of your
  120. annotation names, and which take the number of arguments specified in the
  121. dictionary.
  122. Example:
  123. >>> my_annotations = { 'STEP_LOG_LINE': 2 }
  124. >>> class MyObj(AnnotationPrinter):
  125. ... ANNOTATIONS = my_annotations
  126. ...
  127. >>> o = MyObj()
  128. >>> o.step_log_line('logname', 'here is a line to put in the log')
  129. @@@STEP_LOG_LINE@logname@here is a line to put in the log@@@
  130. >>> o.step_log_line()
  131. Traceback (most recent call last):
  132. File "<stdin>", line 1, in <module>
  133. TypeError: step_log_line() takes exactly 3 arguments (1 given)
  134. >>> o.setp_log_line.__doc__
  135. "Emits an annotation for STEP_LOG_LINE."
  136. >>>
  137. """
  138. __metaclass__ = MetaAnnotationPrinter
  139. def __init__(self, stream, flush_before):
  140. self.stream = stream
  141. self.flush_before = flush_before
  142. def emit(self, line):
  143. emit(line, self.stream, self.flush_before)
  144. class StepCommands(AnnotationPrinter):
  145. """Class holding step commands. Intended to be subclassed."""
  146. ANNOTATIONS = STEP_ANNOTATIONS
  147. def __init__(self, stream, flush_before):
  148. super(StepCommands, self).__init__(stream, flush_before)
  149. self.emitted_logs = set()
  150. def write_log_lines(self, logname, lines, perf=None):
  151. if logname in self.emitted_logs:
  152. raise ValueError('Log %s has been emitted multiple times.' % logname)
  153. self.emitted_logs.add(logname)
  154. logname = logname.replace('/', '&#x2f;')
  155. for line in lines:
  156. self.step_log_line(logname, line)
  157. if perf:
  158. self.step_log_end_perf(logname, perf)
  159. else:
  160. self.step_log_end(logname)
  161. class StepControlCommands(AnnotationPrinter):
  162. """Subclass holding step control commands. Intended to be subclassed.
  163. This is subclassed out so callers in StructuredAnnotationStep can't call
  164. step_started() or step_closed().
  165. """
  166. ANNOTATIONS = CONTROL_ANNOTATIONS
  167. class StructuredAnnotationStep(StepCommands):
  168. """Helper class to provide context for a step."""
  169. def __init__(self, annotation_stream, *args, **kwargs):
  170. self.annotation_stream = annotation_stream
  171. super(StructuredAnnotationStep, self).__init__(*args, **kwargs)
  172. self.control = StepControlCommands(self.stream, self.flush_before)
  173. self.emitted_logs = set()
  174. def __enter__(self):
  175. return self.step_started()
  176. def step_started(self):
  177. self.control.step_started()
  178. return self
  179. def __exit__(self, exc_type, exc_value, tb):
  180. self.annotation_stream.step_cursor(self.annotation_stream.current_step)
  181. #TODO(martinis) combine this and step_ended
  182. if exc_type:
  183. self.step_exception_occured(exc_type, exc_value, tb)
  184. self.control.step_closed()
  185. self.annotation_stream.current_step = ''
  186. return not exc_type
  187. def step_exception_occured(self, exc_type, exc_value, tb):
  188. trace = traceback.format_exception(exc_type, exc_value, tb)
  189. trace_lines = ''.join(trace).split('\n')
  190. self.write_log_lines('exception', filter(None, trace_lines))
  191. self.step_exception()
  192. def step_ended(self):
  193. self.annotation_stream.step_cursor(self.annotation_stream.current_step)
  194. self.control.step_closed()
  195. self.annotation_stream.current_step = ''
  196. return True
  197. class AdvancedAnnotationStep(StepCommands, StepControlCommands):
  198. """Holds additional step functions for finer step control.
  199. Most users will want to use StructuredAnnotationSteps generated from a
  200. StructuredAnnotationStream as these handle state automatically.
  201. """
  202. def __init__(self, *args, **kwargs):
  203. super(AdvancedAnnotationStep, self).__init__(*args, **kwargs)
  204. class AdvancedAnnotationStream(AnnotationPrinter):
  205. """Holds individual annotation generating functions for streams.
  206. Most callers should use StructuredAnnotationStream to simplify coding and
  207. avoid errors. For the rare cases where StructuredAnnotationStream is
  208. insufficient (parallel step execution), the individual functions are exposed
  209. here.
  210. """
  211. ANNOTATIONS = STREAM_ANNOTATIONS
  212. class StructuredAnnotationStream(AdvancedAnnotationStream):
  213. """Provides an interface to handle an annotated build.
  214. StructuredAnnotationStream handles most of the step setup and closure calls
  215. for you. All you have to do is execute your code within the steps and set any
  216. failures or warnings that come up. You may optionally provide a list of steps
  217. to seed before execution.
  218. Usage:
  219. stream = StructuredAnnotationStream()
  220. with stream.step('compile') as s:
  221. # do something
  222. if error:
  223. s.step_failure()
  224. with stream.step('test') as s:
  225. # do something
  226. if warnings:
  227. s.step_warnings()
  228. """
  229. def __init__(self, stream=sys.stdout,
  230. flush_before=sys.stderr,
  231. seed_steps=None): # pylint: disable=W0613
  232. super(StructuredAnnotationStream, self).__init__(stream=stream,
  233. flush_before=flush_before)
  234. self.current_step = ''
  235. def step(self, name):
  236. """Provide a context with which to execute a step."""
  237. if self.current_step:
  238. raise Exception('Can\'t start step %s while in step %s.' % (
  239. name, self.current_step))
  240. self.seed_step(name)
  241. self.step_cursor(name)
  242. self.current_step = name
  243. return StructuredAnnotationStep(self, stream=self.stream,
  244. flush_before=self.flush_before)
  245. def MatchAnnotation(line, callback_implementor):
  246. """Call back into |callback_implementor| if line contains an annotation.
  247. Args:
  248. line (str) - The line to analyze
  249. callback_implementor (object) - An object which contains methods
  250. corresponding to all of the annotations in the |ALL_ANNOTATIONS|
  251. dictionary. For example, it should contain a method STEP_SUMMARY_TEXT
  252. taking a single argument.
  253. Parsing method:
  254. * if line doesn't match /^@@@.*@@@$/, return without calling back
  255. * Look for the first '@' or ' '
  256. """
  257. if not (line.startswith('@@@') and line.endswith('@@@') and len(line) > 6):
  258. return
  259. line = line[3:-3]
  260. # look until the first @ or ' '
  261. idx = min((x for x in (line.find('@'), line.find(' '), len(line)) if x > 0))
  262. cmd_text = line[:idx]
  263. cmd = DEPRECATED_ALIASES.get(cmd_text, cmd_text)
  264. field_count = ALL_ANNOTATIONS.get(cmd)
  265. if field_count is None:
  266. raise Exception('Unrecognized annotator command "%s"' % cmd_text)
  267. if field_count:
  268. if idx == len(line):
  269. raise Exception('Annotator command "%s" expects %d args, got 0.'
  270. % (cmd_text, field_count))
  271. line = line[idx+1:]
  272. args = line.split('@', field_count-1)
  273. if len(args) != field_count:
  274. raise Exception('Annotator command "%s" expects %d args, got %d.'
  275. % (cmd_text, field_count, len(args)))
  276. else:
  277. line = line[len(cmd_text):]
  278. if line:
  279. raise Exception('Annotator command "%s" expects no args, got cruft "%s".'
  280. % (cmd_text, line))
  281. args = []
  282. fn = getattr(callback_implementor, cmd, None)
  283. if fn is None:
  284. raise Exception('"%s" does not implement "%s"'
  285. % (callback_implementor, cmd))
  286. fn(*args)
  287. def _merge_envs(original, override):
  288. """Merges two environments.
  289. Returns a new environment dict with entries from |override| overwriting
  290. corresponding entries in |original|. Keys whose value is None will completely
  291. remove the environment variable. Values can contain %(KEY)s strings, which
  292. will be substituted with the values from the original (useful for amending, as
  293. opposed to overwriting, variables like PATH).
  294. """
  295. result = original.copy()
  296. if not override:
  297. return result
  298. for k, v in override.items():
  299. if v is None:
  300. if k in result:
  301. del result[k]
  302. else:
  303. result[str(k)] = str(v) % original
  304. return result
  305. def _validate_step(step):
  306. """Validates parameters of the step.
  307. Returns None if it's OK, error message if not.
  308. """
  309. for req in ['cmd', 'name']:
  310. if req not in step:
  311. return 'missing \'%s\' parameter' % (req,)
  312. if 'cwd' in step and not os.path.isabs(step['cwd']):
  313. return '\'cwd\' should be an absolute path'
  314. return None
  315. def print_step(step, env, stream):
  316. """Prints the step command and relevant metadata.
  317. Intended to be similar to the information that Buildbot prints at the
  318. beginning of each non-annotator step.
  319. """
  320. step_info_lines = []
  321. step_info_lines.append(' '.join(step['cmd']))
  322. step_info_lines.append('in dir %s:' % (step['cwd'] or os.getcwd()))
  323. for key, value in sorted(step.items()):
  324. if value is not None:
  325. if callable(value):
  326. # This prevents functions from showing up as:
  327. # '<function foo at 0x7f523ec7a410>'
  328. # which is tricky to test.
  329. value = value.__name__+'(...)'
  330. step_info_lines.append(' %s: %s' % (key, value))
  331. step_info_lines.append('full environment:')
  332. for key, value in sorted(env.items()):
  333. step_info_lines.append(' %s: %s' % (key, value))
  334. step_info_lines.append('')
  335. stream.emit('\n'.join(step_info_lines))
  336. @contextlib.contextmanager
  337. def modify_lookup_path(path):
  338. """Places the specified path into os.environ.
  339. Necessary because subprocess.Popen uses os.environ to perform lookup on the
  340. supplied command, and only uses the |env| kwarg for modifying the environment
  341. of the child process.
  342. """
  343. saved_path = os.environ['PATH']
  344. try:
  345. if path is not None:
  346. os.environ['PATH'] = path
  347. yield
  348. finally:
  349. os.environ['PATH'] = saved_path
  350. def normalizeChange(change):
  351. assert isinstance(change, dict), 'Change is not a dict'
  352. change = change.copy()
  353. # Convert when_timestamp to UNIX timestamp.
  354. when = change.get('when_timestamp')
  355. if isinstance(when, datetime.datetime):
  356. when = calendar.timegm(when.utctimetuple())
  357. change['when_timestamp'] = when
  358. return change
  359. def triggerBuilds(step, trigger_specs):
  360. assert trigger_specs is not None
  361. for trig in trigger_specs:
  362. builder_name = trig.get('builder_name')
  363. if not builder_name:
  364. raise ValueError('Trigger spec: builder_name is not set')
  365. changes = trig.get('buildbot_changes', [])
  366. assert isinstance(changes, list), 'buildbot_changes must be a list'
  367. changes = map(normalizeChange, changes)
  368. step.step_trigger(json.dumps({
  369. 'builderNames': [builder_name],
  370. 'bucket': trig.get('bucket'),
  371. 'changes': changes,
  372. 'properties': trig.get('properties'),
  373. }, sort_keys=True))
  374. def run_step(stream, name, cmd,
  375. cwd=None, env=None,
  376. allow_subannotations=False,
  377. trigger_specs=None,
  378. **kwargs):
  379. """Runs a single step.
  380. Context:
  381. stream: StructuredAnnotationStream to use to emit step
  382. Step parameters:
  383. name: name of the step, will appear in buildbots waterfall
  384. cmd: command to run, list of one or more strings
  385. cwd: absolute path to working directory for the command
  386. env: dict with overrides for environment variables
  387. allow_subannotations: if True, lets the step emit its own annotations
  388. trigger_specs: a list of trigger specifications, which are dict with keys:
  389. properties: a dict of properties.
  390. Buildbot requires buildername property.
  391. Known kwargs:
  392. stdout: Path to a file to put step stdout into. If used, stdout won't appear
  393. in annotator's stdout (and |allow_subannotations| is ignored).
  394. stderr: Path to a file to put step stderr into. If used, stderr won't appear
  395. in annotator's stderr.
  396. stdin: Path to a file to read step stdin from.
  397. Returns the returncode of the step.
  398. """
  399. if isinstance(cmd, basestring):
  400. cmd = (cmd,)
  401. cmd = map(str, cmd)
  402. # For error reporting.
  403. step_dict = kwargs.copy()
  404. step_dict.update({
  405. 'name': name,
  406. 'cmd': cmd,
  407. 'cwd': cwd,
  408. 'env': env,
  409. 'allow_subannotations': allow_subannotations,
  410. })
  411. step_env = _merge_envs(os.environ, env)
  412. step_annotation = stream.step(name)
  413. step_annotation.step_started()
  414. print_step(step_dict, step_env, stream)
  415. returncode = 0
  416. if cmd:
  417. try:
  418. # Open file handles for IO redirection based on file names in step_dict.
  419. fhandles = {
  420. 'stdout': subprocess.PIPE,
  421. 'stderr': subprocess.PIPE,
  422. 'stdin': None,
  423. }
  424. for key in fhandles:
  425. if key in step_dict:
  426. fhandles[key] = open(step_dict[key],
  427. 'rb' if key == 'stdin' else 'wb')
  428. if sys.platform.startswith('win'):
  429. # Windows has a bad habit of opening a dialog when a console program
  430. # crashes, rather than just letting it crash. Therefore, when a program
  431. # crashes on Windows, we don't find out until the build step times out.
  432. # This code prevents the dialog from appearing, so that we find out
  433. # immediately and don't waste time waiting for a user to close the
  434. # dialog.
  435. import ctypes
  436. # SetErrorMode(SEM_NOGPFAULTERRORBOX). For more information, see:
  437. # https://msdn.microsoft.com/en-us/library/windows/desktop/ms680621.aspx
  438. ctypes.windll.kernel32.SetErrorMode(0x0002)
  439. # CREATE_NO_WINDOW. For more information, see:
  440. # https://msdn.microsoft.com/en-us/library/windows/desktop/ms684863.aspx
  441. creationflags = 0x8000000
  442. else:
  443. creationflags = 0
  444. with modify_lookup_path(step_env.get('PATH')):
  445. proc = subprocess.Popen(
  446. cmd,
  447. env=step_env,
  448. cwd=cwd,
  449. universal_newlines=True,
  450. creationflags=creationflags,
  451. **fhandles)
  452. # Safe to close file handles now that subprocess has inherited them.
  453. for handle in fhandles.itervalues():
  454. if isinstance(handle, file):
  455. handle.close()
  456. outlock = threading.Lock()
  457. def filter_lines(lock, allow_subannotations, inhandle, outhandle):
  458. while True:
  459. line = inhandle.readline()
  460. if not line:
  461. break
  462. lock.acquire()
  463. try:
  464. if not allow_subannotations and line.startswith('@@@'):
  465. outhandle.write('!')
  466. outhandle.write(line)
  467. outhandle.flush()
  468. finally:
  469. lock.release()
  470. # Pump piped stdio through filter_lines. IO going to files on disk is
  471. # not filtered.
  472. threads = []
  473. for key in ('stdout', 'stderr'):
  474. if fhandles[key] == subprocess.PIPE:
  475. inhandle = getattr(proc, key)
  476. outhandle = getattr(sys, key)
  477. threads.append(threading.Thread(
  478. target=filter_lines,
  479. args=(outlock, allow_subannotations, inhandle, outhandle)))
  480. for th in threads:
  481. th.start()
  482. proc.wait()
  483. for th in threads:
  484. th.join()
  485. returncode = proc.returncode
  486. except OSError:
  487. # File wasn't found, error will be reported to stream when the exception
  488. # crosses the context manager.
  489. step_annotation.step_exception_occured(*sys.exc_info())
  490. raise
  491. # TODO(martiniss) move logic into own module?
  492. if trigger_specs:
  493. triggerBuilds(step_annotation, trigger_specs)
  494. return step_annotation, returncode
  495. def update_build_failure(failure, retcode, **_kwargs):
  496. """Potentially moves failure from False to True, depending on returncode of
  497. the run step and the step's configuration.
  498. can_fail_build: A boolean indicating that a bad retcode for this step should
  499. be intepreted as a build failure.
  500. Returns new value for failure.
  501. Called externally from annotated_run, which is why it's a separate function.
  502. """
  503. # TODO(iannucci): Allow step to specify "OK" return values besides 0?
  504. return failure or retcode
  505. def run_steps(steps, build_failure):
  506. for step in steps:
  507. error = _validate_step(step)
  508. if error:
  509. print 'Invalid step - %s\n%s' % (error, json.dumps(step, indent=2))
  510. sys.exit(1)
  511. stream = StructuredAnnotationStream()
  512. ret_codes = []
  513. build_failure = False
  514. prev_annotation = None
  515. for step in steps:
  516. if build_failure and not step.get('always_run', False):
  517. ret = None
  518. else:
  519. prev_annotation, ret = run_step(stream, **step)
  520. stream = prev_annotation.annotation_stream
  521. if ret > 0:
  522. stream.step_cursor(stream.current_step)
  523. stream.emit('step returned non-zero exit code: %d' % ret)
  524. prev_annotation.step_failure()
  525. prev_annotation.step_ended()
  526. build_failure = update_build_failure(build_failure, ret)
  527. ret_codes.append(ret)
  528. if prev_annotation:
  529. prev_annotation.step_ended()
  530. return build_failure, ret_codes
  531. def main():
  532. usage = '%s <command list file or - for stdin>' % sys.argv[0]
  533. parser = optparse.OptionParser(usage=usage)
  534. _, args = parser.parse_args()
  535. if not args:
  536. parser.error('Must specify an input filename.')
  537. if len(args) > 1:
  538. parser.error('Too many arguments specified.')
  539. steps = []
  540. def force_list_str(lst):
  541. ret = []
  542. for v in lst:
  543. if isinstance(v, basestring):
  544. v = str(v)
  545. elif isinstance(v, list):
  546. v = force_list_str(v)
  547. elif isinstance(v, dict):
  548. v = force_dict_strs(v)
  549. ret.append(v)
  550. return ret
  551. def force_dict_strs(obj):
  552. ret = {}
  553. for k, v in obj.iteritems():
  554. if isinstance(v, basestring):
  555. v = str(v)
  556. elif isinstance(v, list):
  557. v = force_list_str(v)
  558. elif isinstance(v, dict):
  559. v = force_dict_strs(v)
  560. ret[str(k)] = v
  561. return ret
  562. if args[0] == '-':
  563. steps.extend(json.load(sys.stdin, object_hook=force_dict_strs))
  564. else:
  565. with open(args[0], 'rb') as f:
  566. steps.extend(json.load(f, object_hook=force_dict_strs))
  567. return 1 if run_steps(steps, False)[0] else 0
  568. if __name__ == '__main__':
  569. sys.exit(main())