openstack/python-openstackclient
Code Issues Proposed changes

Set up every time record log in file

Browse Source 
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
This commit is contained in:
Daisuke Fujita
2015-05-29 20:39:24 +09:00
committed by TerryHowe
parent 46cc7d12ad
commit e23dd6de58
6 changed files with 479 additions and 15 deletions
Download Patch File Download Diff File Expand all files Collapse all files

71
doc/source/configuration.rst
View File

@@ -143,3 +143,74 @@ Debugging
You may find the :doc:`config show <command-objects/config>`
helpful to debug configuration issues. It will display your current
configuration.
Logging Settings
----------------
By setting `log_level` or `log_file` in the configuration
:file:`clouds.yaml`, a user may enable additional logging::
clouds:
devstack:
auth:
auth_url: http://192.168.122.10:35357/
project_name: demo
username: demo
password: 0penstack
region_name: RegionOne
operation_log:
logging: TRUE
file: /tmp/openstackclient_demo.log
level: info
ds-admin:
auth:
auth_url: http://192.168.122.10:35357/
project_name: admin
username: admin
password: 0penstack
region_name: RegionOne
log_file: /tmp/openstackclient_admin.log
log_level: debug
:dfn:`log_file`: ``</path/file-name>``
Full path to logging file.
:dfn:`log_level`: ``error`` | ``info`` | ``debug``
If log level is not set, ``warning`` will be used.
If log level is ``info``, the following information is recorded:
* cloud name
* user name
* project name
* CLI start time (logging start time)
* CLI end time
* CLI arguments
* CLI return value
* and any ``info`` messages.
If log level is ``debug``, the following information is recorded:
* cloud name
* user name
* project name
* CLI start time (logging start time)
* CLI end time
* CLI arguments
* CLI return value
* API request header/body
* API response header/body
* and any ``debug`` messages.
When a command is executed, these logs are saved every time. Recording the user
operations can help to identify resource changes and provide useful information
for troubleshooting.
If saving the output of a single command use the `--log-file` option instead.
* `--log-file <LOG_FILE>`
The logging level for `--log-file` can be set by using following options.
* `-v, --verbose`
* `-q, --quiet`
* `--debug`

21
doc/source/man/openstack.rst
View File

@@ -123,6 +123,18 @@ OPTIONS
:option:`--os-interface` <interface>
Interface type. Valid options are `public`, `admin` and `internal`.
:option:`--log-file` <LOGFILE>
Specify a file to log output. Disabled by default.
:option:`-v, --verbose`
Increase verbosity of output. Can be repeated.
:option:`-q, --quiet`
suppress output except warnings and errors
:option:`--debug`
show tracebacks on errors and set verbosity to debug
COMMANDS
========
@@ -240,6 +252,15 @@ When :option:`--os-token` and :option:`--os-url` are both present the
:option:`--os-auth-url` and :option:`--os-username` are present ``password``
auth type is selected.
Logging Settings
----------------
:program:`openstack` can record the operation history by logging settings
in configuration file. Recording the user operation, it can identify the
change of the resource and it becomes useful information for troubleshooting.
See :doc:`../configuration` about Logging Settings for more details.
NOTES
=====

149
openstackclient/common/context.py Normal file
View File

