From 630e1d55f7e6941123101a95907c270af60f235a Mon Sep 17 00:00:00 2001 From: Xavier-Do Date: Mon, 16 Dec 2019 11:50:05 +0100 Subject: [PATCH] [IMP] runbot: custom python result This commit add the possibility to add custom checks to python steps, as well as ignoring triggered result if log of level error/warning is not considered as a problem. --- runbot/models/build.py | 12 +- runbot/models/build_config.py | 135 ++++++++++++++----- runbot/tests/common.py | 1 - runbot/tests/test_build.py | 1 + runbot/tests/test_build_config_step.py | 173 ++++++++++++++++++++++++- runbot/views/config_views.xml | 2 + 6 files changed, 283 insertions(+), 41 deletions(-) diff --git a/runbot/models/build.py b/runbot/models/build.py index 29629ceb..9a0144c3 100644 --- a/runbot/models/build.py +++ b/runbot/models/build.py @@ -647,7 +647,7 @@ class runbot_build(models.Model): else: # testing/running build if build.local_state == 'testing': # failfast in case of docker error (triggered in database) - if build.triggered_result: + if build.triggered_result and not build.active_step.ignore_triggered_result: worst_result = self._get_worst_result([build.triggered_result, build.local_result]) if worst_result != build.local_result: build.local_result = build.triggered_result @@ -673,9 +673,13 @@ class runbot_build(models.Model): # make result of previous job try: results = build.active_step._make_results(build) - except: - _logger.exception('An error occured while computing results') - build._log('_make_results', 'An error occured while computing results', level='ERROR') + except Exception as e: + if isinstance(e, RunbotException): + message = e.args[0] + else: + message = 'An error occured while computing results of %s:\n %s' % (build.job, str(e).replace('\\n', '\n').replace("\\'", "'")) + _logger.exception(message) + build._log('_make_results', message, level='ERROR') results = {'local_result': 'ko'} build_values.update(results) diff --git a/runbot/models/build_config.py b/runbot/models/build_config.py index da026c1f..29e2fbde 100644 --- a/runbot/models/build_config.py +++ b/runbot/models/build_config.py @@ -9,6 +9,7 @@ from ..container import docker_run, docker_get_gateway_ip, Command from odoo import models, fields, api from odoo.exceptions import UserError, ValidationError from odoo.tools.safe_eval import safe_eval, test_python_expr +from odoo.addons.runbot.models.repo import RunbotException _logger = logging.getLogger(__name__) @@ -113,6 +114,8 @@ class ConfigStep(models.Model): additionnal_env = fields.Char('Extra env', help='Example: foo="bar",bar="foo". Cannot contains \' ', track_visibility='onchange') # python python_code = fields.Text('Python code', track_visibility='onchange', default=PYTHON_DEFAULT) + python_result_code = fields.Text('Python code for result', track_visibility='onchange', default=PYTHON_DEFAULT) + ignore_triggered_result = fields.Boolean('Ignore error triggered in logs', track_visibility='onchange', default=False) running_job = fields.Boolean('Job final state is running', default=False, help="Docker won't be killed if checked") # create_build create_config_ids = fields.Many2many('runbot.build.config', 'runbot_build_config_step_ids_create_config_ids_rel', string='New Build Configs', track_visibility='onchange', index=True) @@ -124,8 +127,15 @@ class ConfigStep(models.Model): @api.constrains('python_code') def _check_python_code(self): - for step in self.sudo().filtered('python_code'): - msg = test_python_expr(expr=step.python_code.strip(), mode="exec") + return self._check_python_field('python_code') + + @api.constrains('python_result_code') + def _check_python_result_code(self): + return self._check_python_field('python_result_code') + + def _check_python_field(self, field_name): + for step in self.sudo().filtered(field_name): + msg = test_python_expr(expr=step[field_name].strip(), mode="exec") if msg: raise ValidationError(msg) @@ -173,6 +183,8 @@ class ConfigStep(models.Model): if not self.env.user.has_group('runbot.group_build_config_administrator'): if (values.get('job_type') == 'python' or ('python_code' in values and values['python_code'] and values['python_code'] != PYTHON_DEFAULT)): raise UserError('cannot create or edit config step of type python code') + if (values.get('job_type') == 'python' or ('python_result_code' in values and values['python_result_code'] and values['python_result_code'] != PYTHON_DEFAULT)): + raise UserError('cannot create or edit config step of type python code') if (values.get('extra_params')): reg = r'^[a-zA-Z0-9\-_ "]*$' if not re.match(reg, values.get('extra_params')): @@ -226,15 +238,15 @@ class ConfigStep(models.Model): }) build._log('create_build', 'created with config %s' % create_config.name, log_type='subbuild', path=str(children.id)) - def _run_python(self, build, log_path): - eval_ctx = { + def make_python_ctx(self, build): + return { 'self': self, 'fields': fields, 'models': models, 'build': build, 'docker_run': docker_run, '_logger': _logger, - 'log_path': log_path, + 'log_path': build._path('logs', '%s.txt' % self.name), 'glob': glob.glob, 'Command': Command, 'Commit': Commit, @@ -244,7 +256,15 @@ class ConfigStep(models.Model): 'grep': grep, 'rfind': rfind, } - return safe_eval(self.sudo().python_code.strip(), eval_ctx, mode="exec", nocopy=True) + def _run_python(self, build, log_path): # TODO rework log_path after checking python steps, compute on build + eval_ctx = self.make_python_ctx(build) + try: + safe_eval(self.python_code.strip(), eval_ctx, mode="exec", nocopy=True) + except RunbotException as e: + message = e.args[0] + build._log("run", message, level='ERROR') + build._kill(result='ko') + def _is_docker_step(self): if not self: @@ -425,13 +445,26 @@ class ConfigStep(models.Model): def _make_results(self, build): build_values = {} - if self.job_type in ['install_odoo', 'python']: + log_time = self._get_log_last_write(build) + if log_time: + build_values['job_end'] = log_time + if self.job_type == 'python' and self.python_result_code and self.python_result_code != PYTHON_DEFAULT: + build_values.update(self._make_python_results(build)) + elif self.job_type in ['install_odoo', 'python']: if self.coverage: build_values.update(self._make_coverage_results(build)) if self.test_enable or self.test_tags: build_values.update(self._make_tests_results(build)) return build_values + def _make_python_results(self, build): + eval_ctx = self.make_python_ctx(build) + safe_eval(self.python_result_code.strip(), eval_ctx, mode="exec", nocopy=True) + return_value = eval_ctx.get('return_value') + if not isinstance(return_value, dict): + raise RunbotException('python_result_code must set return_value to a dict values on build') + return return_value + def _make_coverage_results(self, build): build_values = {} build._log('coverage_result', 'Start getting coverage result') @@ -449,35 +482,69 @@ class ConfigStep(models.Model): build._log('coverage_result', 'Coverage file not found', level='WARNING') return build_values + def _check_log(self, build): + log_path = build._path('logs', '%s.txt' % self.name) + if not os.path.isfile(log_path): + build._log('_make_tests_results', "Log file not found at the end of test job", level="ERROR") + return 'ko' + return 'ok' + + def _check_module_loaded(self, build): + log_path = build._path('logs', '%s.txt' % self.name) + if not grep(log_path, ".modules.loading: Modules loaded."): + build._log('_make_tests_results', "Modules loaded not found in logs", level="ERROR") + return 'ko' + return 'ok' + + def _check_error(self, build, regex=None): + log_path = build._path('logs', '%s.txt' % self.name) + regex = regex or _re_error + if rfind(log_path, regex): + build._log('_make_tests_results', 'Error or traceback found in logs', level="ERROR") + return 'ko' + return 'ok' + + def _check_warning(self, build, regex=None): + log_path = build._path('logs', '%s.txt' % self.name) + regex = regex or _re_warning + if rfind(log_path, regex): + build._log('_make_tests_results', 'Warning found in logs', level="WARNING") + return 'warn' + return 'ok' + + def _check_build_ended(self, build): + log_path = build._path('logs', '%s.txt' % self.name) + if not grep(log_path, "Initiating shutdown"): + build._log('_make_tests_results', 'No "Initiating shutdown" found in logs, maybe because of cpu limit.', level="ERROR") + return 'ko' + return 'ok' + + def _get_log_last_write(self, build): + log_path = build._path('logs', '%s.txt' % self.name) + if os.path.isfile(log_path): + return time2str(time.localtime(os.path.getmtime(log_path))) + + def _get_checkers_result(self, build, checkers): + for checker in checkers: + result = checker(build) + if result != 'ok': + return result + return 'ok' + def _make_tests_results(self, build): build_values = {} - if self.test_enable or self.test_tags: - build._log('run', 'Getting results for build %s' % build.dest) - log_file = build._path('logs', '%s.txt' % build.active_step.name) - if not os.path.isfile(log_file): - build_values['local_result'] = 'ko' - build._log('_checkout', "Log file not found at the end of test job", level="ERROR") - else: - log_time = time.localtime(os.path.getmtime(log_file)) - build_values['job_end'] = time2str(log_time), - if not build.local_result or build.local_result in ['ok', "warn"]: - if grep(log_file, ".modules.loading: Modules loaded."): - local_result = False - if rfind(log_file, _re_error): - local_result = 'ko' - build._log('_checkout', 'Error or traceback found in logs', level="ERROR") - elif rfind(log_file, _re_warning): - local_result = 'warn' - build._log('_checkout', 'Warning found in logs', level="WARNING") - elif not grep(log_file, "Initiating shutdown"): - local_result = 'ko' - build._log('_checkout', 'No "Initiating shutdown" found in logs, maybe because of cpu limit.', level="ERROR") - else: - local_result = 'ok' - build_values['local_result'] = build._get_worst_result([build.local_result, local_result]) - else: - build_values['local_result'] = 'ko' - build._log('_checkout', "Module loaded not found in logs", level="ERROR") + build._log('run', 'Getting results for build %s' % build.dest) + + if build.local_result != 'ko': + checkers = [ + self._check_log, + self._check_module_loaded, + self._check_error, + self._check_warning, + self._check_build_ended + ] + local_result = self._get_checkers_result(build, checkers) + build_values['local_result'] = build._get_worst_result([build.local_result, local_result]) return build_values def _step_state(self): diff --git a/runbot/tests/common.py b/runbot/tests/common.py index 85c966df..f549c40e 100644 --- a/runbot/tests/common.py +++ b/runbot/tests/common.py @@ -27,7 +27,6 @@ class RunbotCase(TransactionCase): self.start_patcher('git_patcher', 'odoo.addons.runbot.models.repo.runbot_repo._git', side_effect=git_side_effect) self.start_patcher('fqdn_patcher', 'odoo.addons.runbot.common.socket.getfqdn', 'host.runbot.com') - self.start_patcher('find_patcher', 'odoo.addons.runbot.common.find', 0) self.start_patcher('github_patcher', 'odoo.addons.runbot.models.repo.runbot_repo._github', {}) self.start_patcher('is_on_remote_patcher', 'odoo.addons.runbot.models.branch.runbot_branch._is_on_remote', True) self.start_patcher('repo_root_patcher', 'odoo.addons.runbot.models.repo.runbot_repo._root', '/tmp/runbot_test/static') diff --git a/runbot/tests/test_build.py b/runbot/tests/test_build.py index 8be9f9ac..5a7ae37a 100644 --- a/runbot/tests/test_build.py +++ b/runbot/tests/test_build.py @@ -31,6 +31,7 @@ class Test_Build(RunbotCase): 'repo_id': self.repo.id, 'name': 'refs/heads/11.0' }) + self.start_patcher('find_patcher', 'odoo.addons.runbot.common.find', 0) def test_base_fields(self): build = self.create_build({ diff --git a/runbot/tests/test_build_config_step.py b/runbot/tests/test_build_config_step.py index f3b414cf..52e65f23 100644 --- a/runbot/tests/test_build_config_step.py +++ b/runbot/tests/test_build_config_step.py @@ -1,6 +1,7 @@ # -*- coding: utf-8 -*- -from unittest.mock import patch +from unittest.mock import patch, mock_open from odoo.tests import common +from odoo.addons.runbot.models.repo import RunbotException from .common import RunbotCase class TestBuildConfigStep(RunbotCase): @@ -31,7 +32,7 @@ class TestBuildConfigStep(RunbotCase): }) self.start_patcher('_local_pg_createdb', 'odoo.addons.runbot.models.build.runbot_build._local_pg_createdb', True) self.start_patcher('_get_py_version', 'odoo.addons.runbot.models.build.runbot_build._get_py_version', 3) - + self.start_patcher('find_patcher', 'odoo.addons.runbot.common.find', 0) def test_config_step_create_results(self): """ Test child builds are taken into account""" @@ -155,3 +156,171 @@ class TestBuildConfigStep(RunbotCase): self.patchers['docker_run'].side_effect = docker_run2 config_step._run_odoo_install(self.parent_build, 'dev/null/logpath') + + +class TestMakeResult(RunbotCase): + + def setUp(self): + super(TestMakeResult, self).setUp() + self.ConfigStep = self.env['runbot.build.config.step'] + self.Config = self.env['runbot.build.config'] + self.repo = self.Repo.create({'name': 'bla@example.com:foo/bar', 'server_files': 'server.py'}) + self.branch = self.Branch.create({ + 'repo_id': self.repo.id, + 'name': 'refs/heads/master' + }) + + @patch('odoo.addons.runbot.models.build_config.os.path.getmtime') + @patch('odoo.addons.runbot.models.build.runbot_build._log') + def test_make_result(self, mock_log, mock_getmtime): + file_content = """ +Loading stuff +odoo.stuff.modules.loading: Modules loaded. +Some post install stuff +Initiating shutdown +""" + logs = [] + + def _log(func, message, level='INFO', log_type='runbot', path='runbot'): + logs.append((level, message)) + + mock_log.side_effect = _log + mock_getmtime.return_value = 7200 + + config_step = self.ConfigStep.create({ + 'name': 'all', + 'job_type': 'install_odoo', + 'test_tags': '/module,:class.method', + }) + build = self.Build.create({ + 'branch_id': self.branch.id, + 'name': 'd0d0caca0000ffffffffffffffffffffffffffff', + 'port': '1234', + }) + logs = [] + with patch('builtins.open', mock_open(read_data=file_content)): + result = config_step._make_results(build) + self.assertEqual(result, {'job_end': '1970-01-01 02:00:00', 'local_result': 'ok'}) + self.assertEqual(logs, [('INFO', 'Getting results for build %s' % build.dest)]) + # no shutdown + logs = [] + file_content = """ +Loading stuff +odoo.stuff.modules.loading: Modules loaded. +Some post install stuff + """ + with patch('builtins.open', mock_open(read_data=file_content)): + result = config_step._make_results(build) + self.assertEqual(result, {'job_end': '1970-01-01 02:00:00', 'local_result': 'ko'}) + self.assertEqual(logs, [ + ('INFO', 'Getting results for build %s' % build.dest), + ('ERROR', 'No "Initiating shutdown" found in logs, maybe because of cpu limit.') + ]) + # no loaded + logs = [] + file_content = """ +Loading stuff +""" + with patch('builtins.open', mock_open(read_data=file_content)): + result = config_step._make_results(build) + self.assertEqual(result, {'job_end': '1970-01-01 02:00:00', 'local_result': 'ko'}) + self.assertEqual(logs, [ + ('INFO', 'Getting results for build %s' % build.dest), + ('ERROR', 'Modules loaded not found in logs') + ]) + + # traceback + logs = [] + file_content = """ +Loading stuff +odoo.stuff.modules.loading: Modules loaded. +Some post install stuff +2019-12-17 17:34:37,692 17 ERROR dbname path.to.test: FAIL: TestClass.test_ +Traceback (most recent call last): +File "x.py", line a, in test_ + .... +Initiating shutdown +""" + with patch('builtins.open', mock_open(read_data=file_content)): + result = config_step._make_results(build) + self.assertEqual(result, {'job_end': '1970-01-01 02:00:00', 'local_result': 'ko'}) + self.assertEqual(logs, [ + ('INFO', 'Getting results for build %s' % build.dest), + ('ERROR', 'Error or traceback found in logs') + ]) + + # warning in logs + logs = [] + file_content = """ +Loading stuff +odoo.stuff.modules.loading: Modules loaded. +Some post install stuff +2019-12-17 17:34:37,692 17 WARNING dbname path.to.test: timeout exceded +Initiating shutdown +""" + with patch('builtins.open', mock_open(read_data=file_content)): + result = config_step._make_results(build) + self.assertEqual(result, {'job_end': '1970-01-01 02:00:00', 'local_result': 'warn'}) + self.assertEqual(logs, [ + ('INFO', 'Getting results for build %s' % build.dest), + ('WARNING', 'Warning found in logs') + ]) + + # no log file + logs = [] + self.patchers['isfile'].return_value = False + result = config_step._make_results(build) + + self.assertEqual(result, {'local_result': 'ko'}) + self.assertEqual(logs, [ + ('INFO', 'Getting results for build %s' % build.dest), + ('ERROR', 'Log file not found at the end of test job') + ]) + + #no error but build was already in warn + logs = [] + file_content = """ +Loading stuff +odoo.stuff.modules.loading: Modules loaded. +Some post install stuff +Initiating shutdown +""" + self.patchers['isfile'].return_value = True + build.local_result = 'warn' + with patch('builtins.open', mock_open(read_data=file_content)): + result = config_step._make_results(build) + self.assertEqual(logs, [ + ('INFO', 'Getting results for build %s' % build.dest) + ]) + self.assertEqual(result, {'job_end': '1970-01-01 02:00:00', 'local_result': 'warn'}) + + @patch('odoo.addons.runbot.models.build_config.ConfigStep._make_tests_results') + def test_make_python_result(self, mock_make_tests_results): + config_step = self.ConfigStep.create({ + 'name': 'all', + 'job_type': 'python', + 'test_tags': '/module,:class.method', + 'python_result_code': """a = 2*5\nreturn_value = {'local_result': 'ok'}""" + }) + build = self.Build.create({ + 'branch_id': self.branch.id, + 'name': 'd0d0caca0000ffffffffffffffffffffffffffff', + 'port': '1234', + }) + build.state = 'testing' + self.patchers['isfile'].return_value = False + result = config_step._make_results(build) + self.assertEqual(result, {'local_result': 'ok'}) + + # invalid result code (no return_value set) + config_step.python_result_code = """a = 2*5\nr = {'a': 'ok'}""" + with self.assertRaises(RunbotException): + result = config_step._make_results(build) + + # no result defined + config_step.python_result_code = "" + mock_make_tests_results.return_value = {'local_result': 'warning'} + result = config_step._make_results(build) + self.assertEqual(result, {'local_result': 'warning'}) + + diff --git a/runbot/views/config_views.xml b/runbot/views/config_views.xml index 212a2958..6f5fe185 100644 --- a/runbot/views/config_views.xml +++ b/runbot/views/config_views.xml @@ -50,7 +50,9 @@ + +