From eb1910c3d005ac0819416983262812b71edd85f3 Mon Sep 17 00:00:00 2001
From: Tom Clegg <tclegg@veritasgenetics.com>
Date: Tue, 23 Jul 2019 14:02:21 -0400
Subject: [PATCH] 12020: Fix unreliable test.

test_subscribe_poll was failing occasionally due to a race (inserting
time.sleep(1) at the top of PollClient.run made the test fail
consistently).

The test now waits for PollClient to establish its _skip_old_events
filter, and then proceeds to create the event which PollClient is
expected to return.

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <tclegg@veritasgenetics.com>
---
 sdk/python/arvados/events.py    | 23 ++++++++++++-----------
 sdk/python/tests/test_events.py |  8 ++++++++
 2 files changed, 20 insertions(+), 11 deletions(-)

diff --git a/sdk/python/arvados/events.py b/sdk/python/arvados/events.py
index c308750f43..22364d2ae5 100644
--- a/sdk/python/arvados/events.py
+++ b/sdk/python/arvados/events.py
@@ -163,16 +163,17 @@ class PollClient(threading.Thread):
         self._closing = threading.Event()
         self._closing_lock = threading.RLock()
 
-    def run(self):
         if self.last_log_id != None:
             # Caller supplied the last-seen event ID from a previous
-            # connection
-            skip_old_events = [["id", ">", str(self.last_log_id)]]
+            # connection.
+            self._skip_old_events = [["id", ">", str(self.last_log_id)]]
         else:
             # We need to do a reverse-order query to find the most
-            # recent event ID (see "if not skip_old_events" below).
-            skip_old_events = False
+            # recent event ID (see "if not self._skip_old_events"
+            # in run()).
+            self._skip_old_events = False
 
+    def run(self):
         self.on_event({'status': 200})
 
         while not self._closing.is_set():
@@ -180,7 +181,7 @@ class PollClient(threading.Thread):
             for f in self.filters:
                 for tries_left in RetryLoop(num_retries=25, backoff_start=.1, max_wait=self.poll_time):
                     try:
-                        if not skip_old_events:
+                        if not self._skip_old_events:
                             # If the caller didn't provide a known
                             # recent ID, our first request will ask
                             # for the single most recent event from
@@ -198,7 +199,7 @@ class PollClient(threading.Thread):
                             # filter on that same cutoff time, or
                             # (once we see our first matching event)
                             # the ID of the last-seen event.
-                            skip_old_events = [[
+                            self._skip_old_events = [[
                                 "created_at", ">=",
                                 time.strftime(
                                     "%Y-%m-%dT%H:%M:%SZ",
@@ -206,9 +207,9 @@ class PollClient(threading.Thread):
                             items = self.api.logs().list(
                                 order="id desc",
                                 limit=1,
-                                filters=f+skip_old_events).execute()
+                                filters=f+self._skip_old_events).execute()
                             if items["items"]:
-                                skip_old_events = [
+                                self._skip_old_events = [
                                     ["id", ">", str(items["items"][0]["id"])]]
                                 items = {
                                     "items": [],
@@ -223,7 +224,7 @@ class PollClient(threading.Thread):
                             # order.
                             items = self.api.logs().list(
                                 order="id asc",
-                                filters=f+skip_old_events).execute()
+                                filters=f+self._skip_old_events).execute()
                         break
                     except errors.ApiError as error:
                         pass
@@ -237,7 +238,7 @@ class PollClient(threading.Thread):
                     _thread.interrupt_main()
                     return
                 for i in items["items"]:
-                    skip_old_events = [["id", ">", str(i["id"])]]
+                    self._skip_old_events = [["id", ">", str(i["id"])]]
                     with self._closing_lock:
                         if self._closing.is_set():
                             return
diff --git a/sdk/python/tests/test_events.py b/sdk/python/tests/test_events.py
index 35614346d5..f5192160f3 100644
--- a/sdk/python/tests/test_events.py
+++ b/sdk/python/tests/test_events.py
@@ -63,6 +63,14 @@ class WebsocketTest(run_test_server.TestCaseWithServers):
             last_log_id=(1 if start_time else None))
         self.assertIsInstance(self.ws, expect_type)
         self.assertEqual(200, events.get(True, 5)['status'])
+
+        if hasattr(self.ws, '_skip_old_events'):
+            # Avoid race by waiting for the first "find ID threshold"
+            # poll to finish.
+            deadline = time.time() + 10
+            while not self.ws._skip_old_events:
+                self.assertLess(time.time(), deadline)
+                time.sleep(0.1)
         human = arvados.api('v1').humans().create(body={}).execute()
 
         want_uuids = []
-- 
2.30.2