TestConcurrentGets tweaks

gistfile1.txt

diff --git a/test/unit/proxy/controllers/test_base.py b/test/unit/proxy/controllers/test_base.py
index 285909e..25742fd 100644
--- a/test/unit/proxy/controllers/test_base.py
+++ b/test/unit/proxy/controllers/test_base.py
@@ -911,6 +911,7 @@ class TestConcurrentGets(unittest.TestCase):
         self._now = time.time()
         self.tickets = []
         self.finished_tickets = []
+        self.unused_tickets = 0
 
     def test_attribute_setup(self):
         self.assertEqual(self.app.concurrent_gets, True)
@@ -938,7 +939,8 @@ class TestConcurrentGets(unittest.TestCase):
                 not_ready_tickets.append(ticket)
         self.finished_tickets.extend(ready_tickets)
         self.tickets = not_ready_tickets
-        print ready_tickets
+        if ready_tickets:
+            print "ready tickets %s" % ready_tickets
         return ready_tickets
 
     @contextmanager
@@ -948,12 +950,14 @@ class TestConcurrentGets(unittest.TestCase):
 
             test_case = self
 
-            def __init__(self, ip, *args, **kargs):
+            def __init__(self, ip, stats, *args, **kargs):
                 self.ip = ip
                 self.args = args
                 self.kargs = kargs
 
             def getresponse(self):
+                print('getresponse() for %s -->' % self.ip)
+
                 def mygetheader(header, *args, **kargs):
                     if header == "Content-Type":
                         return ""
@@ -966,10 +970,15 @@ class TestConcurrentGets(unittest.TestCase):
                 resp.getheaders.return_value = {}
                 resp.reason = ''
                 resp.status = self.test_case.statuses[self.ip]
+                stats = [self.ip, resp.status, self.test_case._now]
+                self.test_case.connections.append(stats)
                 self.test_case.sleepish(self.test_case.timings[self.ip],
                                         ip=self.ip,
                                         args=self.args,
                                         kargs=self.kargs)
+
+                stats.append(self.test_case._now)
+                print('getresponse() for %s <-- %s' % (self.ip, resp.status))
                 return resp
 
         class MockedGreenAsyncPile(GreenAsyncPile):
@@ -981,8 +990,10 @@ class TestConcurrentGets(unittest.TestCase):
                 time_to_quit = self.test_case._now + timeout
                 while self.test_case._now < time_to_quit:
                     sleep(0)
-                    if self.test_case.any_ready_tickets():
+                    self.test_case.unused_tickets += len(self.test_case.any_ready_tickets())
+                    if self.test_case.unused_tickets:
                         print('DROPPING')
+                        self.test_case.unused_tickets -= 1
                         return super(MockedGreenAsyncPile, self)._wait(
                             0.01, first_n=first_n)
                     self.test_case._now += 0.1
@@ -992,10 +1003,9 @@ class TestConcurrentGets(unittest.TestCase):
             def __iter__(self):
                 def mocked_gen():
                     while True:
-                        for r in super(MockedGreenAsyncPile, self)._wait(
-                                0.01, first_n=1):
+                        print 'NEXT'
+                        for r in self._wait(100, first_n=1):
                             yield r
-                        self.test_case._now += 0.1
                         if self._pending <= 0:
                             break
                 return mocked_gen()
@@ -1004,13 +1014,14 @@ class TestConcurrentGets(unittest.TestCase):
             conn = FakeConn(ip, *args, **kargs)
             return conn
 
+        self.connections = []
         with patch('swift.common.bufferedhttp.http_connect_raw',
                    myfake_http_connect_raw), \
                 patch('swift.proxy.controllers.base.GreenAsyncPile',
                       MockedGreenAsyncPile):
             yield
 
-    def test_fasted_node(self):
+    def test_fastest_node(self):
         self.timings = {'10.0.0.0': 2, '10.0.0.1': 1, '10.0.0.2': 0}
         self.statuses = {'10.0.0.0': 200, '10.0.0.1': 200, '10.0.0.2': 200}
         req = Request.blank(self.req_path)
@@ -1022,6 +1033,7 @@ class TestConcurrentGets(unittest.TestCase):
             # Should get 10.0.0.2 as this has a wait of 0 seconds.
             self.assertEqual(resp.body, 'Response from 10.0.0.2')
             self.assertAlmostEqual(handle_time, 0, delta=0.2)
+            self.assertEqual(3, len(self.connections))
 
     def test_fastest_node_errors(self):
         # 10.0.0.0 with 0 timing but returns an error.
@@ -1034,8 +1046,10 @@ class TestConcurrentGets(unittest.TestCase):
             start = self._now
             resp = self.app.handle_request(req)
             handle_time = self._now - start
+            self._print_connections()
             self.assertEqual(resp.body, 'Response from 10.0.0.2')
             self.assertAlmostEqual(handle_time, 0, delta=0.2)
+            self.assertEqual(3, len(self.connections))
 
     def test_fastest_node_errors_starts_new_req_quickly(self):
         # 10.0.0.0 with 0 timing but returns an error.
@@ -1053,24 +1067,45 @@ class TestConcurrentGets(unittest.TestCase):
             # Should get 10.0.0.1 as this has a wait of 1 seconds.
             self.assertEqual(resp.body, 'Response from 10.0.0.1')
             self.assertAlmostEqual(handle_time, 1, delta=0.2)
+            self.assertEqual(2, len(self.connections))
 
     def test_slow_error_node_has_one_in_waiting(self):
         # 10.0.0.0 with 0 timing but returns an error.
-        self.timings = {'10.0.0.0': 1, '10.0.0.1': 1, '10.0.0.2': 1}
+        self.timings = {'10.0.0.0': 1.1, '10.0.0.1': 1, '10.0.0.2': 1}
         self.statuses = {'10.0.0.0': 500, '10.0.0.1': 200, '10.0.0.2': 200}
         req = Request.blank(self.req_path)
 
         # With concurrency_timeout 0.5 we won't start the second request right
         # away, but we will start it before the first error is returned
-        self.app.concurrency_timeout = 0.5
+        self.app.concurrency_timeout = 1.0
         with self.mocked_http_connect():
             start = self._now
             resp = self.app.handle_request(req)
             handle_time = self._now - start
 
+            self._print_connections()
+            self.assertEqual('200 OK', resp.status)
             # Should get 10.0.0.1 as this has a wait of 1 seconds.
             self.assertEqual(resp.body, 'Response from 10.0.0.1')
-            self.assertAlmostEqual(handle_time, 1.5, delta=0.2)
+            self.assertAlmostEqual(handle_time, 2.0, delta=0.2)
+            self.assertEqual(3, len(self.connections))
+
+    def _print_connections(self):
+        scale = 20
+        t0 = None
+        for conn in self.connections:
+            ip, status, start = conn[:3]
+            if not t0:
+                t0 = start
+            t_start = start - t0
+            if len(conn) == 4:
+                t_stop = conn[3] - t0
+                print('%s %s %4.2f %4.2f %s<%s>' %
+                      (ip, status, t_start, t_stop, ' ' * int(scale * t_start),
+                       '-' * int(scale * (t_stop - t_start))))
+            else:
+                print('%s %s %4.2f ???? %s<- ????' %
+                      (ip, status, t_start, ' ' * int(scale * t_start)))
 
 
 class TestContainerConcurrentGets(TestConcurrentGets):