diff --git a/pavelib/acceptance_test.py b/pavelib/acceptance_test.py index 271c1e6c8921fa1a50c13c6d3e9cc23a423255da..ceca56e5ccba525b99c218a31438df49715baa7d 100644 --- a/pavelib/acceptance_test.py +++ b/pavelib/acceptance_test.py @@ -4,6 +4,7 @@ Acceptance test tasks from paver.easy import cmdopts, needs from pavelib.utils.test.suites import AcceptanceTestSuite from pavelib.utils.passthrough_opts import PassthroughTask +from pavelib.utils.timer import timed from optparse import make_option try: @@ -29,6 +30,7 @@ __test__ = False # do not collect ('extra_args=', 'e', 'deprecated, pass extra options directly in the paver commandline'), ]) @PassthroughTask +@timed def test_acceptance(options, passthrough_options): """ Run the acceptance tests for either lms or cms diff --git a/pavelib/assets.py b/pavelib/assets.py index c1320eb698a5f82e34a11f821200c4197d70b6c8..ed1618f69a447c489a59ee42738796810a50c36f 100644 --- a/pavelib/assets.py +++ b/pavelib/assets.py @@ -17,6 +17,7 @@ from watchdog.events import PatternMatchingEventHandler from .utils.envs import Env from .utils.cmd import cmd, django_cmd +from .utils.timer import timed from openedx.core.djangoapps.theming.paver_helpers import get_theme_paths @@ -384,6 +385,7 @@ def coffeescript_files(): @task @no_help +@timed def compile_coffeescript(*files): """ Compile CoffeeScript to JavaScript. @@ -404,6 +406,7 @@ def compile_coffeescript(*files): ('debug', 'd', 'Debug mode'), ('force', '', 'Force full compilation'), ]) +@timed def compile_sass(options): """ Compile Sass to CSS. If command is called without any arguments, it will @@ -683,6 +686,7 @@ def execute_compile_sass(args): ('theme-dirs=', '-td', 'The themes dir containing all themes (defaults to None)'), ('themes=', '-t', 'The themes to add sass watchers for (defaults to None)'), ]) +@timed def watch_assets(options): """ Watch for changes to asset files, and regenerate js/css @@ -731,6 +735,7 @@ def watch_assets(options): 'pavelib.prereqs.install_node_prereqs', ) @consume_args +@timed def update_assets(args): """ Compile CoffeeScript and Sass, then collect static assets. diff --git a/pavelib/bok_choy.py b/pavelib/bok_choy.py index a8d5048e8f4d72b552969b22df09602889fb570d..6ceb1c1dd78aa6365c17e2ea9f4d4aad16a0fde1 100644 --- a/pavelib/bok_choy.py +++ b/pavelib/bok_choy.py @@ -4,9 +4,11 @@ http://bok-choy.readthedocs.org/en/latest/ """ from paver.easy import task, needs, cmdopts, sh from pavelib.utils.test.suites.bokchoy_suite import BokChoyTestSuite, Pa11yCrawler +from pavelib.utils.test.bokchoy_options import BOKCHOY_OPTS from pavelib.utils.envs import Env from pavelib.utils.test.utils import check_firefox_version from pavelib.utils.passthrough_opts import PassthroughTask +from pavelib.utils.timer import timed from optparse import make_option import os @@ -17,75 +19,11 @@ except ImportError: __test__ = False # do not collect -BOKCHOY_OPTS = [ - ('test-spec=', 't', 'Specific test to run'), - ('fasttest', 'a', 'Skip some setup'), - ('skip-clean', 'C', 'Skip cleaning repository before running tests'), - ('serversonly', 'r', 'Prepare suite and leave servers running'), - ('testsonly', 'o', 'Assume servers are running and execute tests only'), - ('default-store=', 's', 'Default modulestore'), - ('test-dir=', 'd', 'Directory for finding tests (relative to common/test/acceptance)'), - ('imports-dir=', 'i', 'Directory containing (un-archived) courses to be imported'), - ('num-processes=', 'n', 'Number of test threads (for multiprocessing)'), - ('verify-xss', 'x', 'Run XSS vulnerability tests'), - make_option("--verbose", action="store_const", const=2, dest="verbosity"), - make_option("-q", "--quiet", action="store_const", const=0, dest="verbosity"), - make_option("-v", "--verbosity", action="count", dest="verbosity"), - make_option("--skip-firefox-version-validation", action='store_false', dest="validate_firefox_version"), - make_option("--save-screenshots", action='store_true', dest="save_screenshots"), - ('default_store=', None, 'deprecated in favor of default-store'), - ('extra_args=', 'e', 'deprecated, pass extra options directly in the paver commandline'), - ('imports_dir=', None, 'deprecated in favor of imports-dir'), - ('num_processes=', None, 'deprecated in favor of num-processes'), - ('skip_clean', None, 'deprecated in favor of skip-clean'), - ('test_dir=', None, 'deprecated in favor of test-dir'), - ('test_spec=', None, 'Specific test to run'), - ('verify_xss', None, 'deprecated in favor of verify-xss'), - make_option( - "--skip_firefox_version_validation", - action='store_false', - dest="validate_firefox_version", - help="deprecated in favor of --skip-firefox-version-validation" - ), - make_option( - "--save_screenshots", - action='store_true', - dest="save_screenshots", - help="deprecated in favor of save-screenshots" - ), -] - - -def parse_bokchoy_opts(options, passthrough_options=None): - """ - Parses bok choy options. - - Returns: dict of options. - """ - if passthrough_options is None: - passthrough_options = [] - - return { - 'test_spec': getattr(options, 'test_spec', None), - 'fasttest': getattr(options, 'fasttest', False), - 'num_processes': int(getattr(options, 'num_processes', 1)), - 'verify_xss': getattr(options, 'verify_xss', os.environ.get('VERIFY_XSS', False)), - 'serversonly': getattr(options, 'serversonly', False), - 'testsonly': getattr(options, 'testsonly', False), - 'default_store': getattr(options, 'default_store', os.environ.get('DEFAULT_STORE', 'split')), - 'verbosity': getattr(options, 'verbosity', 2), - 'extra_args': getattr(options, 'extra_args', ''), - 'pdb': getattr(options, 'pdb', False), - 'test_dir': getattr(options, 'test_dir', 'tests'), - 'imports_dir': getattr(options, 'imports_dir', None), - 'save_screenshots': getattr(options, 'save_screenshots', False), - 'passthrough_options': passthrough_options - } - @needs('pavelib.prereqs.install_prereqs') @cmdopts(BOKCHOY_OPTS) @PassthroughTask +@timed def test_bokchoy(options, passthrough_options): """ Run acceptance tests that use the bok-choy framework. @@ -109,13 +47,13 @@ def test_bokchoy(options, passthrough_options): if validate_firefox: check_firefox_version() - opts = parse_bokchoy_opts(options, passthrough_options) - run_bokchoy(**opts) + run_bokchoy(passthrough_options=passthrough_options, **options) @needs('pavelib.prereqs.install_prereqs') @cmdopts(BOKCHOY_OPTS) @PassthroughTask +@timed def test_a11y(options, passthrough_options): """ Run accessibility tests that use the bok-choy framework. @@ -132,24 +70,27 @@ def test_a11y(options, passthrough_options): It can also be left blank to run all tests in the suite that are tagged with `@attr("a11y")`. """ - opts = parse_bokchoy_opts(options, passthrough_options) - opts['report_dir'] = Env.BOK_CHOY_A11Y_REPORT_DIR - opts['coveragerc'] = Env.BOK_CHOY_A11Y_COVERAGERC - opts['extra_args'] = opts['extra_args'] + ' -a "a11y" ' - run_bokchoy(**opts) + # Modify the options object directly, so that any subsequently called tasks + # that share with this task get the modified options + options['test_a11y']['report_dir'] = Env.BOK_CHOY_A11Y_REPORT_DIR + options['test_a11y']['coveragerc'] = Env.BOK_CHOY_A11Y_COVERAGERC + options['test_a11y']['extra_args'] = options.get('extra_args', '') + ' -a "a11y" ' + run_bokchoy(passthrough_options=passthrough_options, **options['test_a11y']) @needs('pavelib.prereqs.install_prereqs') @cmdopts(BOKCHOY_OPTS) @PassthroughTask +@timed def perf_report_bokchoy(options, passthrough_options): """ Generates a har file for with page performance info. """ - opts = parse_bokchoy_opts(options, passthrough_options) - opts['test_dir'] = 'performance' + # Modify the options object directly, so that any subsequently called tasks + # that share with this task get the modified options + options['perf_report_bokchoy']['test_dir'] = 'performance' - run_bokchoy(**opts) + run_bokchoy(passthrough_options=passthrough_options, **options['perf_report_bokchoy']) @needs('pavelib.prereqs.install_prereqs') @@ -164,6 +105,7 @@ def perf_report_bokchoy(options, passthrough_options): ), ]) @PassthroughTask +@timed def pa11ycrawler(options, passthrough_options): """ Runs pa11ycrawler against the demo-test-course to generates accessibility @@ -173,12 +115,17 @@ def pa11ycrawler(options, passthrough_options): flag to get an environment running. The setup for this is the same as for bok-choy tests, only test course is imported as well. """ - opts = parse_bokchoy_opts(options, passthrough_options) - opts['report_dir'] = Env.PA11YCRAWLER_REPORT_DIR - opts['coveragerc'] = Env.PA11YCRAWLER_COVERAGERC - opts['should_fetch_course'] = getattr(options, 'should_fetch_course', not opts['fasttest']) - opts['course_key'] = getattr(options, 'course-key', "course-v1:edX+Test101+course") - test_suite = Pa11yCrawler('a11y_crawler', **opts) + # Modify the options object directly, so that any subsequently called tasks + # that share with this task get the modified options + options['pa11ycrawler']['report_dir'] = Env.PA11YCRAWLER_REPORT_DIR + options['pa11ycrawler']['coveragerc'] = Env.PA11YCRAWLER_COVERAGERC + options['pa11ycrawler']['should_fetch_course'] = getattr( + options, + 'should_fetch_course', + not options.get('fasttest') + ) + options['pa11ycrawler']['course_key'] = getattr(options, 'course-key', "course-v1:edX+Test101+course") + test_suite = Pa11yCrawler('a11y_crawler', passthrough_options=passthrough_options, **options['pa11ycrawler']) test_suite.run() if getattr(options, 'with_html', False): @@ -220,6 +167,7 @@ def parse_coverage(report_dir, coveragerc): @task +@timed def bokchoy_coverage(): """ Generate coverage reports for bok-choy tests @@ -231,6 +179,7 @@ def bokchoy_coverage(): @task +@timed def a11y_coverage(): """ Generate coverage reports for a11y tests. Note that this coverage report @@ -246,6 +195,7 @@ def a11y_coverage(): @task +@timed def pa11ycrawler_coverage(): """ Generate coverage reports for bok-choy tests diff --git a/pavelib/docs.py b/pavelib/docs.py index 0b10b61286db98561c90048e7f58093e3d2452db..b96580714aed297c1936d10d9a0099f49264685d 100644 --- a/pavelib/docs.py +++ b/pavelib/docs.py @@ -7,6 +7,8 @@ import sys from paver.easy import cmdopts, needs, sh, task +from .utils.timer import timed + DOC_PATHS = { "dev": "docs/en_us/developers", @@ -64,6 +66,7 @@ def doc_path(options, allow_default=True): ("type=", "t", "Type of docs to compile"), ("verbose", "v", "Display verbose output"), ]) +@timed def build_docs(options): """ Invoke sphinx 'make build' to generate docs. diff --git a/pavelib/i18n.py b/pavelib/i18n.py index a79b9f79c8eb871d660849f4cc0758cdbb481261..326f31ac7080b9d237cb255fcbb69b3241e60ccb 100644 --- a/pavelib/i18n.py +++ b/pavelib/i18n.py @@ -10,6 +10,7 @@ from path import Path as path from paver.easy import task, cmdopts, needs, sh from .utils.cmd import django_cmd +from .utils.timer import timed try: from pygments.console import colorize @@ -28,6 +29,7 @@ DEFAULT_SETTINGS = 'devstack' @cmdopts([ ("verbose", "v", "Sets 'verbose' to True"), ]) +@timed def i18n_extract(options): """ Extract localizable strings from sources @@ -42,6 +44,7 @@ def i18n_extract(options): @task +@timed def i18n_fastgenerate(): """ Compile localizable strings from sources without re-extracting strings first. @@ -51,6 +54,7 @@ def i18n_fastgenerate(): @task @needs("pavelib.i18n.i18n_extract") +@timed def i18n_generate(): """ Compile localizable strings from sources, extracting strings first. @@ -60,6 +64,7 @@ def i18n_generate(): @task @needs("pavelib.i18n.i18n_extract") +@timed def i18n_generate_strict(): """ Compile localizable strings from sources, extracting strings first. @@ -70,6 +75,7 @@ def i18n_generate_strict(): @task @needs("pavelib.i18n.i18n_extract") +@timed def i18n_dummy(): """ Simulate international translation by generating dummy strings @@ -85,6 +91,7 @@ def i18n_dummy(): @task +@timed def i18n_validate_gettext(): """ Make sure GNU gettext utilities are available @@ -107,6 +114,7 @@ def i18n_validate_gettext(): @task +@timed def i18n_validate_transifex_config(): """ Make sure config file with username/password exists @@ -130,6 +138,7 @@ def i18n_validate_transifex_config(): @task @needs("pavelib.i18n.i18n_validate_transifex_config") +@timed def i18n_transifex_push(): """ Push source strings to Transifex for translation @@ -139,6 +148,7 @@ def i18n_transifex_push(): @task @needs("pavelib.i18n.i18n_validate_transifex_config") +@timed def i18n_transifex_pull(): """ Pull translated strings from Transifex @@ -147,6 +157,7 @@ def i18n_transifex_pull(): @task +@timed def i18n_rtl(): """ Pull all RTL translations (reviewed AND unreviewed) from Transifex @@ -164,6 +175,7 @@ def i18n_rtl(): @task +@timed def i18n_ltr(): """ Pull all LTR translations (reviewed AND unreviewed) from Transifex @@ -188,6 +200,7 @@ def i18n_ltr(): "pavelib.i18n.i18n_dummy", "pavelib.i18n.i18n_generate_strict", ) +@timed def i18n_robot_pull(): """ Pull source strings, generate po and mo files, and validate @@ -215,6 +228,7 @@ def i18n_robot_pull(): @task +@timed def i18n_clean(): """ Clean the i18n directory of artifacts @@ -227,6 +241,7 @@ def i18n_clean(): "pavelib.i18n.i18n_extract", "pavelib.i18n.i18n_transifex_push", ) +@timed def i18n_robot_push(): """ Extract new strings, and push to transifex @@ -239,6 +254,7 @@ def i18n_robot_push(): "pavelib.i18n.i18n_validate_transifex_config", "pavelib.i18n.i18n_generate", ) +@timed def i18n_release_push(): """ Push release-specific resources to Transifex. @@ -251,6 +267,7 @@ def i18n_release_push(): @needs( "pavelib.i18n.i18n_validate_transifex_config", ) +@timed def i18n_release_pull(): """ Pull release-specific translations from Transifex. diff --git a/pavelib/js_test.py b/pavelib/js_test.py index 058ffebe837bef17c8b5a6dc303d89d01ea351f3..7102d7471fda9430caeabbe33ecff40460a04ecd 100644 --- a/pavelib/js_test.py +++ b/pavelib/js_test.py @@ -5,6 +5,7 @@ import sys from paver.easy import task, cmdopts, needs from pavelib.utils.test.suites import JsTestSuite from pavelib.utils.envs import Env +from pavelib.utils.timer import timed __test__ = False # do not collect @@ -22,6 +23,7 @@ __test__ = False # do not collect ('skip-clean', 'C', 'skip cleaning repository before running tests'), ('skip_clean', None, 'deprecated in favor of skip-clean'), ], share_with=["pavelib.utils.tests.utils.clean_reports_dir"]) +@timed def test_js(options): """ Run the JavaScript tests @@ -58,6 +60,7 @@ def test_js(options): ("suite=", "s", "Test suite to run"), ("coverage", "c", "Run test under coverage"), ]) +@timed def test_js_run(options): """ Run the JavaScript tests and print results to the console @@ -71,6 +74,7 @@ def test_js_run(options): ("suite=", "s", "Test suite to run"), ("port=", "p", "Port to run test server on"), ]) +@timed def test_js_dev(options): """ Run the JavaScript tests in your default browsers diff --git a/pavelib/paver_tests/test_timer.py b/pavelib/paver_tests/test_timer.py new file mode 100644 index 0000000000000000000000000000000000000000..742e6a34a37022879af0c99817512565569c7225 --- /dev/null +++ b/pavelib/paver_tests/test_timer.py @@ -0,0 +1,188 @@ +""" +Tests of the pavelib.utils.timer module. +""" + +from datetime import datetime, timedelta +from mock import patch, MagicMock +from unittest import TestCase + +from pavelib.utils import timer + + +@timer.timed +def identity(*args, **kwargs): + """ + An identity function used as a default task to test the timing of. + """ + return args, kwargs + + +MOCK_OPEN = MagicMock(spec=open) + + +@patch.dict('pavelib.utils.timer.__builtins__', open=MOCK_OPEN) +class TimedDecoratorTests(TestCase): + """ + Tests of the pavelib.utils.timer:timed decorator. + """ + def setUp(self): + super(TimedDecoratorTests, self).setUp() + + patch_dumps = patch.object(timer.json, 'dump', autospec=True) + self.mock_dump = patch_dumps.start() + self.addCleanup(patch_dumps.stop) + + patch_makedirs = patch.object(timer.os, 'makedirs', autospec=True) + self.mock_makedirs = patch_makedirs.start() + self.addCleanup(patch_makedirs.stop) + + patch_datetime = patch.object(timer, 'datetime', autospec=True) + self.mock_datetime = patch_datetime.start() + self.addCleanup(patch_datetime.stop) + + patch_exists = patch.object(timer, 'exists', autospec=True) + self.mock_exists = patch_exists.start() + self.addCleanup(patch_exists.stop) + + MOCK_OPEN.reset_mock() + + def get_log_messages(self, task=identity, args=None, kwargs=None, raises=None): + """ + Return all timing messages recorded during the execution of ``task``. + """ + if args is None: + args = [] + if kwargs is None: + kwargs = {} + + if raises is None: + task(*args, **kwargs) + else: + self.assertRaises(raises, task, *args, **kwargs) + + return [ + call[0][0] # log_message + for call in self.mock_dump.call_args_list + ] + + @patch.object(timer, 'PAVER_TIMER_LOG', '/tmp/some-log') + def test_times(self): + start = datetime(2016, 7, 20, 10, 56, 19) + end = start + timedelta(seconds=35.6) + + self.mock_datetime.utcnow.side_effect = [start, end] + + messages = self.get_log_messages() + self.assertEquals(len(messages), 1) + + # I'm not using assertDictContainsSubset because it is + # removed in python 3.2 (because the arguments were backwards) + # and it wasn't ever replaced by anything *headdesk* + self.assertIn('duration', messages[0]) + self.assertEquals(35.6, messages[0]['duration']) + + self.assertIn('started_at', messages[0]) + self.assertEquals(start.isoformat(' '), messages[0]['started_at']) + + self.assertIn('ended_at', messages[0]) + self.assertEquals(end.isoformat(' '), messages[0]['ended_at']) + + @patch.object(timer, 'PAVER_TIMER_LOG', None) + def test_no_logs(self): + messages = self.get_log_messages() + self.assertEquals(len(messages), 0) + + @patch.object(timer, 'PAVER_TIMER_LOG', '/tmp/some-log') + def test_arguments(self): + messages = self.get_log_messages(args=(1, 'foo'), kwargs=dict(bar='baz')) + self.assertEquals(len(messages), 1) + + # I'm not using assertDictContainsSubset because it is + # removed in python 3.2 (because the arguments were backwards) + # and it wasn't ever replaced by anything *headdesk* + self.assertIn('args', messages[0]) + self.assertEquals([repr(1), repr('foo')], messages[0]['args']) + self.assertIn('kwargs', messages[0]) + self.assertEquals({'bar': repr('baz')}, messages[0]['kwargs']) + + @patch.object(timer, 'PAVER_TIMER_LOG', '/tmp/some-log') + def test_task_name(self): + messages = self.get_log_messages() + self.assertEquals(len(messages), 1) + + # I'm not using assertDictContainsSubset because it is + # removed in python 3.2 (because the arguments were backwards) + # and it wasn't ever replaced by anything *headdesk* + self.assertIn('task', messages[0]) + self.assertEquals('pavelib.paver_tests.test_timer.identity', messages[0]['task']) + + @patch.object(timer, 'PAVER_TIMER_LOG', '/tmp/some-log') + def test_exceptions(self): + + @timer.timed + def raises(): + """ + A task used for testing exception handling of the timed decorator. + """ + raise Exception('The Message!') + + messages = self.get_log_messages(task=raises, raises=Exception) + self.assertEquals(len(messages), 1) + + # I'm not using assertDictContainsSubset because it is + # removed in python 3.2 (because the arguments were backwards) + # and it wasn't ever replaced by anything *headdesk* + self.assertIn('exception', messages[0]) + self.assertEquals("Exception: The Message!", messages[0]['exception']) + + @patch.object(timer, 'PAVER_TIMER_LOG', '/tmp/some-log-%Y-%m-%d-%H-%M-%S.log') + def test_date_formatting(self): + start = datetime(2016, 7, 20, 10, 56, 19) + end = start + timedelta(seconds=35.6) + + self.mock_datetime.utcnow.side_effect = [start, end] + + messages = self.get_log_messages() + self.assertEquals(len(messages), 1) + + MOCK_OPEN.assert_called_once_with('/tmp/some-log-2016-07-20-10-56-19.log', 'a') + + @patch.object(timer, 'PAVER_TIMER_LOG', '/tmp/some-log') + def test_nested_tasks(self): + + @timer.timed + def parent(): + """ + A timed task that calls another task + """ + identity() + + parent_start = datetime(2016, 7, 20, 10, 56, 19) + parent_end = parent_start + timedelta(seconds=60) + child_start = parent_start + timedelta(seconds=10) + child_end = parent_end - timedelta(seconds=10) + + self.mock_datetime.utcnow.side_effect = [parent_start, child_start, child_end, parent_end] + + messages = self.get_log_messages(task=parent) + self.assertEquals(len(messages), 2) + + # Child messages first + self.assertIn('duration', messages[0]) + self.assertEquals(40, messages[0]['duration']) + + self.assertIn('started_at', messages[0]) + self.assertEquals(child_start.isoformat(' '), messages[0]['started_at']) + + self.assertIn('ended_at', messages[0]) + self.assertEquals(child_end.isoformat(' '), messages[0]['ended_at']) + + # Parent messages after + self.assertIn('duration', messages[1]) + self.assertEquals(60, messages[1]['duration']) + + self.assertIn('started_at', messages[1]) + self.assertEquals(parent_start.isoformat(' '), messages[1]['started_at']) + + self.assertIn('ended_at', messages[1]) + self.assertEquals(parent_end.isoformat(' '), messages[1]['ended_at']) diff --git a/pavelib/prereqs.py b/pavelib/prereqs.py index 262a3b243d20d9421706168cfff86c90735a699f..81ceb25fcfeccea2dda0510fe46e67e4f8fcabf4 100644 --- a/pavelib/prereqs.py +++ b/pavelib/prereqs.py @@ -11,6 +11,7 @@ import sys from paver.easy import sh, task from .utils.envs import Env +from .utils.timer import timed PREREQS_STATE_DIR = os.getenv('PREREQ_CACHE_DIR', Env.REPO_ROOT / '.prereqs_cache') @@ -145,6 +146,7 @@ def python_prereqs_installation(): @task +@timed def install_node_prereqs(): """ Installs Node prerequisites @@ -168,6 +170,7 @@ PACKAGES_TO_UNINSTALL = [ @task +@timed def uninstall_python_packages(): """ Uninstall Python packages that need explicit uninstallation. @@ -235,6 +238,7 @@ def package_in_frozen(package_name, frozen_output): @task +@timed def install_python_prereqs(): """ Installs Python prerequisites. @@ -268,6 +272,7 @@ def install_python_prereqs(): @task +@timed def install_prereqs(): """ Installs Node and Python prerequisites diff --git a/pavelib/quality.py b/pavelib/quality.py index 3882969eda6745ff2b3d2e21aeff46b211eb721f..a37f717970e9faf287b594f8d827faa817f860e0 100644 --- a/pavelib/quality.py +++ b/pavelib/quality.py @@ -9,6 +9,7 @@ import re from openedx.core.djangolib.markup import HTML from .utils.envs import Env +from .utils.timer import timed ALL_SYSTEMS = 'lms,cms,common,openedx,pavelib' @@ -38,6 +39,7 @@ def top_python_dirs(dirname): @cmdopts([ ("system=", "s", "System to act on"), ]) +@timed def find_fixme(options): """ Run pylint on system code, only looking for fixme items. @@ -82,6 +84,7 @@ def find_fixme(options): ("errors", "e", "Check for errors only"), ("limit=", "l", "limit for number of acceptable violations"), ]) +@timed def run_pylint(options): """ Run pylint on system code. When violations limit is passed in, @@ -197,6 +200,7 @@ def _pep8_violations(report_file): @cmdopts([ ("system=", "s", "System to act on"), ]) +@timed def run_pep8(options): # pylint: disable=unused-argument """ Run pep8 on system code. @@ -224,6 +228,7 @@ def run_pep8(options): # pylint: disable=unused-argument @task @needs('pavelib.prereqs.install_python_prereqs') +@timed def run_complexity(): """ Uses radon to examine cyclomatic complexity. @@ -262,6 +267,7 @@ def run_complexity(): @cmdopts([ ("limit=", "l", "limit for number of acceptable violations"), ]) +@timed def run_jshint(options): """ Runs jshint on static asset directories @@ -306,6 +312,7 @@ def run_jshint(options): @cmdopts([ ("thresholds=", "t", "json containing limit for number of acceptable violations per rule"), ]) +@timed def run_safelint(options): """ Runs safe_template_linter.py on the codebase @@ -407,6 +414,7 @@ def run_safelint(options): @task @needs('pavelib.prereqs.install_python_prereqs') +@timed def run_safecommit_report(): """ Runs safe-commit-linter.sh on the current branch. @@ -580,6 +588,7 @@ def _get_safecommit_count(filename): ("compare-branch=", "b", "Branch to compare against, defaults to origin/master"), ("percentage=", "p", "fail if diff-quality is below this percentage"), ]) +@timed def run_quality(options): """ Build the html diff quality reports, and print the reports to the console. diff --git a/pavelib/servers.py b/pavelib/servers.py index db4076ccf6da2aaedff3963359d42ee7f6529343..cf4711f728839c53ad102d06caeb6497ca11c074 100644 --- a/pavelib/servers.py +++ b/pavelib/servers.py @@ -10,6 +10,7 @@ from paver.easy import call_task, cmdopts, consume_args, needs, sh, task from .assets import collect_assets from .utils.cmd import django_cmd from .utils.process import run_process, run_multi_processes +from .utils.timer import timed DEFAULT_PORT = {"lms": 8000, "studio": 8001} @@ -244,6 +245,7 @@ def run_all_servers(options): ("settings=", "s", "Django settings"), ("fake-initial", None, "Fake the initial migrations"), ]) +@timed def update_db(options): """ Migrates the lms and cms across all databases @@ -261,6 +263,7 @@ def update_db(options): @task @needs('pavelib.prereqs.install_prereqs') @consume_args +@timed def check_settings(args): """ Checks settings files. diff --git a/pavelib/tests.py b/pavelib/tests.py index ffcf7668fe25ace98d1da4317a60502bf33b5ec3..7660a4390b1abb04380361d4d327e74979d84bd0 100644 --- a/pavelib/tests.py +++ b/pavelib/tests.py @@ -7,6 +7,7 @@ import sys from paver.easy import sh, task, cmdopts, needs, call_task from pavelib.utils.test import suites from pavelib.utils.envs import Env +from pavelib.utils.timer import timed from pavelib.utils.passthrough_opts import PassthroughTask from optparse import make_option @@ -55,6 +56,7 @@ __test__ = False # do not collect ('skip_clean', None, 'deprecated in favor of skip-clean'), ], share_with=['pavelib.utils.test.utils.clean_reports_dir']) @PassthroughTask +@timed def test_system(options, passthrough_options): """ Run tests on our djangoapps for lms and cms @@ -120,6 +122,7 @@ def test_system(options, passthrough_options): ("test_id=", None, "deprecated in favor of test-id"), ], share_with=['pavelib.utils.test.utils.clean_reports_dir']) @PassthroughTask +@timed def test_lib(options, passthrough_options): """ Run tests for common/lib/ and pavelib/ (paver-tests) @@ -184,6 +187,7 @@ def test_lib(options, passthrough_options): ("fail_fast", None, "deprecated in favor of fail-fast"), ]) @PassthroughTask +@timed def test_python(options, passthrough_options): """ Run all python tests @@ -216,6 +220,7 @@ def test_python(options, passthrough_options): ), ]) @PassthroughTask +@timed def test(options, passthrough_options): """ Run all tests @@ -239,7 +244,8 @@ def test(options, passthrough_options): ("compare-branch=", "b", "Branch to compare against, defaults to origin/master"), ("compare_branch=", None, "deprecated in favor of compare-branch"), ]) -def coverage(options): +@timed +def coverage(): """ Build the html, xml, and diff coverage reports """ @@ -276,6 +282,7 @@ def coverage(options): ("compare-branch=", "b", "Branch to compare against, defaults to origin/master"), ("compare_branch=", None, "deprecated in favor of compare-branch"), ], share_with=['coverage']) +@timed def diff_coverage(options): """ Build the diff coverage reports diff --git a/pavelib/utils/test/bokchoy_options.py b/pavelib/utils/test/bokchoy_options.py new file mode 100644 index 0000000000000000000000000000000000000000..84cdf2a6390419346e311ddefc069abfc4a1139d --- /dev/null +++ b/pavelib/utils/test/bokchoy_options.py @@ -0,0 +1,71 @@ +""" +Definitions of all options used by the various bok_choy tasks. +""" + +from optparse import make_option +import os + +from pavelib.utils.envs import Env + + +BOKCHOY_OPTS = [ + ('test-spec=', 't', 'Specific test to run'), + make_option('-a', '--fasttest', action='store_true', help='Skip some setup'), + ('skip-clean', 'C', 'Skip cleaning repository before running tests'), + make_option('-r', '--serversonly', action='store_true', help='Prepare suite and leave servers running'), + make_option('-o', '--testsonly', action='store_true', help='Assume servers are running and execute tests only'), + make_option("-s", "--default-store", default=os.environ.get('DEFAULT_STORE', 'split'), help='Default modulestore'), + make_option( + '-d', '--test-dir', + default='tests', + help='Directory for finding tests (relative to common/test/acceptance)' + ), + ('imports-dir=', 'i', 'Directory containing (un-archived) courses to be imported'), + make_option('-n', '--num-processes', type='int', help='Number of test threads (for multiprocessing)'), + make_option( + '-x', '--verify-xss', + action='store_true', + default=os.environ.get('VERIFY_XSS', False), + help='Run XSS vulnerability tests' + ), + make_option("--verbose", action="store_const", const=2, dest="verbosity"), + make_option("-q", "--quiet", action="store_const", const=0, dest="verbosity"), + make_option("-v", "--verbosity", action="count", dest="verbosity"), + make_option("--skip-firefox-version-validation", action='store_false', dest="validate_firefox_version"), + make_option("--save-screenshots", action='store_true', dest="save_screenshots"), + make_option("--report-dir", default=Env.BOK_CHOY_REPORT_DIR, help="Directory to store reports in"), + + make_option( + "--default_store", + default=os.environ.get('DEFAULT_STORE', 'split'), + help='deprecated in favor of default-store' + ), + make_option( + '-e', '--extra_args', + default='', + help='deprecated, pass extra options directly in the paver commandline' + ), + ('imports_dir=', None, 'deprecated in favor of imports-dir'), + make_option('--num_processes', type='int', help='deprecated in favor of num-processes'), + ('skip_clean', None, 'deprecated in favor of skip-clean'), + make_option('--test_dir', default='tests', help='deprecated in favor of test-dir'), + ('test_spec=', None, 'Specific test to run'), + make_option( + '--verify_xss', + action='store_true', + default=os.environ.get('VERIFY_XSS', False), + help='deprecated in favor of verify-xss' + ), + make_option( + "--skip_firefox_version_validation", + action='store_false', + dest="validate_firefox_version", + help="deprecated in favor of --skip-firefox-version-validation" + ), + make_option( + "--save_screenshots", + action='store_true', + dest="save_screenshots", + help="deprecated in favor of save-screenshots" + ), +] diff --git a/pavelib/utils/test/bokchoy_utils.py b/pavelib/utils/test/bokchoy_utils.py index 7aac1ec606420a6a3d98ac03e67694680a587131..8a4117e4fb08da68b3b4664917c9a49af52c59ed 100644 --- a/pavelib/utils/test/bokchoy_utils.py +++ b/pavelib/utils/test/bokchoy_utils.py @@ -6,9 +6,11 @@ import os import time import httplib import subprocess -from paver.easy import sh +from paver.easy import sh, task, cmdopts from pavelib.utils.envs import Env from pavelib.utils.process import run_background_process +from pavelib.utils.test.bokchoy_options import BOKCHOY_OPTS +from pavelib.utils.timer import timed try: from pygments.console import colorize @@ -18,11 +20,14 @@ except ImportError: __test__ = False # do not collect -def start_servers(default_store, coveragerc=None): +@task +@cmdopts(BOKCHOY_OPTS, share_with=['test_bokchoy', 'test_a11y', 'pa11ycrawler']) +@timed +def start_servers(options): """ Start the servers we will run tests on, returns PIDs for servers. """ - coveragerc = coveragerc or Env.BOK_CHOY_COVERAGERC + coveragerc = options.get('coveragerc', Env.BOK_CHOY_COVERAGERC) def start_server(cmd, logfile, cwd=None): """ @@ -38,7 +43,7 @@ def start_servers(default_store, coveragerc=None): "coverage run --rcfile={coveragerc} -m " "manage {service} --settings bok_choy runserver " "{address} --traceback --noreload".format( - default_store=default_store, + default_store=options.default_store, coveragerc=coveragerc, service=service, address=address, @@ -137,6 +142,8 @@ def is_mysql_running(): return returncode == 0 +@task +@timed def clear_mongo(): """ Clears mongo database. @@ -148,6 +155,8 @@ def clear_mongo(): ) +@task +@timed def check_mongo(): """ Check that mongo is running @@ -158,6 +167,8 @@ def check_mongo(): sys.exit(1) +@task +@timed def check_memcache(): """ Check that memcache is running @@ -168,6 +179,8 @@ def check_memcache(): sys.exit(1) +@task +@timed def check_mysql(): """ Check that mysql is running @@ -178,6 +191,8 @@ def check_mysql(): sys.exit(1) +@task +@timed def check_services(): """ Check that all required services are running diff --git a/pavelib/utils/test/suites/acceptance_suite.py b/pavelib/utils/test/suites/acceptance_suite.py index e21f6088bd757befa1d8440cd91c87d69c9e91b4..79d23eb862dcdd5a45948afc5faed763002b12e2 100644 --- a/pavelib/utils/test/suites/acceptance_suite.py +++ b/pavelib/utils/test/suites/acceptance_suite.py @@ -1,14 +1,70 @@ """ Acceptance test suite """ -from paver.easy import sh, call_task +from paver.easy import sh, call_task, task from pavelib.utils.test import utils as test_utils from pavelib.utils.test.suites.suite import TestSuite from pavelib.utils.envs import Env +from pavelib.utils.timer import timed __test__ = False # do not collect +DBS = { + 'default': Env.REPO_ROOT / 'test_root/db/test_edx.db', + 'student_module_history': Env.REPO_ROOT / 'test_root/db/test_student_module_history.db' +} +DB_CACHES = { + 'default': Env.REPO_ROOT / 'common/test/db_cache/lettuce.db', + 'student_module_history': Env.REPO_ROOT / 'common/test/db_cache/lettuce_student_module_history.db' +} + + +@task +@timed +def setup_acceptance_db(): + """ + TODO: Improve the following + + Since the CMS depends on the existence of some database tables + that are now in common but used to be in LMS (Role/Permissions for Forums) + we need to create/migrate the database tables defined in the LMS. + We might be able to address this by moving out the migrations from + lms/django_comment_client, but then we'd have to repair all the existing + migrations from the upgrade tables in the DB. + But for now for either system (lms or cms), use the lms + definitions to sync and migrate. + """ + + for db in DBS.keys(): + if DBS[db].isfile(): + # Since we are using SQLLite, we can reset the database by deleting it on disk. + DBS[db].remove() + + if all(DB_CACHES[cache].isfile() for cache in DB_CACHES.keys()): + # To speed up migrations, we check for a cached database file and start from that. + # The cached database file should be checked into the repo + + # Copy the cached database to the test root directory + for db_alias in DBS.keys(): + sh("cp {db_cache} {db}".format(db_cache=DB_CACHES[db_alias], db=DBS[db_alias])) + + # Run migrations to update the db, starting from its cached state + for db_alias in sorted(DBS.keys()): + # pylint: disable=line-too-long + sh("./manage.py lms --settings acceptance migrate --traceback --noinput --fake-initial --database {}".format(db_alias)) + sh("./manage.py cms --settings acceptance migrate --traceback --noinput --fake-initial --database {}".format(db_alias)) + else: + # If no cached database exists, syncdb before migrating, then create the cache + for db_alias in sorted(DBS.keys()): + sh("./manage.py lms --settings acceptance migrate --traceback --noinput --database {}".format(db_alias)) + sh("./manage.py cms --settings acceptance migrate --traceback --noinput --database {}".format(db_alias)) + + # Create the cache if it doesn't already exist + for db_alias in DBS.keys(): + sh("cp {db} {db_cache}".format(db_cache=DB_CACHES[db_alias], db=DBS[db_alias])) + + class AcceptanceTest(TestSuite): """ A class for running lettuce acceptance tests. @@ -67,14 +123,6 @@ class AcceptanceTestSuite(TestSuite): def __init__(self, *args, **kwargs): super(AcceptanceTestSuite, self).__init__(*args, **kwargs) self.root = 'acceptance' - self.dbs = { - 'default': Env.REPO_ROOT / 'test_root/db/test_edx.db', - 'student_module_history': Env.REPO_ROOT / 'test_root/db/test_student_module_history.db' - } - self.db_caches = { - 'default': Env.REPO_ROOT / 'common/test/db_cache/lettuce.db', - 'student_module_history': Env.REPO_ROOT / 'common/test/db_cache/lettuce_student_module_history.db' - } self.fasttest = kwargs.get('fasttest', False) if kwargs.get('system'): @@ -102,46 +150,4 @@ class AcceptanceTestSuite(TestSuite): test_utils.clean_test_files() if not self.fasttest: - self._setup_acceptance_db() - - def _setup_acceptance_db(self): - """ - TODO: Improve the following - - Since the CMS depends on the existence of some database tables - that are now in common but used to be in LMS (Role/Permissions for Forums) - we need to create/migrate the database tables defined in the LMS. - We might be able to address this by moving out the migrations from - lms/django_comment_client, but then we'd have to repair all the existing - migrations from the upgrade tables in the DB. - But for now for either system (lms or cms), use the lms - definitions to sync and migrate. - """ - - for db in self.dbs.keys(): - if self.dbs[db].isfile(): - # Since we are using SQLLite, we can reset the database by deleting it on disk. - self.dbs[db].remove() - - if all(self.db_caches[cache].isfile() for cache in self.db_caches.keys()): - # To speed up migrations, we check for a cached database file and start from that. - # The cached database file should be checked into the repo - - # Copy the cached database to the test root directory - for db_alias in self.dbs.keys(): - sh("cp {db_cache} {db}".format(db_cache=self.db_caches[db_alias], db=self.dbs[db_alias])) - - # Run migrations to update the db, starting from its cached state - for db_alias in sorted(self.dbs.keys()): - # pylint: disable=line-too-long - sh("./manage.py lms --settings acceptance migrate --traceback --noinput --fake-initial --database {}".format(db_alias)) - sh("./manage.py cms --settings acceptance migrate --traceback --noinput --fake-initial --database {}".format(db_alias)) - else: - # If no cached database exists, syncdb before migrating, then create the cache - for db_alias in sorted(self.dbs.keys()): - sh("./manage.py lms --settings acceptance migrate --traceback --noinput --database {}".format(db_alias)) - sh("./manage.py cms --settings acceptance migrate --traceback --noinput --database {}".format(db_alias)) - - # Create the cache if it doesn't already exist - for db_alias in self.dbs.keys(): - sh("cp {db} {db_cache}".format(db_cache=self.db_caches[db_alias], db=self.dbs[db_alias])) + setup_acceptance_db() diff --git a/pavelib/utils/test/suites/bokchoy_suite.py b/pavelib/utils/test/suites/bokchoy_suite.py index 4929b589ea770792cb4d0350338145c34c48d67d..7618a503184adefc029b0e3a08f99ce353022674 100644 --- a/pavelib/utils/test/suites/bokchoy_suite.py +++ b/pavelib/utils/test/suites/bokchoy_suite.py @@ -7,11 +7,15 @@ from urllib import urlencode from common.test.acceptance.fixtures.course import CourseFixture, FixtureError from path import Path as path -from paver.easy import sh, BuildFailure +from paver.easy import sh, BuildFailure, cmdopts, task, needs from pavelib.utils.test.suites.suite import TestSuite from pavelib.utils.envs import Env -from pavelib.utils.test import bokchoy_utils +from pavelib.utils.test.bokchoy_utils import ( + clear_mongo, start_servers, check_services, wait_for_test_servers +) +from pavelib.utils.test.bokchoy_options import BOKCHOY_OPTS from pavelib.utils.test import utils as test_utils +from pavelib.utils.timer import timed import os @@ -26,6 +30,77 @@ DEFAULT_NUM_PROCESSES = 1 DEFAULT_VERBOSITY = 2 +@task +@cmdopts(BOKCHOY_OPTS, share_with=['test_bokchoy', 'test_a11y', 'pa11ycrawler']) +@timed +def load_bok_choy_data(options): + """ + Loads data into database from db_fixtures + """ + print 'Loading data from json fixtures in db_fixtures directory' + sh( + "DEFAULT_STORE={default_store}" + " ./manage.py lms --settings bok_choy loaddata --traceback" + " common/test/db_fixtures/*.json".format( + default_store=options.default_store, + ) + ) + + +@task +@cmdopts(BOKCHOY_OPTS, share_with=['test_bokchoy', 'test_a11y', 'pa11ycrawler']) +@timed +def load_courses(options): + """ + Loads courses from options.imports_dir. + + Note: options.imports_dir is the directory that contains the directories + that have courses in them. For example, if the course is located in + `test_root/courses/test-example-course/`, options.imports_dir should be + `test_root/courses/`. + """ + if 'imports_dir' in options: + msg = colorize('green', "Importing courses from {}...".format(options.imports_dir)) + print msg + + sh( + "DEFAULT_STORE={default_store}" + " ./manage.py cms --settings=bok_choy import {import_dir}".format( + default_store=options.default_store, + import_dir=options.imports_dir + ) + ) + + +@task +@timed +def reset_test_database(): + """ + Reset the database used by the bokchoy tests. + """ + sh("{}/scripts/reset-test-db.sh".format(Env.REPO_ROOT)) + + +@task +@needs(['reset_test_database', 'clear_mongo', 'load_bok_choy_data', 'load_courses']) +@cmdopts(BOKCHOY_OPTS, share_with=['test_bokchoy', 'test_a11y', 'pa11ycrawler']) +@timed +def prepare_bokchoy_run(options, call_task): + """ + Sets up and starts servers for a Bok Choy run. If --fasttest is not + specified then static assets are collected + """ + if not options.get('fasttest', False): + print colorize('green', "Generating optimized static assets...") + # Use call_task so that we can specify options + call_task('update_assets', args=['--settings', 'test_static_optimized']) + + # Ensure the test servers are available + msg = colorize('green', "Confirming servers are running...") + print msg + start_servers() # pylint: disable=no-value-for-parameter + + class BokChoyTestSuite(TestSuite): """ TestSuite for running Bok Choy tests @@ -73,24 +148,24 @@ class BokChoyTestSuite(TestSuite): self.log_dir.makedirs_p() self.har_dir.makedirs_p() self.report_dir.makedirs_p() - test_utils.clean_reports_dir() # pylint: disable=no-value-for-parameter + test_utils.clean_reports_dir() # pylint: disable=no-value-for-parameter if not (self.fasttest or self.skip_clean or self.testsonly): test_utils.clean_test_files() msg = colorize('green', "Checking for mongo, memchache, and mysql...") print msg - bokchoy_utils.check_services() + check_services() if not self.testsonly: - self.prepare_bokchoy_run() + prepare_bokchoy_run() # pylint: disable=no-value-for-parameter else: # load data in db_fixtures - self.load_data() + load_bok_choy_data() # pylint: disable=no-value-for-parameter msg = colorize('green', "Confirming servers have started...") print msg - bokchoy_utils.wait_for_test_servers() + wait_for_test_servers() try: # Create course in order to seed forum data underneath. This is # a workaround for a race condition. The first time a course is created; @@ -116,7 +191,7 @@ class BokChoyTestSuite(TestSuite): msg = colorize('green', "Cleaning up databases...") print msg sh("./manage.py lms --settings bok_choy flush --traceback --noinput") - bokchoy_utils.clear_mongo() + clear_mongo() @property def verbosity_processes_command(self): @@ -147,66 +222,6 @@ class BokChoyTestSuite(TestSuite): return command - def prepare_bokchoy_run(self): - """ - Sets up and starts servers for a Bok Choy run. If --fasttest is not - specified then static assets are collected - """ - sh("{}/scripts/reset-test-db.sh".format(Env.REPO_ROOT)) - - if not self.fasttest: - self.generate_optimized_static_assets() - - # Clear any test data already in Mongo or MySQLand invalidate - # the cache - bokchoy_utils.clear_mongo() - self.cache.flush_all() - - # load data in db_fixtures - self.load_data() - - # load courses if self.imports_dir is set - self.load_courses() - - # Ensure the test servers are available - msg = colorize('green', "Confirming servers are running...") - print msg - bokchoy_utils.start_servers(self.default_store, self.coveragerc) - - def load_courses(self): - """ - Loads courses from self.imports_dir. - - Note: self.imports_dir is the directory that contains the directories - that have courses in them. For example, if the course is located in - `test_root/courses/test-example-course/`, self.imports_dir should be - `test_root/courses/`. - """ - msg = colorize('green', "Importing courses from {}...".format(self.imports_dir)) - print msg - - if self.imports_dir: - sh( - "DEFAULT_STORE={default_store}" - " ./manage.py cms --settings=bok_choy import {import_dir}".format( - default_store=self.default_store, - import_dir=self.imports_dir - ) - ) - - def load_data(self): - """ - Loads data into database from db_fixtures - """ - print 'Loading data from json fixtures in db_fixtures directory' - sh( - "DEFAULT_STORE={default_store}" - " ./manage.py lms --settings bok_choy loaddata --traceback" - " common/test/db_fixtures/*.json".format( - default_store=self.default_store, - ) - ) - def run_servers_continuously(self): """ Infinite loop. Servers will continue to run in the current session unless interrupted. diff --git a/pavelib/utils/test/suites/suite.py b/pavelib/utils/test/suites/suite.py index dfe34a97c776f2a8ac739b0938caba5ad352be9c..9c8e712ff8c2d6fba5c2eeb7d1d70268b42843d7 100644 --- a/pavelib/utils/test/suites/suite.py +++ b/pavelib/utils/test/suites/suite.py @@ -61,14 +61,6 @@ class TestSuite(object): """ return None - def generate_optimized_static_assets(self): - """ - Collect static assets using test_static_optimized.py which generates - optimized files to a dedicated test static root. - """ - print colorize('green', "Generating optimized static assets...") - sh("paver update_assets --settings=test_static_optimized") - def run_test(self): """ Runs a self.cmd in a subprocess and waits for it to finish. diff --git a/pavelib/utils/test/utils.py b/pavelib/utils/test/utils.py index 769fe1738625b49a67b410f1f6ae98c7636eec2f..ea189c625d094626bfb295fe237c77fa32ebe3a1 100644 --- a/pavelib/utils/test/utils.py +++ b/pavelib/utils/test/utils.py @@ -3,6 +3,7 @@ Helper functions for test tasks """ from paver.easy import sh, task, cmdopts from pavelib.utils.envs import Env +from pavelib.utils.timer import timed import os import re import subprocess @@ -15,6 +16,7 @@ __test__ = False # do not collect @task +@timed def clean_test_files(): """ Clean fixture files used by tests and .pyc files @@ -42,6 +44,7 @@ def clean_dir(directory): ('skip-clean', 'C', 'skip cleaning repository before running tests'), ('skip_clean', None, 'deprecated in favor of skip-clean'), ]) +@timed def clean_reports_dir(options): """ Clean coverage files, to ensure that we don't use stale data to generate reports. @@ -57,6 +60,7 @@ def clean_reports_dir(options): @task +@timed def clean_mongo(): """ Clean mongo test databases diff --git a/pavelib/utils/timer.py b/pavelib/utils/timer.py new file mode 100644 index 0000000000000000000000000000000000000000..9a521ec6879efdda99ca7bab776e5f6c7c6a0347 --- /dev/null +++ b/pavelib/utils/timer.py @@ -0,0 +1,80 @@ +""" +Tools for timing paver tasks +""" + +from datetime import datetime +import json +import logging +import os +from os.path import dirname, exists +import sys +import traceback +import wrapt + +LOGGER = logging.getLogger(__file__) +PAVER_TIMER_LOG = os.environ.get('PAVER_TIMER_LOG') + + +@wrapt.decorator +def timed(wrapped, instance, args, kwargs): # pylint: disable=unused-argument + """ + Log execution time for a function to a log file. + + Logging is only actually executed if the PAVER_TIMER_LOG environment variable + is set. That variable is expanded for the current user and current + environment variables. It also can have :meth:`~Datetime.strftime` format + identifiers which are substituted using the time when the task started. + + For example, ``PAVER_TIMER_LOG='~/.paver.logs/%Y-%d-%m.log'`` will create a new + log file every day containing reconds for paver tasks run that day, and + will put those log files in the ``.paver.logs`` directory inside the users + home. + + Must be earlier in the decorator stack than the paver task declaration. + """ + start = datetime.utcnow() + exception_info = {} + try: + return wrapped(*args, **kwargs) + except Exception as exc: # pylint: disable=broad-except + exception_info = { + 'exception': "".join(traceback.format_exception_only(type(exc), exc)).strip() + } + raise + finally: + end = datetime.utcnow() + + # N.B. This is intended to provide a consistent interface and message format + # across all of Open edX tooling, so it deliberately eschews standard + # python logging infrastructure. + if PAVER_TIMER_LOG is not None: + + log_path = start.strftime(PAVER_TIMER_LOG) + + log_message = { + 'python_version': sys.version, + 'task': "{}.{}".format(wrapped.__module__, wrapped.__name__), + 'args': [repr(arg) for arg in args], + 'kwargs': {key: repr(value) for key, value in kwargs.items()}, + 'started_at': start.isoformat(' '), + 'ended_at': end.isoformat(' '), + 'duration': (end - start).total_seconds(), + } + log_message.update(exception_info) + + try: + if not exists(dirname(log_path)): + os.makedirs(dirname(log_path)) + + with open(log_path, 'a') as outfile: + json.dump( + log_message, + outfile, + separators=(',', ':'), + sort_keys=True, + ) + outfile.write('\n') + except OSError: + # Squelch OSErrors, because we expect them and they shouldn't + # interrupt the rest of the process. + LOGGER.exception("Unable to write timing logs")