openstack/swift
Code Issues Proposed changes

Log the correct request type of a subrequest downstream of copy

Browse Source 
Before this change, subrequests made while servicing a copy would
result in logging the request type from the copy PUT/GET request
instead of the type from the subrequest being logged.

In order to have the correct requst type logged for subrequests:
- Changed subrequest environments to not inherit the orig_req_method
  of the enclosing request.
- Changed copy to be more picky about when it sets orig_req_method

In addition, subrequest environments will no longer inherit the
swift.log_info from the enclosing request.  That inheritance had
been added at Ic96a92e938589a2f6add35a40741fd062f1c29eb
along with swift.orig_req_method.

Change-Id: I1ccb2665b6cd2887659e548e55a26aa00de879e3
Closes-Bug: #1657246
This commit is contained in:
Janie Richling 2017-03-11 13:30:35 -06:00
parent 3cabafa326
commit 108501a8c1
4 changed files with 201 additions and 14 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

10
swift/common/middleware/copy.py
View File

@ -321,17 +321,17 @@ class ServerSideCopyMiddleware(object):
self.container_name = container
self.object_name = obj
# Save off original request method (COPY/POST) in case it gets mutated
# into PUT during handling. This way logging can display the method
# the client actually sent.
req.environ['swift.orig_req_method'] = req.method
try:
# In some cases, save off original request method since it gets
# mutated into PUT during handling. This way logging can display
# the method the client actually sent.
if req.method == 'PUT' and req.headers.get('X-Copy-From'):
return self.handle_PUT(req, start_response)
elif req.method == 'COPY':
req.environ['swift.orig_req_method'] = req.method
return self.handle_COPY(req, start_response)
elif req.method == 'POST' and self.object_post_as_copy:
req.environ['swift.orig_req_method'] = req.method
return self.handle_object_post_as_copy(req, start_response)
elif req.method == 'OPTIONS':
# Does not interfere with OPTIONS response from

3
swift/common/wsgi.py
View File

@ -1111,8 +1111,7 @@ def make_env(env, method=None, path=None, agent='Swift', query_string=None,
'SERVER_PROTOCOL', 'swift.cache', 'swift.source',
'swift.trans_id', 'swift.authorize_override',
'swift.authorize', 'HTTP_X_USER_ID', 'HTTP_X_PROJECT_ID',
'HTTP_REFERER', 'swift.orig_req_method', 'swift.log_info',
'swift.infocache'):
'HTTP_REFERER', 'swift.infocache'):
if name in env:
newenv[name] = env[name]
if method:

24
test/unit/common/middleware/test_copy.py
View File

