Repository: amwa-tv/nmos-testing
Issue: IS04-01 test_21: sleep/wait resumes too soon

test_21: "Node correctly interprets a 200 code from a registry upon initial registration"
FAIL -> Node did not attempt to DELETE itself having encountered a 200 code on initial registration

This test is failing on my setup because the test disables the registry as soon as it receives the first POST. The DELETE is properly sent but receives a 500.

I added some logs to investigate the failure:

>  * Running test_21
Tue Jul 23 12:00:27 2019 REGISTRY ENABLED ON PORT 5102
Tue Jul 23 12:00:27 2019 WAITING UP TO 5  SECONDS
10.129.110.210 - - [23/Jul/2019 12:00:28] "POST /x-nmos/registration/v1.2/health/nodes/11111111-2222-4444-9999-444444444444 HTTP/1.1" 404 -
Tue Jul 23 12:00:28 2019 RESUMING
Tue Jul 23 12:00:28 2019 REGISTRY DISABLE ON PORT 5102
10.129.110.210 - - [23/Jul/2019 12:00:28] "POST /x-nmos/registration/v1.2/resource HTTP/1.1" 200 -
10.129.110.210 - - [23/Jul/2019 12:00:28] "DELETE /x-nmos/registration/v1.2/resource/senders/52303352-abe7-4061-a7ca-acd6f5aa15a1 HTTP/1.1" 500 -



It happens here: IS0401Test.py at line 1105
        # Wait for n seconds after advertising the service for the first POST from a Node
        self.primary_registry.wait_for_registration(DNS_SD_ADVERT_TIMEOUT)

Changed files:
IS0401Test.py, Registry.py

diff --git a/IS0401Test.py b/IS0401Test.py
index 30931a6..896a341 100644
--- a/IS0401Test.py
+++ b/IS0401Test.py
@@ -1102,8 +1102,9 @@ class IS0401Test(GenericTest):
             # Advertise a registry at pri 0 and allow the Node to do a basic registration
             self.zc.register_service(registry_info)
 
-        # Wait for n seconds after advertising the service for the first POST from a Node
+        # Wait for n seconds after advertising the service for the first POST and then DELETE from a Node
         self.primary_registry.wait_for_registration(DNS_SD_ADVERT_TIMEOUT)
+        self.primary_registry.wait_for_delete(HEARTBEAT_INTERVAL + 1)
 
         # By this point we should have had at least one Node POST and a corresponding DELETE
         if DNS_SD_MODE == "multicast":
diff --git a/Registry.py b/Registry.py
index b7f78a8..192d327 100644
--- a/Registry.py
+++ b/Registry.py
@@ -40,7 +40,8 @@ class Registry(object):
     def __init__(self, data_store, port_increment):
         self.common = data_store
         self.port = 5100 + port_increment  # cf. test_data/IS0401/dns_records.zone
-        self.event = Event()
+        self.add_event = Event()
+        self.delete_event = Event()
         self.reset()
 
     def reset(self):
@@ -51,11 +52,12 @@ class Registry(object):
         self.enabled = False
         self.test_first_reg = False
         self.test_invalid_reg = False
-        self.event.clear()
+        self.add_event.clear()
+        self.delete_event.clear()
 
     def add(self, headers, payload, version):
         self.last_time = time.time()
-        self.event.set()
+        self.add_event.set()
         self.data.posts.append((self.last_time, {"headers": headers, "payload": payload, "version": version}))
         if "type" in payload and "data" in payload:
             if payload["type"] not in self.common.resources:
@@ -65,7 +67,7 @@ class Registry(object):
 
     def delete(self, headers, payload, version, resource_type, resource_id):
         self.last_time = time.time()
-        self.event.set()
+        self.delete_event.set()
         self.data.deletes.append((self.last_time, {"headers": headers, "payload": payload, "version": version,
                                                    "type": resource_type, "id": resource_id}))
         if resource_type in self.common.resources:
@@ -93,10 +95,13 @@ class Registry(object):
         self.enabled = False
 
     def wait_for_registration(self, timeout):
-        self.event.wait(timeout)
+        self.add_event.wait(timeout)
+
+    def wait_for_delete(self, timeout):
+        self.delete_event.wait(timeout)
 
     def has_registrations(self):
-        return self.event.is_set()
+        return self.add_event.is_set()
 
 
 # 0 = Invalid request testing registry