From 01c19851144c0597f93fe58d98bcc44319df5e7e Mon Sep 17 00:00:00 2001 From: Daisuke Fujita Date: Fri, 29 May 2015 20:39:24 +0900 Subject: [PATCH] Set up every time record log in file This will allow users to record logs of all their commands into a predefined log file, in clouds.yaml. The log should have a format similar to that of oslo.log. Change-Id: I1b334bf429d575fc25809c9706fc0b11116be3f1 Implements: blueprint every-time-record-log-in-file --- openstackclient/shell.py | 55 +++++++++++++---- openstackclient/tests/test_shell.py | 96 +++++++++++++++++++++++++++-- 2 files changed, 136 insertions(+), 15 deletions(-) diff --git a/openstackclient/shell.py b/openstackclient/shell.py index 319f10d..7cef51b 100644 --- a/openstackclient/shell.py +++ b/openstackclient/shell.py @@ -30,6 +30,7 @@ from cliff import help import openstackclient from openstackclient.common import clientmanager from openstackclient.common import commandmanager +from openstackclient.common import context from openstackclient.common import exceptions as exc from openstackclient.common import timing from openstackclient.common import utils @@ -95,6 +96,10 @@ class OpenStackShell(app.App): self.client_manager = None + # Operation log + self.enable_operation_logging = False + self.command_options = None + def configure_logging(self): """Configure logging for the app @@ -107,24 +112,30 @@ class OpenStackShell(app.App): self.options.verbose_level = 3 super(OpenStackShell, self).configure_logging() - root_logger = logging.getLogger('') # Set logging to the requested level if self.options.verbose_level == 0: # --quiet - root_logger.setLevel(logging.ERROR) + log_level = logging.ERROR warnings.simplefilter("ignore") elif self.options.verbose_level == 1: # This is the default case, no --debug, --verbose or --quiet - root_logger.setLevel(logging.WARNING) + log_level = logging.WARNING warnings.simplefilter("ignore") elif self.options.verbose_level == 2: # One --verbose - root_logger.setLevel(logging.INFO) + log_level = logging.INFO warnings.simplefilter("once") elif self.options.verbose_level >= 3: # Two or more --verbose - root_logger.setLevel(logging.DEBUG) + log_level = logging.DEBUG + + # Set the handler logging level of FileHandler(--log-file) + # and StreamHandler + if self.options.log_file: + context.setup_handler_logging_level(logging.FileHandler, log_level) + + context.setup_handler_logging_level(logging.StreamHandler, log_level) # Requests logs some stuff at INFO that we don't want # unless we have DEBUG @@ -147,9 +158,17 @@ class OpenStackShell(app.App): stevedore_log.setLevel(logging.ERROR) iso8601_log.setLevel(logging.ERROR) + # Operation logging + self.operation_log = logging.getLogger("operation_log") + self.operation_log.setLevel(logging.ERROR) + self.operation_log.propagate = False + def run(self, argv): + ret_val = 1 + self.command_options = argv try: - return super(OpenStackShell, self).run(argv) + ret_val = super(OpenStackShell, self).run(argv) + return ret_val except Exception as e: if not logging.getLogger('').handlers: logging.basicConfig() @@ -157,7 +176,13 @@ class OpenStackShell(app.App): self.log.error(traceback.format_exc(e)) else: self.log.error('Exception raised: ' + str(e)) - return 1 + if self.enable_operation_logging: + self.operation_log.error(traceback.format_exc(e)) + + return ret_val + + finally: + self.log.info("END return value: %s", ret_val) def build_option_parser(self, description, version): parser = super(OpenStackShell, self).build_option_parser( @@ -243,7 +268,6 @@ class OpenStackShell(app.App): auth_type = 'token_endpoint' else: auth_type = 'osc_password' - self.log.debug("options: %s", self.options) project_id = getattr(self.options, 'project_id', None) project_name = getattr(self.options, 'project_name', None) @@ -266,14 +290,23 @@ class OpenStackShell(app.App): # Ignore the default value of interface. Only if it is set later # will it be used. cc = cloud_config.OpenStackConfig( - override_defaults={'interface': None, - 'auth_type': auth_type, }) - self.log.debug("defaults: %s", cc.defaults) + override_defaults={ + 'interface': None, + 'auth_type': auth_type, + }, + ) self.cloud = cc.get_one_cloud( cloud=self.options.cloud, argparse=self.options, ) + + # Set up every time record log in file and logging start + context.setup_logging(self, self.cloud) + + self.log.info("START with options: %s", self.command_options) + self.log.debug("options: %s", self.options) + self.log.debug("defaults: %s", cc.defaults) self.log.debug("cloud cfg: %s", self.cloud.config) # Set up client TLS diff --git a/openstackclient/tests/test_shell.py b/openstackclient/tests/test_shell.py index e2f0580..5b84475 100644 --- a/openstackclient/tests/test_shell.py +++ b/openstackclient/tests/test_shell.py @@ -77,6 +77,8 @@ CLOUD_2 = { 'username': 'zaphod', }, 'region_name': 'occ-cloud', + 'log_file': '/tmp/test_log_file', + 'log_level': 'debug', } } } @@ -621,9 +623,12 @@ class TestShellCli(TestShell): @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") - def test_shell_args_cloud_public(self, config_mock, public_mock): + @mock.patch("openstackclient.common.context._setup_handler_for_logging") + def test_shell_args_cloud_public(self, setup_handler, config_mock, + public_mock): config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_2)) public_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + setup_handler.return_value = mock.MagicMock() _shell = make_shell() fake_execute( @@ -661,9 +666,12 @@ class TestShellCli(TestShell): @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") - def test_shell_args_precedence(self, config_mock, vendor_mock): + @mock.patch("openstackclient.common.context._setup_handler_for_logging") + def test_shell_args_precedence(self, setup_handler, config_mock, + vendor_mock): config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_2)) vendor_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + setup_handler.return_value = mock.MagicMock() _shell = make_shell() # Test command option overriding config file value @@ -715,9 +723,12 @@ class TestShellCliEnv(TestShell): @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") - def test_shell_args_precedence_1(self, config_mock, vendor_mock): + @mock.patch("openstackclient.common.context._setup_handler_for_logging") + def test_shell_args_precedence_1(self, setup_handler, config_mock, + vendor_mock): config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_2)) vendor_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + setup_handler.return_value = mock.MagicMock() _shell = make_shell() # Test env var @@ -756,9 +767,12 @@ class TestShellCliEnv(TestShell): @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") - def test_shell_args_precedence_2(self, config_mock, vendor_mock): + @mock.patch("openstackclient.common.context._setup_handler_for_logging") + def test_shell_args_precedence_2(self, setup_handler, config_mock, + vendor_mock): config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_2)) vendor_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + setup_handler.return_value = mock.MagicMock() _shell = make_shell() # Test command option overriding config file value @@ -796,3 +810,77 @@ class TestShellCliEnv(TestShell): 'krikkit', _shell.cloud.config['region_name'], ) + + +class TestShellCliLogging(TestShell): + def setUp(self): + super(TestShellCliLogging, self).setUp() + + def tearDown(self): + super(TestShellCliLogging, self).tearDown() + + @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") + @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") + @mock.patch("openstackclient.common.context._setup_handler_for_logging") + def test_shell_args_precedence_1(self, setup_handler, config_mock, + vendor_mock): + config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_2)) + vendor_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + setup_handler.return_value = mock.MagicMock() + _shell = make_shell() + + # These come from clouds.yaml + fake_execute( + _shell, + "--os-cloud megacloud list user", + ) + self.assertEqual( + 'megacloud', + _shell.cloud.name, + ) + + self.assertEqual( + '/tmp/test_log_file', + _shell.cloud.config['log_file'], + ) + self.assertEqual( + 'debug', + _shell.cloud.config['log_level'], + ) + + @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") + @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") + def test_shell_args_precedence_2(self, config_mock, vendor_mock): + config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_1)) + vendor_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + _shell = make_shell() + + # Test operation_log_file not set + fake_execute( + _shell, + "--os-cloud scc list user", + ) + self.assertEqual( + False, + _shell.enable_operation_logging, + ) + + @mock.patch("os_client_config.config.OpenStackConfig._load_vendor_file") + @mock.patch("os_client_config.config.OpenStackConfig._load_config_file") + @mock.patch("openstackclient.common.context._setup_handler_for_logging") + def test_shell_args_precedence_3(self, setup_handler, config_mock, + vendor_mock): + config_mock.return_value = ('file.yaml', copy.deepcopy(CLOUD_2)) + vendor_mock.return_value = ('file.yaml', copy.deepcopy(PUBLIC_1)) + setup_handler.return_value = mock.MagicMock() + _shell = make_shell() + + # Test enable_operation_logging set + fake_execute( + _shell, + "--os-cloud megacloud list user", + ) + self.assertEqual( + True, + _shell.enable_operation_logging, + )