@ -150,13 +150,15 @@ class TestServerSideCopyMiddleware(unittest.TestCase):
self.assertEqual(len(self.authorized), 1)
self.assertRequestEqual(req, self.authorized[0])
def test_object_delete_pass_through(self):
self.app.register('DELETE', '/v1/a/c/o', swob.HTTPOk, {})
req = Request.blank('/v1/a/c/o', method='DELETE')
status, headers, body = self.call_ssc(req)
self.assertEqual(status, '200 OK')
self.assertEqual(len(self.authorized), 1)
self.assertRequestEqual(req, self.authorized[0])
def test_object_pass_through_methods(self):
for method in ['DELETE', 'GET', 'HEAD', 'REPLICATE']:
self.app.register(method, '/v1/a/c/o', swob.HTTPOk, {})
req = Request.blank('/v1/a/c/o', method=method)
status, headers, body = self.call_ssc(req)
self.assertEqual(status, '200 OK')
self.assertEqual(len(self.authorized), 1)
self.assertRequestEqual(req, self.authorized[0])
self.assertNotIn('swift.orig_req_method', req.environ)
def test_POST_as_COPY_simple(self):
self.app.register('GET', '/v1/a/c/o', swob.HTTPOk, {}, 'passed')
@ -166,6 +168,8 @@ class TestServerSideCopyMiddleware(unittest.TestCase):
self.assertEqual(status, '202 Accepted')
self.assertEqual(len(self.authorized), 1)
self.assertRequestEqual(req, self.authorized[0])
# For basic test cases, assert orig_req_method behavior
self.assertEqual(req.environ['swift.orig_req_method'], 'POST')
def test_POST_as_COPY_201_return_202(self):
self.app.register('GET', '/v1/a/c/o', swob.HTTPOk, {}, 'passed')
@ -258,6 +262,8 @@ class TestServerSideCopyMiddleware(unittest.TestCase):
self.assertEqual('/v1/a/c/o2', self.authorized[1].path)
self.assertEqual(self.app.swift_sources[0], 'SSC')
self.assertEqual(self.app.swift_sources[1], 'SSC')
# For basic test cases, assert orig_req_method behavior
self.assertNotIn('swift.orig_req_method', req.environ)
def test_static_large_object_manifest(self):
self.app.register('GET', '/v1/a/c/o', swob.HTTPOk,
@ -663,6 +669,8 @@ class TestServerSideCopyMiddleware(unittest.TestCase):
('PUT', '/v1/a/c/o-copy')])
self.assertIn('etag', self.app.headers[1])
self.assertEqual(self.app.headers[1]['etag'], 'is sent')
# For basic test cases, assert orig_req_method behavior
self.assertEqual(req.environ['swift.orig_req_method'], 'COPY')
def test_basic_DLO(self):
self.app.register('GET', '/v1/a/c/o', swob.HTTPOk, {
@ -1191,6 +1199,8 @@ class TestServerSideCopyMiddleware(unittest.TestCase):
self.assertEqual(len(self.authorized), 1)
self.assertEqual('OPTIONS', self.authorized[0].method)
self.assertEqual('/v1/a/c/o', self.authorized[0].path)
# For basic test cases, assert orig_req_method behavior
self.assertNotIn('swift.orig_req_method', req.environ)
def test_COPY_in_OPTIONS_response_CORS(self):
self.app.register('OPTIONS', '/v1/a/c/o', swob.HTTPOk,

178
test/unit/common/middleware/test_subrequest_logging.py Normal file
View File

@ -0,0 +1,178 @@
# Copyright (c) 2016-2017 OpenStack Foundation
#
# 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 unittest
from swift.common.middleware import copy, proxy_logging
from swift.common.swob import Request, HTTPOk
from swift.common.utils import close_if_possible
from swift.common.wsgi import make_subrequest
from test.unit import FakeLogger
from test.unit.common.middleware.helpers import FakeSwift
SUB_GET_PATH = '/v1/a/c/sub_get'
SUB_PUT_POST_PATH = '/v1/a/c/sub_put'
class FakeFilter(object):
def __init__(self, app, conf, register):
self.body = ['FAKE MIDDLEWARE']
self.conf = conf
self.app = app
self.register = register
self.logger = None
def __call__(self, env, start_response):
path = SUB_PUT_POST_PATH
if env['REQUEST_METHOD'] is 'GET':
path = SUB_GET_PATH
# Make a subrequest that will be logged
hdrs = {'content-type': 'text/plain'}
sub_req = make_subrequest(env, path=path,
method=self.conf['subrequest_type'],
headers=hdrs,
agent='FakeApp',
swift_source='FA')
self.register(self.conf['subrequest_type'],
path, HTTPOk, headers=hdrs)
resp = sub_req.get_response(self.app)
close_if_possible(resp.app_iter)
def _start_response(status, headers, exc_info=None):
return start_response(status, headers, exc_info)
return self.app(env, start_response)
class FakeApp(object):
def __init__(self, conf):
self.fake_logger = FakeLogger()
self.fake_swift = self.app = FakeSwift()
self.register = self.fake_swift.register
for filter in reversed([
proxy_logging.filter_factory,
copy.filter_factory,
lambda conf: lambda app: FakeFilter(app, conf, self.register),
proxy_logging.filter_factory]):
self.app = filter(conf)(self.app)
self.app.logger = self.fake_logger
if hasattr(self.app, 'access_logger'):
self.app.access_logger = self.fake_logger
if conf['subrequest_type'] == 'GET':
self.register(conf['subrequest_type'], SUB_GET_PATH, HTTPOk, {})
else:
self.register(conf['subrequest_type'],
SUB_PUT_POST_PATH, HTTPOk, {})
@property
def __call__(self):
return self.app.__call__
class TestSubRequestLogging(unittest.TestCase):
path = '/v1/a/c/o'
def _test_subrequest_logged(self, subrequest_type):
# Test that subrequests made downstream from Copy PUT will be logged
# with the request type of the subrequest as opposed to the GET/PUT.
app = FakeApp({'subrequest_type': subrequest_type})
hdrs = {'content-type': 'text/plain', 'X-Copy-From': 'test/obj'}
req = Request.blank(self.path, method='PUT', headers=hdrs)
app.register('PUT', self.path, HTTPOk, headers=hdrs)
app.register('GET', '/v1/a/test/obj', HTTPOk, headers=hdrs)
req.get_response(app)
info_log_lines = app.fake_logger.get_lines_for_level('info')
self.assertEqual(len(info_log_lines), 5)
self.assertTrue(info_log_lines[0].startswith('Copying object'))
subreq_get = '%s %s' % (subrequest_type, SUB_GET_PATH)
subreq_put = '%s %s' % (subrequest_type, SUB_PUT_POST_PATH)
origput = 'PUT %s' % self.path
copyget = 'GET %s' % '/v1/a/test/obj'
# expect GET subreq, copy GET, PUT subreq, orig PUT
self.assertTrue(subreq_get in info_log_lines[1])
self.assertTrue(copyget in info_log_lines[2])
self.assertTrue(subreq_put in info_log_lines[3])
self.assertTrue(origput in info_log_lines[4])
def test_subrequest_logged_x_copy_from(self):
self._test_subrequest_logged('HEAD')
self._test_subrequest_logged('GET')
self._test_subrequest_logged('POST')
self._test_subrequest_logged('PUT')
self._test_subrequest_logged('DELETE')
def _test_subrequest_logged_POST(self, subrequest_type,
post_as_copy=False):
# Test that subrequests made downstream from Copy POST will be logged
# with the request type of the subrequest as opposed to the GET/PUT.
app = FakeApp({'subrequest_type': subrequest_type,
'object_post_as_copy': post_as_copy})
hdrs = {'content-type': 'text/plain'}
req = Request.blank(self.path, method='POST', headers=hdrs)
app.register('POST', self.path, HTTPOk, headers=hdrs)
expect_lines = 2
if post_as_copy:
app.register('PUT', self.path, HTTPOk, headers=hdrs)
app.register('GET', '/v1/a/c/o', HTTPOk, headers=hdrs)
expect_lines = 4
req.get_response(app)
info_log_lines = app.fake_logger.get_lines_for_level('info')
self.assertEqual(len(info_log_lines), expect_lines)
self.assertTrue('Copying object' not in info_log_lines[0])
subreq_put_post = '%s %s' % (subrequest_type, SUB_PUT_POST_PATH)
origpost = 'POST %s' % self.path
copyget = 'GET %s' % self.path
if post_as_copy:
# post_as_copy expect GET subreq, copy GET, PUT subreq, orig POST
subreq_get = '%s %s' % (subrequest_type, SUB_GET_PATH)
self.assertTrue(subreq_get in info_log_lines[0])
self.assertTrue(copyget in info_log_lines[1])
self.assertTrue(subreq_put_post in info_log_lines[2])
self.assertTrue(origpost in info_log_lines[3])
else:
# fast post expect POST subreq, original POST
self.assertTrue(subreq_put_post in info_log_lines[0])
self.assertTrue(origpost in info_log_lines[1])
def test_subrequest_logged_post_as_copy_with_POST_fast_post(self):
self._test_subrequest_logged_POST('HEAD', post_as_copy=False)
self._test_subrequest_logged_POST('GET', post_as_copy=False)
self._test_subrequest_logged_POST('POST', post_as_copy=False)
self._test_subrequest_logged_POST('PUT', post_as_copy=False)
self._test_subrequest_logged_POST('DELETE', post_as_copy=False)
def test_subrequest_logged_post_as_copy_with_POST(self):
self._test_subrequest_logged_POST('HEAD', post_as_copy=True)
self._test_subrequest_logged_POST('GET', post_as_copy=True)
self._test_subrequest_logged_POST('POST', post_as_copy=True)
self._test_subrequest_logged_POST('PUT', post_as_copy=True)
self._test_subrequest_logged_POST('DELETE', post_as_copy=True)
if __name__ == '__main__':
unittest.main()