diff --git a/nose.cfg b/nose.cfg new file mode 100644 index 00000000000..1243af702b8 --- /dev/null +++ b/nose.cfg @@ -0,0 +1,2 @@ +[nosetests] +logging-filter=azure.cli.testsdk,vcr_test_base diff --git a/scripts/automation/tests/nose_helper.py b/scripts/automation/tests/nose_helper.py index 1e251df9eed..961e9e2c3a7 100644 --- a/scripts/automation/tests/nose_helper.py +++ b/scripts/automation/tests/nose_helper.py @@ -5,6 +5,10 @@ from __future__ import print_function +import os.path +from ..utilities.path import get_repo_root + + def get_nose_runner(report_folder, parallel=True, process_timeout=600, process_restart=True, xunit_report=False, exclude_integration=True): """Create a nose execution method""" @@ -24,7 +28,7 @@ def _run_nose(test_folders): or not os.path.isdir(report_folder): raise ValueError('Report folder {} does not exist'.format(report_folder)) - arguments = [__file__, '-v', '--nologcapture'] + arguments = [__file__, '-v', '-c', os.path.join(get_repo_root(), 'nose.cfg')] if parallel: arguments += ['--processes=-1', '--process-timeout={}'.format(process_timeout)] if process_restart: @@ -36,12 +40,8 @@ def _run_nose(test_folders): else: test_report = '' - if exclude_integration: - arguments += ['--ignore-files=integration*'] - debug_file = os.path.join(report_folder, 'test-debug.log') arguments += ['--debug-log={}'.format(debug_file)] - arguments += ['--nologcapture'] arguments.extend(test_folders) result = nose.run(argv=arguments) diff --git a/src/azure-cli-testsdk/azure/cli/testsdk/base.py b/src/azure-cli-testsdk/azure/cli/testsdk/base.py index dfc843d4a6d..54a1bd258b7 100644 --- a/src/azure-cli-testsdk/azure/cli/testsdk/base.py +++ b/src/azure-cli-testsdk/azure/cli/testsdk/base.py @@ -3,8 +3,6 @@ # Licensed under the MIT License. See License.txt in the project root for license information. # -------------------------------------------------------------------------------------------- -from __future__ import print_function -import datetime import unittest import os import inspect @@ -29,7 +27,7 @@ from .utilities import create_random_name from .decorators import live_only -logger = logging.getLogger('azuer.cli.testsdk') +logger = logging.getLogger('azure.cli.testsdk') class IntegrationTestBase(unittest.TestCase): @@ -37,19 +35,9 @@ def __init__(self, method_name): super(IntegrationTestBase, self).__init__(method_name) self.diagnose = os.environ.get(ENV_TEST_DIAGNOSE, None) == 'True' - def cmd(self, command, checks=None, expect_failure=False): - if self.diagnose: - begin = datetime.datetime.now() - print('\nExecuting command: {}'.format(command)) - - result = execute(command, expect_failure=expect_failure) - - if self.diagnose: - duration = datetime.datetime.now() - begin - print('\nCommand accomplished in {} s. Exit code {}.\n{}'.format( - duration.total_seconds(), result.exit_code, result.output)) - - return result.assert_with_checks(checks) + @classmethod + def cmd(cls, command, checks=None, expect_failure=False): + return execute(command, expect_failure=expect_failure).assert_with_checks(checks) def create_random_name(self, prefix, length): # pylint: disable=no-self-use return create_random_name(prefix=prefix, length=length) @@ -238,17 +226,21 @@ def _custom_request_query_matcher(cls, r1, r2): class ExecutionResult(object): # pylint: disable=too-few-public-methods def __init__(self, command, expect_failure=False, in_process=True): - logger.info('Execute command %s', command) if in_process: self._in_process_execute(command) else: self._out_of_process_execute(command) if expect_failure and self.exit_code == 0: - raise AssertionError('The command is expected to fail but it doesn\'.') + logger.error('Command "%s" => %d. (It did not fail as expected) Output: %s', command, + self.exit_code, self.output) + raise AssertionError('The command did not fail as it was expected.') elif not expect_failure and self.exit_code != 0: + logger.error('Command "%s" => %d. Output: %s', command, self.exit_code, self.output) raise AssertionError('The command failed. Exit code: {}'.format(self.exit_code)) + logger.info('Command "%s" => %d.', command, self.exit_code) + self.json_value = None self.skip_assert = os.environ.get(ENV_SKIP_ASSERT, None) == 'True' @@ -260,8 +252,6 @@ def assert_with_checks(self, *args): elif callable(each): checks.append(each) - logger.info('Checkers to be executed %s', len(checks)) - if not self.skip_assert: for c in checks: c(self) diff --git a/src/azure-cli-testsdk/azure/cli/testsdk/vcr_test_base.py b/src/azure-cli-testsdk/azure/cli/testsdk/vcr_test_base.py index dfc63a5fc63..fd23ae3c895 100644 --- a/src/azure-cli-testsdk/azure/cli/testsdk/vcr_test_base.py +++ b/src/azure-cli-testsdk/azure/cli/testsdk/vcr_test_base.py @@ -15,6 +15,7 @@ import sys import tempfile import traceback +import logging from random import choice from string import digits, ascii_lowercase @@ -45,6 +46,7 @@ MOCKED_TENANT_ID = '00000000-0000-0000-0000-000000000000' MOCKED_STORAGE_ACCOUNT = 'dummystorage' +logger = logging.getLogger('vcr_test_base') # MOCK METHODS @@ -109,7 +111,7 @@ def _mock_subscriptions(self): # pylint: disable=unused-argument def _mock_user_access_token(_, _1, _2, _3): # pylint: disable=unused-argument - return ('Bearer', 'top-secret-token-for-you', None) + return 'Bearer', 'top-secret-token-for-you', None def _mock_operation_delay(_): @@ -284,7 +286,6 @@ def __init__(self, test_file, test_name, run_live=False, debug=False, debug_vcr= self.exception = CLIError('No recorded result provided for {}.'.format(self.test_name)) if debug_vcr: - import logging logging.basicConfig() vcr_log = logging.getLogger('vcr') vcr_log.setLevel(logging.INFO) @@ -427,8 +428,11 @@ def cmd(self, command, checks=None, allowed_exceptions=None, cli_main(command_list, file=output) except Exception as ex: # pylint: disable=broad-except ex_msg = str(ex) + logger.error('Command "%s" => %s. Output: %s', command, ex_msg, output.getvalue()) if not next((x for x in allowed_exceptions if x in ex_msg), None): raise ex + + logger.info('Command "%s" => %s.', command, 'success') self._track_executed_commands(command_list) result = output.getvalue().strip() output.close()