Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

enhancement to AccessLogger #1303

Merged
merged 10 commits into from
Oct 15, 2016
23 changes: 17 additions & 6 deletions aiohttp/helpers.py
Original file line number Diff line number Diff line change
Expand Up @@ -281,10 +281,12 @@ def __init__(self, logger, log_format=LOG_FORMAT):

"""
self.logger = logger

_compiled_format = AccessLogger._FORMAT_CACHE.get(log_format)
if not _compiled_format:
_compiled_format = self.compile_format(log_format)
AccessLogger._FORMAT_CACHE[log_format] = _compiled_format

self._log_format, self._methods = _compiled_format

def compile_format(self, log_format):
Expand All @@ -311,14 +313,17 @@ def compile_format(self, log_format):

log_format = log_format.replace("%l", "-")
log_format = log_format.replace("%u", "-")
methods = []
methods = [] # list of tuples: (format_str, format_method)

for atom in self.FORMAT_RE.findall(log_format):
if atom[1] == '':
methods.append(getattr(AccessLogger, '_format_%s' % atom[0]))
m = getattr(AccessLogger, '_format_%s' % atom[0])
else:
m = getattr(AccessLogger, '_format_%s' % atom[2])
methods.append(functools.partial(m, atom[1]))
m = functools.partial(m, atom[1])

methods.append(('%%%s' % atom[0], m))

log_format = self.FORMAT_RE.sub(r'%s', log_format)
log_format = self.CLEANUP_RE.sub(r'%\1', log_format)
return log_format, methods
Expand All @@ -331,6 +336,7 @@ def _format_e(key, args):
def _format_i(key, args):
if not args[0]:
return '(no headers)'

# suboptimal, make istr(key) once
return args[0].headers.get(key, '-')

Expand Down Expand Up @@ -390,7 +396,7 @@ def _format_D(args):
return round(args[4] * 1000000)

def _format_line(self, args):
return tuple(m(args) for m in self._methods)
return tuple((m[0], m[1](args)) for m in self._methods)

def log(self, message, environ, response, transport, time):
"""Log access.
Expand All @@ -402,8 +408,13 @@ def log(self, message, environ, response, transport, time):
:param float time: Time taken to serve the request.
"""
try:
self.logger.info(self._log_format % self._format_line(
[message, environ, response, transport, time]))
fmt_info = self._format_line(
[message, environ, response, transport, time])

extra = {name: value for name, value in fmt_info}
self.logger.info(self._log_format %
tuple([value for _, value in fmt_info]),
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is it fmt_info.values()?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not currently as fmt_info is a tuple of tuples to keep items in format order. Would you prefer it be a OrderedDict/namedtuple?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Aaah, got it.
But if you'll return just extra OrderedDict from _format_line the code may look better.

Also keys for headers/envvars from dicts like extra={'%{None}i': '-', '%{SPAM}e': 'EGGS', '%{Content-Length}o': 123, '%{User-Agent}i': 'Mock/1.0'} looks... Well, they looks non-intuitive.
I would expect something like input_header[User-Agent] instead of cryptic %{User-Agent}i.

Maybe constructing _log_format as format accepting params by name in new-styled .format form like "{status} {remote_address} {input_headers[User-Agent]}" makes sense?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually reading the docs for the new formatter it seems like the logging module in python 3.2+ supports the new '{}' style formatting, making this solution a win-win and removes any hesitations I had for this solution, yay! I'll code something up shortly.

extra=extra)
except Exception:
self.logger.exception("Error in logging")

Expand Down