diff --git a/test-requirements.txt b/test-requirements.txt index 3f207f0..a08c619 100644 --- a/test-requirements.txt +++ b/test-requirements.txt @@ -7,6 +7,9 @@ coverage>=3.6 sphinx>=1.1.2,!=1.2.0,!=1.3b1,<1.3 discover +mock +six +unittest2 python-subunit testrepository>=0.0.13 testtools>=0.9.27 diff --git a/tests/base.py b/tests/base.py index a79b535..d4ff9da 100644 --- a/tests/base.py +++ b/tests/base.py @@ -66,17 +66,21 @@ class TestWithGearman(testtools.TestCase): self.config = yaml.safe_load(config_stream) # Set all of the working dirs etc to a writeable temp dir - temp_path = self.useFixture(fixtures.TempDir()).path + self.temp_path = self.useFixture(fixtures.TempDir()).path for config_dir in ['debug_log', 'jobs_working_dir', 'git_working_dir', 'pip_download_cache']: if config_dir in self.config: if self.config[config_dir][0] == '/': self.config[config_dir] = self.config[config_dir][1:] - self.config[config_dir] = os.path.join(temp_path, + self.config[config_dir] = os.path.join(self.temp_path, self.config[config_dir]) if self.config['publish_logs']['type'] == 'local': if self.config['publish_logs']['path'][0] == '/': self.config['publish_logs']['path'] = \ self.config['publish_logs']['path'][1:] self.config['publish_logs']['path'] = os.path.join( - temp_path, self.config[config_dir]) + self.temp_path, self.config['publish_logs']['path']) + + if not os.path.isdir( + os.path.dirname(self.config['publish_logs']['path'])): + os.makedirs(os.path.dirname(self.config['publish_logs']['path'])) diff --git a/tests/etc/default-config.yaml b/tests/etc/default-config.yaml index cfc133f..994d57f 100644 --- a/tests/etc/default-config.yaml +++ b/tests/etc/default-config.yaml @@ -20,13 +20,9 @@ plugins: - name: shell_script function: build:do_something_shelly + shell_script: 'ls -lah && echo' publish_logs: - type: swift - authurl: https://identity.api.rackspacecloud.com/v2.0/ - tenant: XXXX - user: XXXXXX - password: XXXXXX - container: XXXXXX - region: SYD - prepend_url: http://www.rcbops.com/turbo_hipster/results/ + type: local + path: /tmp/turbo-hipster/var/www/results/ + prepend_url: http://localhost/results/ diff --git a/tests/test_shell_task.py b/tests/test_shell_task.py new file mode 100644 index 0000000..780d0d7 --- /dev/null +++ b/tests/test_shell_task.py @@ -0,0 +1,231 @@ +# Copyright 2014 Rackspace Australia +# +# Licensed 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. + +import base +import fakes +import json +import logging +import mock +import os +import uuid + +from turbo_hipster.lib.models import ShellTask, Task + + +class TestTaskRunner(base.TestWithGearman): + log = logging.getLogger("TestTaskRunner") + + def test_simple_job_passes(self): + self.start_server() + zuul = fakes.FakeZuul(self.config['zuul_server']['gearman_host'], + self.config['zuul_server']['gearman_port']) + + job_uuid = str(uuid.uuid1())[:8] + data_req = { + 'ZUUL_UUID': job_uuid, + 'ZUUL_PROJECT': 'stackforge/turbo-hipster', + 'ZUUL_PIPELINE': 'check', + 'ZUUL_URL': 'git://git.openstack.org/', + 'BRANCH': 'master', + 'BASE_LOG_PATH': '56/123456/8', + 'LOG_PATH': '56/123456/8/check/job_name/%s' % job_uuid + } + + zuul.submit_job('build:do_something_shelly', data_req) + zuul.wait_for_completion() + + last_data = json.loads(zuul.job.data[-1]) + self.log.debug(last_data) + + self.assertTrue(zuul.job.complete) + self.assertFalse(zuul.job.failure) + self.assertEqual("SUCCESS", last_data['result']) + + task_output_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'task_output.log' + )) + + self.assertIn("Step 1: Setup environment", task_output_file.readline()) + + git_prep_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'git_prep.log' + )) + + self.assertIn("gerrit-git-prep.sh", git_prep_file.readline()) + + shell_output_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'shell_output.log' + )) + + self.assertIn("ls -lah", shell_output_file.readline()) + + def test_simple_job_fails(self): + # Test when the script fails + self.start_server() + zuul = fakes.FakeZuul(self.config['zuul_server']['gearman_host'], + self.config['zuul_server']['gearman_port']) + + job_uuid = str(uuid.uuid1())[:8] + data_req = { + 'ZUUL_UUID': job_uuid, + 'ZUUL_PROJECT': 'stackforge/turbo-hipster', + 'ZUUL_PIPELINE': 'check', + 'ZUUL_URL': 'git://git.openstack.org/', + 'BRANCH': 'master', + 'BASE_LOG_PATH': '56/123456/8', + 'LOG_PATH': '56/123456/8/check/job_name/%s' % job_uuid + } + + # Modify the job to fail. The git_path, job_working_dir and unqiue_id + # are all passed to the shell script. If we 'ls unique_id' it'll fail + # since it doesn't exist. + self.config['plugins'][2]['shell_script'] = 'ls -lah' + + zuul.submit_job('build:do_something_shelly', data_req) + zuul.wait_for_completion() + + last_data = json.loads(zuul.job.data[-1]) + self.log.debug(last_data) + + self.assertTrue(zuul.job.complete) + self.assertTrue(zuul.job.failure) + self.assertEqual("Return code from test script was non-zero (2)", + last_data['result']) + + task_output_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'task_output.log' + )) + + self.assertIn("Step 1: Setup environment", task_output_file.readline()) + + git_prep_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'git_prep.log' + )) + + self.assertIn("gerrit-git-prep.sh", git_prep_file.readline()) + + shell_output_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'shell_output.log' + )) + + self.assertIn("ls -lah", shell_output_file.readline()) + + @mock.patch.object(ShellTask, '_parse_and_check_results') + def test_logs_uploaded_during_failure(self, + mocked_parse_and_check_results): + # When turbo-hipster itself fails (eg analysing results) it should + # still upload the python logging log if it can + + def side_effect(): + raise Exception('check results failed!') + + #ShellTask._parse_and_check_results = _fake_parse_and_check_results + mocked_parse_and_check_results.side_effect = side_effect + + self.start_server() + zuul = fakes.FakeZuul(self.config['zuul_server']['gearman_host'], + self.config['zuul_server']['gearman_port']) + + job_uuid = str(uuid.uuid1())[:8] + data_req = { + 'ZUUL_UUID': job_uuid, + 'ZUUL_PROJECT': 'stackforge/turbo-hipster', + 'ZUUL_PIPELINE': 'check', + 'ZUUL_URL': 'git://git.openstack.org/', + 'BRANCH': 'master', + 'BASE_LOG_PATH': '56/123456/8', + 'LOG_PATH': '56/123456/8/check/job_name/%s' % job_uuid + } + + zuul.submit_job('build:do_something_shelly', data_req) + zuul.wait_for_completion() + + last_data = json.loads(zuul.job.data[-1]) + self.log.debug(last_data) + + self.assertTrue(zuul.job.complete) + self.assertTrue(zuul.job.failure) + self.assertEqual("FAILURE running the job\n" + "Exception: check results failed!", + last_data['result']) + + git_prep_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'git_prep.log' + )) + + self.assertIn("gerrit-git-prep.sh", git_prep_file.readline()) + + shell_output_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'shell_output.log' + )) + + self.assertIn("ls -lah", shell_output_file.readline()) + + task_output_file = open(os.path.join( + self.config['publish_logs']['path'], data_req['LOG_PATH'], + 'task_output.log' + )) + + task_output_lines = task_output_file.readlines() + self.assertIn("Step 1: Setup environment", task_output_lines[0]) + self.assertIn("Something failed running the job!", + task_output_lines[5]) + self.assertIn("Exception: check results failed!", + task_output_lines[len(task_output_lines) - 1]) + + @mock.patch.object(Task, '_upload_results') + def test_exception_when_uploading_fails(self, mocked_upload_results): + + def side_effect(): + raise Exception('uploading results failed!') + + mocked_upload_results.side_effect = side_effect + + self.start_server() + zuul = fakes.FakeZuul(self.config['zuul_server']['gearman_host'], + self.config['zuul_server']['gearman_port']) + + job_uuid = str(uuid.uuid1())[:8] + data_req = { + 'ZUUL_UUID': job_uuid, + 'ZUUL_PROJECT': 'stackforge/turbo-hipster', + 'ZUUL_PIPELINE': 'check', + 'ZUUL_URL': 'git://git.openstack.org/', + 'BRANCH': 'master', + 'BASE_LOG_PATH': '56/123456/8', + 'LOG_PATH': '56/123456/8/check/job_name/%s' % job_uuid + } + + zuul.submit_job('build:do_something_shelly', data_req) + zuul.wait_for_completion() + + last_data = json.loads(zuul.job.data[-1]) + self.log.debug(last_data) + + self.assertTrue(zuul.job.complete) + self.assertTrue(zuul.job.failure) + self.assertEqual("FAILURE during cleanup and log upload\n" + "Exception: uploading results failed!", + last_data['result']) + + def test_failure_during_setup(self): + pass diff --git a/tests/test_worker_manager.py b/tests/test_worker_manager.py index 7fe2d35..f1517f5 100644 --- a/tests/test_worker_manager.py +++ b/tests/test_worker_manager.py @@ -40,7 +40,8 @@ class TestWorkerServer(base.TestWithGearman): } plugin2_config = { "name": "shell_script", - "function": "build:do_something_shelly" + "function": "build:do_something_shelly", + "shell_script": "ls -lah && echo", } self.assertEqual(plugin0_config, diff --git a/turbo_hipster/lib/models.py b/turbo_hipster/lib/models.py index 4da226b..3599766 100644 --- a/turbo_hipster/lib/models.py +++ b/turbo_hipster/lib/models.py @@ -26,7 +26,7 @@ from turbo_hipster.lib import utils class Task(object): """ A base object for running a job (aka Task) """ - log = logging.getLogger("lib.models.Task") + log = logging.getLogger("task") def __init__(self, worker_server, plugin_config, job_name): self.worker_server = worker_server @@ -37,6 +37,12 @@ class Task(object): # Define the number of steps we will do to determine our progress. self.total_steps = 0 + def _cleanup(self): + if self.log_handler: + self.log.removeHandler(self.log_handler) + self.log_handler.flush() + self.log_handler.close() + def _reset(self): self.job = None self.job_arguments = None @@ -45,6 +51,36 @@ class Task(object): self.success = True self.messages = [] self.current_step = 0 + self.log_handler = None + + def _prep_working_dir(self): + self.job_identifier = utils.determine_job_identifier( + self.job_arguments, + self.plugin_config['function'], + self.job.unique + ) + self.job_working_dir = os.path.join( + self.worker_server.config['jobs_working_dir'], + self.job_identifier + ) + self.job_results_dir = os.path.join( + self.job_working_dir, + 'results' + ) + self.task_output_log = os.path.join( + self.job_results_dir, + 'task_output.log' + ) + + if not os.path.isdir(os.path.dirname(self.task_output_log)): + os.makedirs(os.path.dirname(self.task_output_log)) + + def _setup_task_logging(self): + self.log_handler = logging.FileHandler(self.task_output_log) + log_formatter = logging.Formatter('%(asctime)s %(message)s') + self.log_handler.setFormatter(log_formatter) + self.log.addHandler(self.log_handler) + self.log.setLevel(logging.DEBUG) def start_job(self, job): self._reset() @@ -59,16 +95,54 @@ class Task(object): # Send an initial WORK_DATA and WORK_STATUS packets self._send_work_data() - # Execute the job_steps - self.do_job_steps() + # Prep working dirs + self._prep_working_dir() - # Finally, send updated work data and completed packets - self._send_final_results() + # Now we have working dirs we can log the job details to a file + self._setup_task_logging() except Exception as e: - self.log.exception('Exception handling log event.') + # If something failed during this section we have been unable + # to log to file. As such raise an exception to gearman + self.log.exception("Failure during setup") + self.log.exception(e) if not self.cancelled: self.success = False + self.messages.append('FAILURE during the job setup') + self.messages.append('Exception: %s' % e) + self._send_work_data() + self.job.sendWorkException(str(e).encode('utf-8')) + # No point trying the job, lets return here + return + + # From here we can log exceptions + try: + # Execute the job_steps + self.do_job_steps() + except Exception as e: + # Log the problem + if not self.cancelled: + self.success = False + self.log.exception('Something failed running the job!') + self.messages.append('FAILURE running the job') + self.messages.append('Exception: %s' % e) + # Don't return from here as we can continue uploading the + # logs + + try: + self._cleanup() + self._upload_results() + # Finally, send updated work data and completed packets + self._send_final_results() + except Exception as e: + # If something failed during this section we have been unable + # to upload the log. As such raise an exception to gearman + self.log.exception("Failure during cleanup and upload") + self.log.exception(e) + if not self.cancelled: + self.success = False + self.messages.append('FAILURE during cleanup and log ' + 'upload') self.messages.append('Exception: %s' % e) self._send_work_data() self.job.sendWorkException(str(e).encode('utf-8')) @@ -139,24 +213,43 @@ class Task(object): self.current_step += 1 self.job.sendWorkStatus(self.current_step, self.total_steps) + def _upload_results(self): + """Upload the contents of the working dir either using the instructions + provided by zuul and/or our configuration""" + + self.log.debug("Process the resulting files (upload/push)") + + if 'publish_logs' in self.worker_server.config: + index_url = utils.push_file( + self.job_identifier, self.job_results_dir, + self.worker_server.config['publish_logs']) + self.log.debug("Index URL found at %s" % index_url) + self.work_data['url'] = index_url + + if 'ZUUL_EXTRA_SWIFT_URL' in self.job_arguments: + # Upload to zuul's url as instructed + utils.zuul_swift_upload(self.job_working_dir, self.job_arguments) + self.work_data['url'] = self.job_identifier + class ShellTask(Task): - log = logging.getLogger("lib.models.ShellTask") + log = logging.getLogger("task.shell_task") def __init__(self, worker_server, plugin_config, job_name): super(ShellTask, self).__init__(worker_server, plugin_config, job_name) # Define the number of steps we will do to determine our progress. - self.total_steps = 6 + self.total_steps = 5 def _reset(self): super(ShellTask, self)._reset() self.git_path = None self.job_working_dir = None self.shell_output_log = None + self.git_prep_log = None def do_job_steps(self): - self.log.info('Step 1: Prep job working dir') - self._prep_working_dir() + self.log.info('Step 1: Setup environment') + self._setup_environment() self.log.info('Step 2: Checkout updates from git') self._grab_patchset(self.job_arguments) @@ -167,35 +260,29 @@ class ShellTask(Task): self.log.info('Step 4: Analyse logs for errors') self._parse_and_check_results() - self.log.info('Step 5: handle the results (and upload etc)') + self.log.info('Step 5: handle the results') self._handle_results() self.log.info('Step 6: Handle extra actions such as shutting down') self._handle_cleanup() @common.task_step - def _prep_working_dir(self): - self.job_identifier = utils.determine_job_identifier( - self.job_arguments, - self.plugin_config['function'], - self.job.unique - ) - self.job_working_dir = os.path.join( - self.worker_server.config['jobs_working_dir'], - self.job_identifier + def _setup_environment(self): + self.git_prep_log = os.path.join( + self.job_results_dir, + 'git_prep.log' ) self.shell_output_log = os.path.join( - self.job_working_dir, + self.job_results_dir, 'shell_output.log' ) - if not os.path.isdir(os.path.dirname(self.shell_output_log)): - os.makedirs(os.path.dirname(self.shell_output_log)) - @common.task_step def _grab_patchset(self, job_args): """ Checkout the reference into config['git_working_dir'] """ + # TODO(jhesketh): Use the zuul cloner stuff instead :-) + self.log.debug("Grab the patchset we want to test against") local_path = os.path.join(self.worker_server.config['git_working_dir'], self.job_name, job_args['ZUUL_PROJECT']) @@ -204,11 +291,13 @@ class ShellTask(Task): git_args = copy.deepcopy(job_args) - cmd = os.path.join(os.path.join(os.path.dirname(__file__), - 'gerrit-git-prep.sh')) + cmd = os.path.join( + os.path.join(os.path.dirname(os.path.abspath(__file__)), + 'gerrit-git-prep.sh') + ) cmd += ' ' + self.worker_server.config['zuul_server']['gerrit_site'] cmd += ' ' + self.worker_server.config['zuul_server']['git_origin'] - utils.execute_to_log(cmd, self.shell_output_log, env=git_args, + utils.execute_to_log(cmd, self.git_prep_log, env=git_args, cwd=local_path) self.git_path = local_path return local_path @@ -246,25 +335,6 @@ class ShellTask(Task): self.messages.append('Return code from test script was non-zero ' '(%d)' % self.script_return_code) - @common.task_step - def _handle_results(self): - """Upload the contents of the working dir either using the instructions - provided by zuul and/or our configuration""" - - self.log.debug("Process the resulting files (upload/push)") - - if 'publish_logs' in self.worker_server.config: - index_url = utils.push_file( - self.job_identifier, self.shell_output_log, - self.worker_server.config['publish_logs']) - self.log.debug("Index URL found at %s" % index_url) - self.work_data['url'] = index_url - - if 'ZUUL_EXTRA_SWIFT_URL' in self.job_arguments: - # Upload to zuul's url as instructed - utils.zuul_swift_upload(self.job_working_dir, self.job_arguments) - self.work_data['url'] = self.job_identifier - @common.task_step def _handle_cleanup(self): """Handle and cleanup functions. Shutdown if requested to so that no @@ -272,3 +342,7 @@ class ShellTask(Task): if ('shutdown-th' in self.plugin_config and self.plugin_config['shutdown-th']): self.worker_server.shutdown_gracefully() + + @common.task_step + def _handle_results(self): + pass diff --git a/turbo_hipster/lib/utils.py b/turbo_hipster/lib/utils.py index 5487765..aee31e7 100644 --- a/turbo_hipster/lib/utils.py +++ b/turbo_hipster/lib/utils.py @@ -232,17 +232,27 @@ def swift_push_file(results_set_name, file_path, swift_config): def local_push_file(results_set_name, file_path, local_config): """ Copy the file locally somewhere sensible """ - dest_dir = os.path.join(local_config['path'], results_set_name) - dest_filename = os.path.basename(file_path) - if not os.path.isdir(dest_dir): - os.makedirs(dest_dir) + def _push_file_or_dir(results_set_name, file_path, local_config): + dest_dir = os.path.join(local_config['path'], results_set_name) + dest_filename = os.path.basename(file_path) + if not os.path.isdir(dest_dir): + os.makedirs(dest_dir) - dest_file = os.path.join(dest_dir, dest_filename) + dest_file = os.path.join(dest_dir, dest_filename) + + if os.path.isfile(file_path): + shutil.copyfile(file_path, dest_file) + elif os.path.isdir(file_path): + shutil.copytree(file_path, dest_file) if os.path.isfile(file_path): - shutil.copyfile(file_path, dest_file) + _push_file_or_dir(results_set_name, file_path, local_config) elif os.path.isdir(file_path): - shutil.copytree(file_path, dest_file) + for f in os.listdir(file_path): + f_path = os.path.join(file_path, f) + _push_file_or_dir(results_set_name, f_path, local_config) + + dest_filename = os.path.basename(file_path) return local_config['prepend_url'] + os.path.join(results_set_name, dest_filename) diff --git a/turbo_hipster/task_plugins/real_db_upgrade/task.py b/turbo_hipster/task_plugins/real_db_upgrade/task.py index 252160a..635566c 100644 --- a/turbo_hipster/task_plugins/real_db_upgrade/task.py +++ b/turbo_hipster/task_plugins/real_db_upgrade/task.py @@ -38,7 +38,7 @@ class Runner(models.ShellTask): It pulls in a gearman job from the build:real-db-upgrade queue and runs it through _handle_patchset""" - log = logging.getLogger("task_plugins.real_db_upgrade.task.Runner") + log = logging.getLogger("task.real_db_upgrade") def __init__(self, worker_server, plugin_config, job_name): super(Runner, self).__init__(worker_server, plugin_config, job_name)