From 378635224bdc88fef4e150405894be56acfbf0a3 Mon Sep 17 00:00:00 2001 From: Dolph Mathews Date: Tue, 29 Jan 2013 11:12:35 -0600 Subject: [PATCH] Generate apache-style common access logs Taking advantage of this middleware either requires enabling verbose/debug or utilizing an external logging.conf which configures an 'access' logger. Example output: 127.0.0.1 - - [2013-01-29T17:15:02.752214] "GET http://localhost:5000/v3/projects HTTP/1.0" 200 16 This patch also revises etc/logging.conf.sample with some more practical defaults (e.g. supporting externally-managed log rotations) in addition to illustrating how to generate an 'access.log' file. DocImpact Change-Id: I2a6048fa5fbf8661a6859d9e3a259d4cfa5fc589 --- .gitignore | 1 + etc/keystone.conf.sample | 13 +++--- etc/logging.conf.sample | 52 ++++++++++++++++++------ keystone/contrib/access/__init__.py | 17 ++++++++ keystone/contrib/access/core.py | 61 +++++++++++++++++++++++++++++ tests/test_keystoneclient.py | 4 +- 6 files changed, 128 insertions(+), 20 deletions(-) create mode 100644 keystone/contrib/access/__init__.py create mode 100644 keystone/contrib/access/core.py diff --git a/.gitignore b/.gitignore index 1cf971c79a..0cce8974b0 100644 --- a/.gitignore +++ b/.gitignore @@ -23,6 +23,7 @@ AUTHORS build/ dist/ etc/keystone.conf +etc/logging.conf tests/test.db.pristine .project .pydevproject diff --git a/etc/keystone.conf.sample b/etc/keystone.conf.sample index 3b67b30042..89ff9e6d55 100644 --- a/etc/keystone.conf.sample +++ b/etc/keystone.conf.sample @@ -200,6 +200,9 @@ paste.filter_factory = keystone.contrib.stats:StatsMiddleware.factory [filter:stats_reporting] paste.filter_factory = keystone.contrib.stats:StatsExtension.factory +[filter:access_log] +paste.filter_factory = keystone.contrib.access:AccessLogMiddleware.factory + [app:public_service] paste.app_factory = keystone.service:public_app_factory @@ -210,13 +213,13 @@ paste.app_factory = keystone.service:v3_app_factory paste.app_factory = keystone.service:admin_app_factory [pipeline:public_api] -pipeline = sizelimit stats_monitoring url_normalize token_auth admin_token_auth xml_body json_body debug ec2_extension user_crud_extension public_service +pipeline = access_log sizelimit stats_monitoring url_normalize token_auth admin_token_auth xml_body json_body debug ec2_extension user_crud_extension public_service [pipeline:admin_api] -pipeline = sizelimit stats_monitoring url_normalize token_auth admin_token_auth xml_body json_body debug stats_reporting ec2_extension s3_extension crud_extension admin_service +pipeline = access_log sizelimit stats_monitoring url_normalize token_auth admin_token_auth xml_body json_body debug stats_reporting ec2_extension s3_extension crud_extension admin_service [pipeline:api_v3] -pipeline = sizelimit stats_monitoring url_normalize token_auth admin_token_auth xml_body json_body debug stats_reporting ec2_extension s3_extension service_v3 +pipeline = access_log sizelimit stats_monitoring url_normalize token_auth admin_token_auth xml_body json_body debug stats_reporting ec2_extension s3_extension service_v3 [app:public_version_service] paste.app_factory = keystone.service:public_version_app_factory @@ -225,10 +228,10 @@ paste.app_factory = keystone.service:public_version_app_factory paste.app_factory = keystone.service:admin_version_app_factory [pipeline:public_version_api] -pipeline = sizelimit stats_monitoring url_normalize xml_body public_version_service +pipeline = access_log sizelimit stats_monitoring url_normalize xml_body public_version_service [pipeline:admin_version_api] -pipeline = sizelimit stats_monitoring url_normalize xml_body admin_version_service +pipeline = access_log sizelimit stats_monitoring url_normalize xml_body admin_version_service [composite:main] use = egg:Paste#urlmap diff --git a/etc/logging.conf.sample b/etc/logging.conf.sample index d87d3a28d2..6cb8c42532 100644 --- a/etc/logging.conf.sample +++ b/etc/logging.conf.sample @@ -1,27 +1,48 @@ [loggers] -keys=root - -[formatters] -keys=normal,normal_with_name,debug +keys=root,access [handlers] -keys=production,file,devel +keys=production,file,access_file,devel + +[formatters] +keys=minimal,normal,debug + + +########### +# Loggers # +########### [logger_root] level=WARNING handlers=file +[logger_access] +level=INFO +qualname=access +handlers=access_file + + +################ +# Log Handlers # +################ + [handler_production] class=handlers.SysLogHandler level=ERROR -formatter=normal_with_name +formatter=normal args=(('localhost', handlers.SYSLOG_UDP_PORT), handlers.SysLogHandler.LOG_USER) [handler_file] -class=FileHandler -level=DEBUG -formatter=normal_with_name -args=('keystone.log', 'a') +class=handlers.WatchedFileHandler +level=WARNING +formatter=normal +args=('error.log',) + +[handler_access_file] +class=handlers.WatchedFileHandler +level=INFO +formatter=minimal +args=('access.log',) [handler_devel] class=StreamHandler @@ -29,10 +50,15 @@ level=NOTSET formatter=debug args=(sys.stdout,) -[formatter_normal] -format=%(asctime)s %(levelname)s %(message)s -[formatter_normal_with_name] +################## +# Log Formatters # +################## + +[formatter_minimal] +format=%(message)s + +[formatter_normal] format=(%(name)s): %(asctime)s %(levelname)s %(message)s [formatter_debug] diff --git a/keystone/contrib/access/__init__.py b/keystone/contrib/access/__init__.py new file mode 100644 index 0000000000..4b78218320 --- /dev/null +++ b/keystone/contrib/access/__init__.py @@ -0,0 +1,17 @@ +# vim: tabstop=4 shiftwidth=4 softtabstop=4 + +# Copyright 2013 OpenStack LLC +# +# 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. + +from keystone.contrib.access.core import * diff --git a/keystone/contrib/access/core.py b/keystone/contrib/access/core.py new file mode 100644 index 0000000000..f022120096 --- /dev/null +++ b/keystone/contrib/access/core.py @@ -0,0 +1,61 @@ +# vim: tabstop=4 shiftwidth=4 softtabstop=4 + +# Copyright 2013 OpenStack LLC +# +# 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 webob +import webob.dec + +from keystone.common import logging +from keystone.common import wsgi +from keystone import config +from keystone.openstack.common import timeutils + + +CONF = config.CONF +LOG = logging.getLogger('access') +APACHE_TIME_FORMAT = '%d/%b/%Y:%H:%M:%S' +APACHE_LOG_FORMAT = ( + '%(remote_addr)s - %(remote_user)s [%(datetime)s] "%(method)s %(url)s ' + '%(http_version)s" %(status)s %(content_length)s') + + +class AccessLogMiddleware(wsgi.Middleware): + """Writes an access log to INFO.""" + + @webob.dec.wsgify + def __call__(self, request): + data = { + 'remote_addr': request.remote_addr, + 'remote_user': request.remote_user or '-', + 'method': request.method, + 'url': request.url, + 'http_version': request.http_version, + 'status': 500, + 'content_length': '-'} + + try: + response = request.get_response(self.application) + data['status'] = response.status_int + data['content_length'] = len(response.body) or '-' + finally: + # must be calculated *after* the application has been called + now = timeutils.utcnow() + + # timeutils may not return UTC, so we can't hardcode +0000 + data['datetime'] = '%s %s' % (now.strftime(APACHE_TIME_FORMAT), + now.strftime('%z') or '+0000') + + LOG.info(APACHE_LOG_FORMAT % data) + return response diff --git a/tests/test_keystoneclient.py b/tests/test_keystoneclient.py index 32e9ef0a23..b7ff1ee982 100644 --- a/tests/test_keystoneclient.py +++ b/tests/test_keystoneclient.py @@ -995,8 +995,8 @@ class KcMasterTestCase(CompatTestCase, KeystoneClientTests): rv = self.public_server.application( req.environ, responseobject.start_fake_response) - responce_json = jsonutils.loads(rv.next()) - new_token_id = responce_json['access']['token']['id'] + response_json = jsonutils.loads(rv.pop()) + new_token_id = response_json['access']['token']['id'] self.assertRaises(client_exceptions.Unauthorized, client.tenants.list) client.auth_token = new_token_id