@@ -0,0 +1,149 @@
# 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.
#
"""Context and Formatter"""
import logging
_LOG_MESSAGE_FORMAT = ('%(asctime)s.%(msecs)03d %(process)d '
'%(levelname)s %(name)s [%(clouds_name)s '
'%(username)s %(project_name)s] %(message)s')
_LOG_DATE_FORMAT = '%Y-%m-%d %H:%M:%S'
def setup_handler_logging_level(handler_type, level):
"""Setup of the handler for set the logging level
:param handler_type: type of logging handler
:param level: logging level
:return: None
"""
# Set the handler logging level of FileHandler(--log-file)
# and StreamHandler
for h in logging.getLogger('').handlers:
if type(h) is handler_type:
h.setLevel(level)
def setup_logging(shell, cloud_config):
"""Get one cloud configuration from configuration file and setup logging
:param shell: instance of openstackclient shell
:param cloud_config:
instance of the cloud specified by --os-cloud
in the configuration file
:return: None
"""
log_level = logging.WARNING
log_file = cloud_config.config.get('log_file', None)
if log_file:
# setup the logging level
get_log_level = cloud_config.config.get('log_level')
if get_log_level:
log_level = {
'error': logging.ERROR,
'info': logging.INFO,
'debug': logging.DEBUG,
}.get(get_log_level, logging.WARNING)
# setup the logging context
log_cont = _LogContext(
clouds_name=cloud_config.config.get('cloud'),
project_name=cloud_config.auth.get('project_name'),
username=cloud_config.auth.get('username'),
)
# setup the logging handler
log_handler = _setup_handler_for_logging(
logging.FileHandler,
log_level,
file_name=log_file,
context=log_cont,
)
if log_level == logging.DEBUG:
# DEBUG only.
# setup the operation_log
shell.enable_operation_logging = True
shell.operation_log.setLevel(logging.DEBUG)
shell.operation_log.addHandler(log_handler)
def _setup_handler_for_logging(handler_type, level, file_name, context):
"""Setup of the handler
Setup of the handler for addition of the logging handler,
changes of the logging format, change of the logging level,
:param handler_type: type of logging handler
:param level: logging level
:param file_name: name of log-file
:param context: instance of _LogContext()
:return: logging handler
"""
root_logger = logging.getLogger('')
handler = None
# Setup handler for FileHandler(--os-cloud)
handler = logging.FileHandler(
filename=file_name,
)
formatter = _LogContextFormatter(
context=context,
fmt=_LOG_MESSAGE_FORMAT,
datefmt=_LOG_DATE_FORMAT,
)
handler.setFormatter(formatter)
handler.setLevel(level)
# If both `--log-file` and `--os-cloud` are specified,
# the log is output to each file.
root_logger.addHandler(handler)
return handler
class _LogContext(object):
"""Helper class to represent useful information about a logging context"""
def __init__(self, clouds_name=None, project_name=None, username=None):
"""Initialize _LogContext instance
:param clouds_name: one of the cloud name in configuration file
:param project_name: the project name in cloud(clouds_name)
:param username: the user name in cloud(clouds_name)
"""
self.clouds_name = clouds_name
self.project_name = project_name
self.username = username
def to_dict(self):
return {
'clouds_name': self.clouds_name,
'project_name': self.project_name,
'username': self.username
}
class _LogContextFormatter(logging.Formatter):
"""Customize the logging format for logging handler"""
def __init__(self, *args, **kwargs):
self.context = kwargs.pop('context', None)
logging.Formatter.__init__(self, *args, **kwargs)
def format(self, record):
d = self.context.to_dict()
for k, v in d.items():
setattr(record, k, v)
return logging.Formatter.format(self, record)

55
openstackclient/shell.py
View File

@@ -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

102
openstackclient/tests/common/test_context.py Normal file
View File

@@ -0,0 +1,102 @@
# 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 logging
import mock
import os
from openstackclient.common import context
from openstackclient.tests import utils
class TestContext(utils.TestCase):
TEST_LOG_FILE = "/tmp/test_log_file"
def setUp(self):
super(TestContext, self).setUp()
def tearDown(self):
super(TestContext, self).tearDown()
if os.path.exists(self.TEST_LOG_FILE):
os.remove(self.TEST_LOG_FILE)
def setup_handler_logging_level(self):
handler_type = logging.FileHandler
handler = logging.FileHandler(filename=self.TEST_LOG_FILE)
handler.setLevel(logging.ERROR)
logging.getLogger('').addHandler(handler)
context.setup_handler_logging_level(handler_type, logging.INFO)
self.log.info("test log")
ld = open(self.TEST_LOG_FILE)
line = ld.readlines()
ld.close()
if os.path.exists(self.TEST_LOG_FILE):
os.remove(self.TEST_LOG_FILE)
self.assertGreaterEqual(line.find("test log"), 0)
@mock.patch("openstackclient.common.context._setup_handler_for_logging")
def test_setup_logging(self, setuph):
setuph.return_value = mock.MagicMock()
shell = mock.MagicMock()
cloud_config = mock.MagicMock()
cloud_config.auth = {
'project_name': 'heart-o-gold',
'username': 'zaphod'
}
cloud_config.config = {
'log_level': 'debug',
'log_file': self.TEST_LOG_FILE,
'cloud': 'megadodo'
}
context.setup_logging(shell, cloud_config)
self.assertEqual(True, shell.enable_operation_logging)
class Test_LogContext(utils.TestCase):
def setUp(self):
super(Test_LogContext, self).setUp()
def test_context(self):
ctx = context._LogContext()
self.assertTrue(ctx)
def test_context_to_dict(self):
ctx = context._LogContext('cloudsName', 'projectName', 'userNmae')
ctx_dict = ctx.to_dict()
self.assertEqual('cloudsName', ctx_dict['clouds_name'])
self.assertEqual('projectName', ctx_dict['project_name'])
self.assertEqual('userNmae', ctx_dict['username'])
class Test_LogContextFormatter(utils.TestCase):
def setUp(self):
super(Test_LogContextFormatter, self).setUp()
self.ctx = context._LogContext('cloudsName', 'projectName', 'userNmae')
self.addfmt = "%(clouds_name)s %(project_name)s %(username)s"
def test_contextrrormatter(self):
ctxfmt = context._LogContextFormatter()
self.assertTrue(ctxfmt)
def test_context_format(self):
record = mock.MagicMock()
logging.Formatter.format = mock.MagicMock()
logging.Formatter.format.return_value = record
ctxfmt = context._LogContextFormatter(context=self.ctx,
fmt=self.addfmt)
addctx = ctxfmt.format(record)
self.assertEqual('cloudsName', addctx.clouds_name)
self.assertEqual('projectName', addctx.project_name)
self.assertEqual('userNmae', addctx.username)

96
openstackclient/tests/test_shell.py
View File

@@ -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,
)