'log_request() should send timing and byte-count counters for GET
requests.  Also, __call__()\'s iter_response() function should
statsd-log time to first byte (calling the passed-in start_response
function), but only for GET requests.'

def test_log_request_stat_type_good(self):

    stub_times = []
    def stub_time():
        return stub_times.pop(0)
    path_types = {'/v1/a': 'account', '/v1/a/': 'account', '/v1/a/c': 'container', '/v1/a/c/': 'container', '/v1/a/c/o': 'object', '/v1/a/c/o/': 'object', '/v1/a/c/o/p': 'object', '/v1/a/c/o/p/': 'object', '/v1/a/c/o/p/p2': 'object'}
    with mock.patch('time.time', stub_time):
        for (path, exp_type) in path_types.items():
            app = proxy_logging.ProxyLoggingMiddleware(FakeApp(body='7654321', response_str='321    Fubar'), {})
            app.access_logger = FakeLogger()
            req = Request.blank(path, environ={'REQUEST_METHOD': 'GET', 'wsgi.input': BytesIO('4321')})
            stub_times = [18.0, 20.71828182846]
            iter_response = app(req.environ, (lambda *_: None))
            self.assertEqual('7654321', ''.join(iter_response))
            self.assertTiming(('%s.GET.321.timing' % exp_type), app, exp_timing=(2.71828182846 * 1000))
            self.assertTimingSince(('%s.GET.321.first-byte.timing' % exp_type), app, exp_start=18.0)
            if (exp_type == 'object'):
                self.assertTiming(('%s.policy.0.GET.321.timing' % exp_type), app, exp_timing=(2.71828182846 * 1000))
                self.assertUpdateStats([(('%s.GET.321.xfer' % exp_type), (4 + 7)), ('object.policy.0.GET.321.xfer', (4 + 7))], app)
            else:
                self.assertUpdateStats([(('%s.GET.321.xfer' % exp_type), (4 + 7))], app)
            if (exp_type == 'object'):
                app = proxy_logging.ProxyLoggingMiddleware(FakeApp(body='7654321', response_str='321    Fubar', policy_idx='-1'), {})
                app.access_logger = FakeLogger()
                req = Request.blank(path, environ={'REQUEST_METHOD': 'GET', 'wsgi.input': BytesIO('4321')})
                stub_times = [18.0, 20.71828182846]
                iter_response = app(req.environ, (lambda *_: None))
                self.assertEqual('7654321', ''.join(iter_response))
                self.assertTiming(('%s.GET.321.timing' % exp_type), app, exp_timing=(2.71828182846 * 1000))
                self.assertTimingSince(('%s.GET.321.first-byte.timing' % exp_type), app, exp_start=18.0)
                self.assertUpdateStats([(('%s.GET.321.xfer' % exp_type), (4 + 7))], app)
            app = proxy_logging.ProxyLoggingMiddleware(FakeApp(body='7654321', response_str='321    Fubar'), {})
            app.access_logger = FakeLogger()
            req = Request.blank(path, environ={'REQUEST_METHOD': 'GET', 'swift.proxy_access_log_made': True, 'wsgi.input': BytesIO('4321')})
            stub_times = [18.0, 20.71828182846]
            iter_response = app(req.environ, (lambda *_: None))
            self.assertEqual('7654321', ''.join(iter_response))
            self.assertEqual([], app.access_logger.log_dict['timing'])
            self.assertEqual([], app.access_logger.log_dict['timing_since'])
            self.assertEqual([], app.access_logger.log_dict['update_stats'])
            app = proxy_logging.ProxyLoggingMiddleware(FakeApp(body='87654321', response_str='314    PiTown'), {})
            app.access_logger = FakeLogger()
            req = Request.blank(path, environ={'REQUEST_METHOD': 'PUT', 'wsgi.input': BytesIO('654321')})
            stub_times = [58.2, (58.2 + 7.3321)]
            iter_response = app(req.environ, (lambda *_: None))
            self.assertEqual('87654321', ''.join(iter_response))
            self.assertTiming(('%s.PUT.314.timing' % exp_type), app, exp_timing=(7.3321 * 1000))
            self.assertNotTiming(('%s.GET.314.first-byte.timing' % exp_type), app)
            self.assertNotTiming(('%s.PUT.314.first-byte.timing' % exp_type), app)
            if (exp_type == 'object'):
                self.assertTiming(('%s.policy.0.PUT.314.timing' % exp_type), app, exp_timing=(7.3321 * 1000))
                self.assertUpdateStats([('object.PUT.314.xfer', (6 + 8)), ('object.policy.0.PUT.314.xfer', (6 + 8))], app)
            else:
                self.assertUpdateStats([(('%s.PUT.314.xfer' % exp_type), (6 + 8))], app)
            if (exp_type == 'object'):
                app = proxy_logging.ProxyLoggingMiddleware(FakeApp(body='87654321', response_str='314    PiTown', policy_idx='-1'), {})
                app.access_logger = FakeLogger()
                req = Request.blank(path, environ={'REQUEST_METHOD': 'PUT', 'wsgi.input': BytesIO('654321')})
                stub_times = [58.2, (58.2 + 7.3321)]
                iter_response = app(req.environ, (lambda *_: None))
                self.assertEqual('87654321', ''.join(iter_response))
                self.assertTiming(('%s.PUT.314.timing' % exp_type), app, exp_timing=(7.3321 * 1000))
                self.assertNotTiming(('%s.GET.314.first-byte.timing' % exp_type), app)
                self.assertNotTiming(('%s.PUT.314.first-byte.timing' % exp_type), app)
                self.assertUpdateStats([('object.PUT.314.xfer', (6 + 8))], app)
