Skip to content

Commit 6c46355

Browse files
committed
Optimize log formatting
There is no way to change the configuration variables we want printed in log messages, so format them in the constructor. This will save us from overridding the format method and a couple cpu cycles every log message. This change also moves the _LOG* variables into the formatter since they aren't really globally needed. Change-Id: I706e9db7da3daec20332f9d1533fe665f2739dea Implements: blueprint logging-migration
1 parent d828429 commit 6c46355

2 files changed

Lines changed: 60 additions & 92 deletions

File tree

openstackclient/common/context.py

Lines changed: 35 additions & 55 deletions
Original file line numberDiff line numberDiff line change
@@ -16,11 +16,6 @@
1616
import logging
1717
import warnings
1818

19-
_LOG_MESSAGE_FORMAT = ('%(asctime)s.%(msecs)03d %(process)d '
20-
'%(levelname)s %(name)s [%(clouds_name)s '
21-
'%(username)s %(project_name)s] %(message)s')
22-
_LOG_DATE_FORMAT = '%Y-%m-%d %H:%M:%S'
23-
2419

2520
def log_level_from_options(options):
2621
# if --debug, --quiet or --verbose is not specified,
@@ -73,6 +68,37 @@ def set_warning_filter(log_level):
7368
warnings.simplefilter("once")
7469

7570

