diff options
Diffstat (limited to 'src/jaegertracing/thrift/test/crossrunner/report.py')
| -rw-r--r-- | src/jaegertracing/thrift/test/crossrunner/report.py | 441 |
1 files changed, 441 insertions, 0 deletions
diff --git a/src/jaegertracing/thrift/test/crossrunner/report.py b/src/jaegertracing/thrift/test/crossrunner/report.py new file mode 100644 index 000000000..5baf16195 --- /dev/null +++ b/src/jaegertracing/thrift/test/crossrunner/report.py @@ -0,0 +1,441 @@ +# +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you under the Apache License, Version 2.0 (the +# "License"); you may not use this file except in compliance +# with the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, +# software distributed under the License is distributed on an +# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +# KIND, either express or implied. See the License for the +# specific language governing permissions and limitations +# under the License. +# + +from __future__ import print_function +import datetime +import json +import multiprocessing +import os +import platform +import re +import subprocess +import sys +import time +import traceback + +from .compat import logfile_open, path_join, str_join +from .test import TestEntry + +LOG_DIR = 'log' +RESULT_HTML = 'index.html' +RESULT_JSON = 'results.json' +FAIL_JSON = 'known_failures_%s.json' + + +def generate_known_failures(testdir, overwrite, save, out): + def collect_failures(results): + success_index = 5 + for r in results: + if not r[success_index]: + yield TestEntry.get_name(*r) + try: + with logfile_open(path_join(testdir, RESULT_JSON), 'r') as fp: + results = json.load(fp) + except IOError: + sys.stderr.write('Unable to load last result. Did you run tests ?\n') + return False + fails = collect_failures(results['results']) + if not overwrite: + known = load_known_failures(testdir) + known.extend(fails) + fails = known + fails_json = json.dumps(sorted(set(fails)), indent=2, separators=(',', ': ')) + if save: + with logfile_open(os.path.join(testdir, FAIL_JSON % platform.system()), 'w+') as fp: + fp.write(fails_json) + sys.stdout.write('Successfully updated known failures.\n') + if out: + sys.stdout.write(fails_json) + sys.stdout.write('\n') + return True + + +def load_known_failures(testdir): + try: + with logfile_open(path_join(testdir, FAIL_JSON % platform.system()), 'r') as fp: + return json.load(fp) + except IOError: + return [] + + +class TestReporter(object): + # Unfortunately, standard library doesn't handle timezone well + # DATETIME_FORMAT = '%a %b %d %H:%M:%S %Z %Y' + DATETIME_FORMAT = '%a %b %d %H:%M:%S %Y' + + def __init__(self): + self._log = multiprocessing.get_logger() + self._lock = multiprocessing.Lock() + + @classmethod + def test_logfile(cls, test_name, prog_kind, dir=None): + relpath = path_join('log', '%s_%s.log' % (test_name, prog_kind)) + return relpath if not dir else os.path.realpath(path_join(dir, relpath)) + + def _start(self): + self._start_time = time.time() + + @property + def _elapsed(self): + return time.time() - self._start_time + + @classmethod + def _format_date(cls): + return '%s' % datetime.datetime.now().strftime(cls.DATETIME_FORMAT) + + def _print_date(self): + print(self._format_date(), file=self.out) + + def _print_bar(self, out=None): + print( + '===============================================================================', + file=(out or self.out)) + + def _print_exec_time(self): + print('Test execution took {:.1f} seconds.'.format(self._elapsed), file=self.out) + + +class ExecReporter(TestReporter): + def __init__(self, testdir, test, prog): + super(ExecReporter, self).__init__() + self._test = test + self._prog = prog + self.logpath = self.test_logfile(test.name, prog.kind, testdir) + self.out = None + + def begin(self): + self._start() + self._open() + if self.out and not self.out.closed: + self._print_header() + else: + self._log.debug('Output stream is not available.') + + def end(self, returncode): + self._lock.acquire() + try: + if self.out and not self.out.closed: + self._print_footer(returncode) + self._close() + self.out = None + else: + self._log.debug('Output stream is not available.') + finally: + self._lock.release() + + def killed(self): + print(file=self.out) + print('Server process is successfully killed.', file=self.out) + self.end(None) + + def died(self): + print(file=self.out) + print('*** Server process has died unexpectedly ***', file=self.out) + self.end(None) + + _init_failure_exprs = { + 'server': list(map(re.compile, [ + '[Aa]ddress already in use', + 'Could not bind', + 'EADDRINUSE', + ])), + 'client': list(map(re.compile, [ + '[Cc]onnection refused', + 'Could not connect to', + 'Could not open UNIX ', # domain socket (rb) + 'ECONNREFUSED', + 'econnrefused', # erl + 'CONNECTION-REFUSED-ERROR', # cl + 'connect ENOENT', # nodejs domain socket + 'No such file or directory', # domain socket + 'Sockets.TcpClient.Connect', # csharp + ])), + } + + def maybe_false_positive(self): + """Searches through log file for socket bind error. + Returns True if suspicious expression is found, otherwise False""" + try: + if self.out and not self.out.closed: + self.out.flush() + exprs = self._init_failure_exprs[self._prog.kind] + + def match(line): + for expr in exprs: + if expr.search(line): + self._log.info("maybe false positive: %s" % line) + return True + + with logfile_open(self.logpath, 'r') as fp: + if any(map(match, fp)): + return True + except (KeyboardInterrupt, SystemExit): + raise + except Exception as ex: + self._log.warn('[%s]: Error while detecting false positive: %s' % (self._test.name, str(ex))) + self._log.info(traceback.print_exc()) + return False + + def _open(self): + self.out = logfile_open(self.logpath, 'w+') + + def _close(self): + self.out.close() + + def _print_header(self): + self._print_date() + print('Executing: %s' % str_join(' ', self._prog.command), file=self.out) + print('Directory: %s' % self._prog.workdir, file=self.out) + print('config:delay: %s' % self._test.delay, file=self.out) + print('config:timeout: %s' % self._test.timeout, file=self.out) + self._print_bar() + self.out.flush() + + def _print_footer(self, returncode=None): + self._print_bar() + if returncode is not None: + print('Return code: %d (negative values indicate kill by signal)' % returncode, file=self.out) + else: + print('Process is killed.', file=self.out) + self._print_exec_time() + self._print_date() + + +class SummaryReporter(TestReporter): + def __init__(self, basedir, testdir_relative, concurrent=True): + super(SummaryReporter, self).__init__() + self._basedir = basedir + self._testdir_rel = testdir_relative + self.logdir = path_join(self.testdir, LOG_DIR) + self.out_path = path_join(self.testdir, RESULT_JSON) + self.concurrent = concurrent + self.out = sys.stdout + self._platform = platform.system() + self._revision = self._get_revision() + self._tests = [] + if not os.path.exists(self.logdir): + os.mkdir(self.logdir) + self._known_failures = load_known_failures(self.testdir) + self._unexpected_success = [] + self._flaky_success = [] + self._unexpected_failure = [] + self._expected_failure = [] + self._print_header() + + @property + def testdir(self): + return path_join(self._basedir, self._testdir_rel) + + def _result_string(self, test): + if test.success: + if test.retry_count == 0: + return 'success' + elif test.retry_count == 1: + return 'flaky(1 retry)' + else: + return 'flaky(%d retries)' % test.retry_count + elif test.expired: + return 'failure(timeout)' + else: + return 'failure(%d)' % test.returncode + + def _get_revision(self): + p = subprocess.Popen(['git', 'rev-parse', '--short', 'HEAD'], + cwd=self.testdir, stdout=subprocess.PIPE) + out, _ = p.communicate() + return out.strip() + + def _format_test(self, test, with_result=True): + name = '%s-%s' % (test.server.name, test.client.name) + trans = '%s-%s' % (test.transport, test.socket) + if not with_result: + return '{:24s}{:18s}{:25s}'.format(name[:23], test.protocol[:17], trans[:24]) + else: + return '{:24s}{:18s}{:25s}{:s}\n'.format(name[:23], test.protocol[:17], + trans[:24], self._result_string(test)) + + def _print_test_header(self): + self._print_bar() + print( + '{:24s}{:18s}{:25s}{:s}'.format('server-client:', 'protocol:', 'transport:', 'result:'), + file=self.out) + + def _print_header(self): + self._start() + print('Apache Thrift - Integration Test Suite', file=self.out) + self._print_date() + self._print_test_header() + + def _print_unexpected_failure(self): + if len(self._unexpected_failure) > 0: + self.out.writelines([ + '*** Following %d failures were unexpected ***:\n' % len(self._unexpected_failure), + 'If it is introduced by you, please fix it before submitting the code.\n', + # 'If not, please report at https://issues.apache.org/jira/browse/THRIFT\n', + ]) + self._print_test_header() + for i in self._unexpected_failure: + self.out.write(self._format_test(self._tests[i])) + self._print_bar() + else: + print('No unexpected failures.', file=self.out) + + def _print_flaky_success(self): + if len(self._flaky_success) > 0: + print( + 'Following %d tests were expected to cleanly succeed but needed retry:' % len(self._flaky_success), + file=self.out) + self._print_test_header() + for i in self._flaky_success: + self.out.write(self._format_test(self._tests[i])) + self._print_bar() + + def _print_unexpected_success(self): + if len(self._unexpected_success) > 0: + print( + 'Following %d tests were known to fail but succeeded (maybe flaky):' % len(self._unexpected_success), + file=self.out) + self._print_test_header() + for i in self._unexpected_success: + self.out.write(self._format_test(self._tests[i])) + self._print_bar() + + def _http_server_command(self, port): + if sys.version_info[0] < 3: + return 'python -m SimpleHTTPServer %d' % port + else: + return 'python -m http.server %d' % port + + def _print_footer(self): + fail_count = len(self._expected_failure) + len(self._unexpected_failure) + self._print_bar() + self._print_unexpected_success() + self._print_flaky_success() + self._print_unexpected_failure() + self._write_html_data() + self._assemble_log('unexpected failures', self._unexpected_failure) + self._assemble_log('known failures', self._expected_failure) + self.out.writelines([ + 'You can browse results at:\n', + '\tfile://%s/%s\n' % (self.testdir, RESULT_HTML), + '# If you use Chrome, run:\n', + '# \tcd %s\n#\t%s\n' % (self._basedir, self._http_server_command(8001)), + '# then browse:\n', + '# \thttp://localhost:%d/%s/\n' % (8001, self._testdir_rel), + 'Full log for each test is here:\n', + '\ttest/log/server_client_protocol_transport_client.log\n', + '\ttest/log/server_client_protocol_transport_server.log\n', + '%d failed of %d tests in total.\n' % (fail_count, len(self._tests)), + ]) + self._print_exec_time() + self._print_date() + + def _render_result(self, test): + return [ + test.server.name, + test.client.name, + test.protocol, + test.transport, + test.socket, + test.success, + test.as_expected, + test.returncode, + { + 'server': self.test_logfile(test.name, test.server.kind), + 'client': self.test_logfile(test.name, test.client.kind), + }, + ] + + def _write_html_data(self): + """Writes JSON data to be read by result html""" + results = [self._render_result(r) for r in self._tests] + with logfile_open(self.out_path, 'w+') as fp: + fp.write(json.dumps({ + 'date': self._format_date(), + 'revision': str(self._revision), + 'platform': self._platform, + 'duration': '{:.1f}'.format(self._elapsed), + 'results': results, + }, indent=2)) + + def _assemble_log(self, title, indexes): + if len(indexes) > 0: + def add_prog_log(fp, test, prog_kind): + print('*************************** %s message ***************************' % prog_kind, + file=fp) + path = self.test_logfile(test.name, prog_kind, self.testdir) + if os.path.exists(path): + with logfile_open(path, 'r') as prog_fp: + print(prog_fp.read(), file=fp) + filename = title.replace(' ', '_') + '.log' + with logfile_open(os.path.join(self.logdir, filename), 'w+') as fp: + for test in map(self._tests.__getitem__, indexes): + fp.write('TEST: [%s]\n' % test.name) + add_prog_log(fp, test, test.server.kind) + add_prog_log(fp, test, test.client.kind) + fp.write('**********************************************************************\n\n') + print('%s are logged to %s/%s/%s' % (title.capitalize(), self._testdir_rel, LOG_DIR, filename)) + + def end(self): + self._print_footer() + return len(self._unexpected_failure) == 0 + + def add_test(self, test_dict): + test = TestEntry(self.testdir, **test_dict) + self._lock.acquire() + try: + if not self.concurrent: + self.out.write(self._format_test(test, False)) + self.out.flush() + self._tests.append(test) + return len(self._tests) - 1 + finally: + self._lock.release() + + def add_result(self, index, returncode, expired, retry_count): + self._lock.acquire() + try: + failed = returncode is None or returncode != 0 + flaky = not failed and retry_count != 0 + test = self._tests[index] + known = test.name in self._known_failures + if failed: + if known: + self._log.debug('%s failed as expected' % test.name) + self._expected_failure.append(index) + else: + self._log.info('unexpected failure: %s' % test.name) + self._unexpected_failure.append(index) + elif flaky and not known: + self._log.info('unexpected flaky success: %s' % test.name) + self._flaky_success.append(index) + elif not flaky and known: + self._log.info('unexpected success: %s' % test.name) + self._unexpected_success.append(index) + test.success = not failed + test.returncode = returncode + test.retry_count = retry_count + test.expired = expired + test.as_expected = known == failed + if not self.concurrent: + self.out.write(self._result_string(test) + '\n') + else: + self.out.write(self._format_test(test)) + finally: + self._lock.release() |