Merge "request_log addition for running under uwsgi"
This commit is contained in:
Jenkins
Gerrit Code Review
commit
62c4535a85
|
|
@ -28,17 +28,20 @@ use = call:nova.api.openstack.urlmap:urlmap_factory
|
|||
|
||||
[composite:openstack_compute_api_v21]
|
||||
use = call:nova.api.auth:pipeline_factory_v21
|
||||
noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler noauth2 osapi_compute_app_v21
|
||||
keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler authtoken keystonecontext osapi_compute_app_v21
|
||||
noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap request_log sizelimit osprofiler noauth2 osapi_compute_app_v21
|
||||
keystone = cors http_proxy_to_wsgi compute_req_id faultwrap request_log sizelimit osprofiler authtoken keystonecontext osapi_compute_app_v21
|
||||
|
||||
[composite:openstack_compute_api_v21_legacy_v2_compatible]
|
||||
use = call:nova.api.auth:pipeline_factory_v21
|
||||
noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler noauth2 legacy_v2_compatible osapi_compute_app_v21
|
||||
keystone = cors http_proxy_to_wsgi compute_req_id faultwrap sizelimit osprofiler authtoken keystonecontext legacy_v2_compatible osapi_compute_app_v21
|
||||
noauth2 = cors http_proxy_to_wsgi compute_req_id faultwrap request_log sizelimit osprofiler noauth2 legacy_v2_compatible osapi_compute_app_v21
|
||||
keystone = cors http_proxy_to_wsgi compute_req_id faultwrap request_log sizelimit osprofiler authtoken keystonecontext legacy_v2_compatible osapi_compute_app_v21
|
||||
|
||||
[filter:request_id]
|
||||
paste.filter_factory = oslo_middleware:RequestId.factory
|
||||
|
||||
[filter:request_log]
|
||||
paste.filter_factory = nova.api.openstack.requestlog:RequestLog.factory
|
||||
|
||||
[filter:compute_req_id]
|
||||
paste.filter_factory = nova.api.compute_req_id:ComputeReqIdMiddleware.factory
|
||||
|
||||
|
|
@ -64,7 +67,7 @@ paste.filter_factory = nova.api.openstack:LegacyV2CompatibleWrapper.factory
|
|||
paste.app_factory = nova.api.openstack.compute:APIRouterV21.factory
|
||||
|
||||
[pipeline:oscomputeversions]
|
||||
pipeline = cors faultwrap http_proxy_to_wsgi oscomputeversionapp
|
||||
pipeline = cors faultwrap request_log http_proxy_to_wsgi oscomputeversionapp
|
||||
|
||||
[app:oscomputeversionapp]
|
||||
paste.app_factory = nova.api.openstack.compute.versions:Versions.factory
|
||||
|
|
|
|||
|
|
@ -0,0 +1,92 @@
|
|||
# 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.
|
||||
"""Simple middleware for request logging."""
|
||||
|
||||
import time
|
||||
|
||||
from oslo_log import log as logging
|
||||
from oslo_utils import excutils
|
||||
import webob.dec
|
||||
import webob.exc
|
||||
|
||||
from nova.api.openstack import wsgi
|
||||
from nova import wsgi as base_wsgi
|
||||
|
||||
# TODO(sdague) maybe we can use a better name here for the logger
|
||||
LOG = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class RequestLog(base_wsgi.Middleware):
|
||||
"""WSGI Middleware to write a simple request log to.
|
||||
|
||||
Borrowed from Paste Translogger
|
||||
"""
|
||||
|
||||
# This matches the placement fil
|
||||
_log_format = ('%(REMOTE_ADDR)s "%(REQUEST_METHOD)s %(REQUEST_URI)s" '
|
||||
'status: %(status)s len: %(len)s '
|
||||
'microversion: %(microversion)s time: %(time).6f')
|
||||
|
||||
@staticmethod
|
||||
def _get_uri(environ):
|
||||
req_uri = (environ.get('SCRIPT_NAME', '') +
|
||||
environ.get('PATH_INFO', ''))
|
||||
if environ.get('QUERY_STRING'):
|
||||
req_uri += '?' + environ['QUERY_STRING']
|
||||
return req_uri
|
||||
|
||||
@staticmethod
|
||||
def _should_emit(req):
|
||||
"""Conditions under which we should skip logging.
|
||||
|
||||
If we detect we are running under eventlet wsgi processing, we
|
||||
already are logging things, let it go. This is broken out as a
|
||||
separate method so that it can be easily adjusted for testing.
|
||||
"""
|
||||
if req.environ.get('eventlet.input', None) is not None:
|
||||
return False
|
||||
return True
|
||||
|
||||
def _log_req(self, req, res, start):
|
||||
if not self._should_emit(req):
|
||||
return
|
||||
|
||||
# in the event that things exploded really badly deeper in the
|
||||
# wsgi stack, res is going to be an empty dict for the
|
||||
# fallback logging. So never count on it having attributes.
|
||||
status = getattr(res, "status", "500 Error").split(None, 1)[0]
|
||||
data = {
|
||||
'REMOTE_ADDR': req.environ.get('REMOTE_ADDR', '-'),
|
||||
'REQUEST_METHOD': req.environ['REQUEST_METHOD'],
|
||||
'REQUEST_URI': self._get_uri(req.environ),
|
||||
'status': status,
|
||||
'len': getattr(res, "content_length", 0),
|
||||
'time': time.time() - start,
|
||||
'microversion': '-'
|
||||
}
|
||||
# set microversion if it exists
|
||||
if not req.api_version_request.is_null():
|
||||
data["microversion"] = req.api_version_request.get_string()
|
||||
LOG.info(self._log_format, data)
|
||||
|
||||
@webob.dec.wsgify(RequestClass=wsgi.Request)
|
||||
def __call__(self, req):
|
||||
res = {}
|
||||
start = time.time()
|
||||
try:
|
||||
res = req.get_response(self.application)
|
||||
self._log_req(req, res, start)
|
||||
return res
|
||||
except Exception:
|
||||
with excutils.save_and_reraise_exception():
|
||||
self._log_req(req, res, start)
|
||||
|
|
@ -0,0 +1,157 @@
|
|||
# Copyright 2017 IBM Corp.
|
||||
# All Rights Reserved.
|
||||
#
|
||||
# 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 mock
|
||||
|
||||
import fixtures as fx
|
||||
import testtools
|
||||
|
||||
from nova.tests import fixtures
|
||||
from nova.tests.unit import conf_fixture
|
||||
|
||||
"""Test request logging middleware under various conditions.
|
||||
|
||||
The request logging middleware is needed when running under something
|
||||
other than eventlet. While Nova grew up on eventlet, and it's wsgi
|
||||
server, it meant that our user facing data (the log stream) was a mix
|
||||
of what Nova was emitting, and what eventlet.wsgi was emitting on our
|
||||
behalf. When running under uwsgi we want to make sure that we have
|
||||
equivalent coverage.
|
||||
|
||||
All these tests use GET / to hit an endpoint that doesn't require the
|
||||
database setup. We have to do a bit of mocking to make that work.
|
||||
"""
|
||||
|
||||
|
||||
class TestRequestLogMiddleware(testtools.TestCase):
|
||||
|
||||
def setUp(self):
|
||||
super(TestRequestLogMiddleware, self).setUp()
|
||||
# this is the minimal set of magic mocks needed to convince
|
||||
# the API service it can start on it's own without a database.
|
||||
mocks = ['nova.objects.Service.get_by_host_and_binary',
|
||||
'nova.objects.Service.create']
|
||||
for m in mocks:
|
||||
p = mock.patch(m)
|
||||
self.addCleanup(p.stop)
|
||||
p.start()
|
||||
|
||||
@mock.patch('nova.api.openstack.requestlog.RequestLog._should_emit')
|
||||
def test_logs_requests(self, emit):
|
||||
"""Ensure requests are logged.
|
||||
|
||||
Make a standard request for / and ensure there is a log entry.
|
||||
"""
|
||||
|
||||
emit.return_value = True
|
||||
self.useFixture(fixtures.OutputStreamCapture())
|
||||
log = fixtures.StandardLogging()
|
||||
self.useFixture(log)
|
||||
self.useFixture(conf_fixture.ConfFixture())
|
||||
self.useFixture(fixtures.RPCFixture('nova.test'))
|
||||
api = self.useFixture(fixtures.OSAPIFixture()).api
|
||||
|
||||
resp = api.api_request('/', strip_version=True)
|
||||
log1 = ('INFO [nova.api.openstack.requestlog] 127.0.0.1 '
|
||||
'"GET /v2" status: 204 len: 0 microversion: - time:')
|
||||
self.assertIn(log1, log.logger.output)
|
||||
|
||||
# the content length might vary, but the important part is
|
||||
# what we log is what we return to the user (which turns out
|
||||
# to excitingly not be the case with eventlet!)
|
||||
content_length = resp.headers['content-length']
|
||||
|
||||
log2 = ('INFO [nova.api.openstack.requestlog] 127.0.0.1 '
|
||||
'"GET /" status: 200 len: %s' % content_length)
|
||||
self.assertIn(log2, log.logger.output)
|
||||
|
||||
@mock.patch('nova.api.openstack.requestlog.RequestLog._should_emit')
|
||||
def test_logs_mv(self, emit):
|
||||
"""Ensure logs register microversion if passed.
|
||||
|
||||
This makes sure that microversion logging actually shows up
|
||||
when appropriate.
|
||||
"""
|
||||
|
||||
emit.return_value = True
|
||||
self.useFixture(fixtures.OutputStreamCapture())
|
||||
log = fixtures.StandardLogging()
|
||||
self.useFixture(log)
|
||||
self.useFixture(conf_fixture.ConfFixture())
|
||||
# NOTE(sdague): all these tests are using the
|
||||
self.useFixture(
|
||||
fx.MonkeyPatch(
|
||||
'nova.api.openstack.compute.versions.'
|
||||
'Versions.support_api_request_version',
|
||||
True))
|
||||
|
||||
self.useFixture(fixtures.RPCFixture('nova.test'))
|
||||
|
||||
api = self.useFixture(fixtures.OSAPIFixture()).api
|
||||
api.microversion = '2.25'
|
||||
|
||||
resp = api.api_request('/', strip_version=True)
|
||||
content_length = resp.headers['content-length']
|
||||
|
||||
log1 = ('INFO [nova.api.openstack.requestlog] 127.0.0.1 '
|
||||
'"GET /" status: 200 len: %s microversion: 2.25 time:' %
|
||||
content_length)
|
||||
self.assertIn(log1, log.logger.output)
|
||||
|
||||
@mock.patch('nova.api.openstack.compute.versions.Versions.index')
|
||||
@mock.patch('nova.api.openstack.requestlog.RequestLog._should_emit')
|
||||
def test_logs_under_exception(self, emit, v_index):
|
||||
"""Ensure that logs still emit under unexpected failure.
|
||||
|
||||
If we get an unexpected failure all the way up to the top, we should
|
||||
still have a record of that request via the except block.
|
||||
"""
|
||||
|
||||
emit.return_value = True
|
||||
v_index.side_effect = Exception("Unexpected Error")
|
||||
self.useFixture(fixtures.OutputStreamCapture())
|
||||
log = fixtures.StandardLogging()
|
||||
self.useFixture(log)
|
||||
self.useFixture(conf_fixture.ConfFixture())
|
||||
self.useFixture(fixtures.RPCFixture('nova.test'))
|
||||
api = self.useFixture(fixtures.OSAPIFixture()).api
|
||||
|
||||
api.api_request('/', strip_version=True)
|
||||
log1 = ('INFO [nova.api.openstack.requestlog] 127.0.0.1 "GET /"'
|
||||
' status: 500 len: 0 microversion: - time:')
|
||||
self.assertIn(log1, log.logger.output)
|
||||
|
||||
@mock.patch('nova.api.openstack.requestlog.RequestLog._should_emit')
|
||||
def test_no_log_under_eventlet(self, emit):
|
||||
"""Ensure that logs don't end up under eventlet.
|
||||
|
||||
We still set the _should_emit return value directly to prevent
|
||||
the situation where eventlet is removed from tests and this
|
||||
preventing that.
|
||||
|
||||
NOTE(sdague): this test can be deleted when eventlet is no
|
||||
longer supported for the wsgi stack in Nova.
|
||||
"""
|
||||
|
||||
emit.return_value = False
|
||||
self.useFixture(fixtures.OutputStreamCapture())
|
||||
log = fixtures.StandardLogging()
|
||||
self.useFixture(log)
|
||||
self.useFixture(conf_fixture.ConfFixture())
|
||||
self.useFixture(fixtures.RPCFixture('nova.test'))
|
||||
api = self.useFixture(fixtures.OSAPIFixture()).api
|
||||
|
||||
api.api_request('/', strip_version=True)
|
||||
self.assertNotIn("nova.api.openstack.requestlog", log.logger.output)
|
||||
|
|
@ -0,0 +1,11 @@
|
|||
---
|
||||
upgrade:
|
||||
- |
|
||||
A new request_log middleware is created to log REST HTTP requests
|
||||
even if Nova API is not running under eventlet.wsgi. Because this
|
||||
is an api-paste.ini change, you will need to manually update your
|
||||
api-paste.ini with the one from the release to get this
|
||||
functionality. The new request logs will only emit when it is
|
||||
detected that nova-api is not running under eventlet, and will
|
||||
include the microversion of the request in addition to all the
|
||||
previously logged information.
|
||||
Loading…
Reference in New Issue