71+
class _FileFormatter(logging.Formatter):
72+
"""Customize the logging format for logging handler"""
73+
_LOG_MESSAGE_BEGIN = (
74+
'%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s ')
75+
_LOG_MESSAGE_CONTEXT = '[%(cloud)s %(username)s %(project)s] '
76+
_LOG_MESSAGE_END = '%(message)s'
77+
_LOG_DATE_FORMAT = '%Y-%m-%d %H:%M:%S'
78+
79+
def __init__(self, options=None, config=None, **kwargs):
80+
context = {}
81+
if options:
82+
context = {
83+
'cloud': getattr(options, 'cloud', ''),
84+
'project': getattr(options, 'os_project_name', ''),
85+
'username': getattr(options, 'username', ''),
86+
}
87+
elif config:
88+
context = {
89+
'cloud': config.config.get('cloud', ''),
90+
'project': config.auth.get('project_name', ''),
91+
'username': config.auth.get('username', ''),
92+
}
93+
if context:
94+
self.fmt = (self._LOG_MESSAGE_BEGIN +
95+
(self._LOG_MESSAGE_CONTEXT % context) +
96+
self._LOG_MESSAGE_END)
97+
else:
98+
self.fmt = self._LOG_MESSAGE_BEGIN + self._LOG_MESSAGE_END
99+
logging.Formatter.__init__(self, self.fmt, self._LOG_DATE_FORMAT)
100+
101+
76102
def setup_handler_logging_level(handler_type, level):
77103
"""Setup of the handler for set the logging level
78104
@@ -103,17 +129,13 @@ def setup_logging(shell, cloud_config):
103129
log_file = cloud_config.config.get('log_file', None)
104130
if log_file:
105131
# setup the logging context
106-
log_cont = _LogContext(
107-
clouds_name=cloud_config.config.get('cloud'),
108-
project_name=cloud_config.auth.get('project_name'),
109-
username=cloud_config.auth.get('username'),
110-
)
132+
formatter = _FileFormatter(config=cloud_config)
111133
# setup the logging handler
112134
log_handler = _setup_handler_for_logging(
113135
logging.FileHandler,
114136
log_level,
115137
file_name=log_file,
116-
context=log_cont,
138+
formatter=formatter,
117139
)
118140
if log_level == logging.DEBUG:
119141
# DEBUG only.
@@ -123,7 +145,7 @@ def setup_logging(shell, cloud_config):
123145
shell.operation_log.addHandler(log_handler)
124146

125147

126-
def _setup_handler_for_logging(handler_type, level, file_name, context):
148+
def _setup_handler_for_logging(handler_type, level, file_name, formatter):
127149
"""Setup of the handler
128150
129151
Setup of the handler for addition of the logging handler,
@@ -132,7 +154,7 @@ def _setup_handler_for_logging(handler_type, level, file_name, context):
132154
:param handler_type: type of logging handler
133155
:param level: logging level
134156
:param file_name: name of log-file
135-
:param context: instance of _LogContext()
157+
:param formatter: instance of logging.Formatter
136158
:return: logging handler
137159
"""
138160

@@ -142,11 +164,6 @@ def _setup_handler_for_logging(handler_type, level, file_name, context):
142164
handler = logging.FileHandler(
143165
filename=file_name,
144166
)
145-
formatter = _LogContextFormatter(
146-
context=context,
147-
fmt=_LOG_MESSAGE_FORMAT,
148-
datefmt=_LOG_DATE_FORMAT,
149-
)
150167
handler.setFormatter(formatter)
151168
handler.setLevel(level)
152169

@@ -155,40 +172,3 @@ def _setup_handler_for_logging(handler_type, level, file_name, context):
155172
root_logger.addHandler(handler)
156173

157174
return handler
158-
159-
160-
class _LogContext(object):
161-
"""Helper class to represent useful information about a logging context"""
162-
163-
def __init__(self, clouds_name=None, project_name=None, username=None):
164-
"""Initialize _LogContext instance
165-
166-
:param clouds_name: one of the cloud name in configuration file
167-
:param project_name: the project name in cloud(clouds_name)
168-
:param username: the user name in cloud(clouds_name)
169-
"""
170-
171-
self.clouds_name = clouds_name
172-
self.project_name = project_name
173-
self.username = username
174-
175-
def to_dict(self):
176-
return {
177-
'clouds_name': self.clouds_name,
178-
'project_name': self.project_name,
179-
'username': self.username
180-
}
181-
182-
183-
class _LogContextFormatter(logging.Formatter):
184-
"""Customize the logging format for logging handler"""
185-
186-
def __init__(self, *args, **kwargs):
187-
self.context = kwargs.pop('context', None)
188-
logging.Formatter.__init__(self, *args, **kwargs)
189-
190-
def format(self, record):
191-
d = self.context.to_dict()
192-
for k, v in d.items():
193-
setattr(record, k, v)
194-
return logging.Formatter.format(self, record)

openstackclient/tests/common/test_context.py

Lines changed: 25 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -107,40 +107,28 @@ def test_set_warning_filter(self, simplefilter):
107107
simplefilter.assert_called_with("once")
108108

109109

110-
class Test_LogContext(utils.TestCase):
111-
def setUp(self):
112-
super(Test_LogContext, self).setUp()
113-
114-
def test_context(self):
115-
ctx = context._LogContext()
116-
self.assertTrue(ctx)
117-
118-
def test_context_to_dict(self):
119-
ctx = context._LogContext('cloudsName', 'projectName', 'userNmae')
120-
ctx_dict = ctx.to_dict()
121-
self.assertEqual('cloudsName', ctx_dict['clouds_name'])
122-
self.assertEqual('projectName', ctx_dict['project_name'])
123-
self.assertEqual('userNmae', ctx_dict['username'])
124-
125-
126-
class Test_LogContextFormatter(utils.TestCase):
127-
def setUp(self):
128-
super(Test_LogContextFormatter, self).setUp()
129-
self.ctx = context._LogContext('cloudsName', 'projectName', 'userNmae')
130-
self.addfmt = "%(clouds_name)s %(project_name)s %(username)s"
131-
132-
def test_contextrrormatter(self):
133-
ctxfmt = context._LogContextFormatter()
134-
self.assertTrue(ctxfmt)
135-
136-
def test_context_format(self):
137-
record = mock.MagicMock()
138-
logging.Formatter.format = mock.MagicMock()
139-
logging.Formatter.format.return_value = record
140-
141-
ctxfmt = context._LogContextFormatter(context=self.ctx,
142-
fmt=self.addfmt)
143-
addctx = ctxfmt.format(record)
144-
self.assertEqual('cloudsName', addctx.clouds_name)
145-
self.assertEqual('projectName', addctx.project_name)
146-
self.assertEqual('userNmae', addctx.username)
110+
class TestFileFormatter(utils.TestCase):
111+
def test_nothing(self):
112+
formatter = context._FileFormatter()
113+
self.assertEqual(('%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
114+
'%(name)s %(message)s'), formatter.fmt)
115+
116+
def test_options(self):
117+
class Opts(object):
118+
cloud = 'cloudy'
119+
os_project_name = 'projecty'
120+
username = 'usernamey'
121+
options = Opts()
122+
formatter = context._FileFormatter(options=options)
123+
self.assertEqual(('%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
124+
'%(name)s [cloudy usernamey projecty] %(message)s'),
125+
formatter.fmt)
126+
127+
def test_config(self):
128+
config = mock.Mock()
129+
config.config = {'cloud': 'cloudy'}
130+
config.auth = {'project_name': 'projecty', 'username': 'usernamey'}
131+
formatter = context._FileFormatter(config=config)
132+
self.assertEqual(('%(asctime)s.%(msecs)03d %(process)d %(levelname)s '
133+
'%(name)s [cloudy usernamey projecty] %(message)s'),
134+
formatter.fmt)

0 commit comments

Comments
 (0)