Repository: keylime/keylime
Issue: Adding same node twice creates perpetual loop

# Environment
 * OS / version: Fedora 29
 * Processor architecture: x86_64
 * TPM Manufacturer:  emulator
 * Keylime version: master

# Description 

Add a node twice creates a perpetual loop

## Expected behavior vs. actual behavior 

Keylime_verifier and keylime_tenant should report this only once, and then break / exit the loop.

## Steps to reproduce problem

Run the following command:

`keylime_tenant -v 127.0.0.1 -t 127.0.0.1 -f somefile --uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000`

Run the same again:

`keylime_tenant -v 127.0.0.1 -t 127.0.0.1 -f somefile --uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000`

Result

```
2019-03-08 13:34:45.752 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.761 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.771 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.780 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.789 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.799 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.808 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.818 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.827 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.837 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.846 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.856 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.865 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.875 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
2019-03-08 13:34:45.884 - keylime.cloudverifier - INFO - DELETE returning 200 response for instance id: D432FBB3-D2F1-4A97-9EF7-75BD81C00000
2019-03-08 13:34:45.894 - keylime.cloudverifier - WARNING - Node of uuid D432FBB3-D2F1-4A97-9EF7-75BD81C00000 already exists
```

```
2019-03-08 13:34:44.995 - keylime.tenant - WARNING - Node already existed at CV.  Deleting and re-adding...
2019-03-08 13:34:45.004 - keylime.tenant - INFO - Node D432FBB3-D2F1-4A97-9EF7-75BD81C00000 deleted from CV
2019-03-08 13:34:45.004 - keylime.tenant - DEBUG - b64_v:bsoXgk2ceWMVn42XlXiLhOPtzCRAMQ1fbVwCwCyqQcs=
2019-03-08 13:34:45.013 - keylime.tenant - WARNING - Node already existed at CV.  Deleting and re-adding...
2019-03-08 13:34:45.023 - keylime.tenant - INFO - Node D432FBB3-D2F1-4A97-9EF7-75BD81C00000 deleted from CV
2019-03-08 13:34:45.023 - keylime.tenant - DEBUG - b64_v:bsoXgk2ceWMVn42XlXiLhOPtzCRAMQ1fbVwCwCyqQcs=
2019-03-08 13:34:45.032 - keylime.tenant - WARNING - Node already existed at CV.  Deleting and re-adding...
2019-03-08 13:34:45.042 - keylime.tenant - INFO - Node D432FBB3-D2F1-4A97-9EF7-75BD81C00000 deleted from CV
2019-03-08 13:34:45.042 - keylime.tenant - DEBUG - b64_v:bsoXgk2ceWMVn42XlXiLhOPtzCRAMQ1fbVwCwCyqQcs=
2019-03-08 13:34:45.052 - keylime.tenant - WARNING - Node already existed at CV.  Deleting and re-adding...
2019-03-08 13:34:45.061 - keylime.tenant - INFO - Node D432FBB3-D2F1-4A97-9EF7-75BD81C00000 deleted from CV
2019-03-08 13:34:45.061 - keylime.tenant - DEBUG - b64_v:bsoXgk2ceWMVn42XlXiLhOPtzCRAMQ1fbVwCwCyqQcs=
2019-03-08 13:34:45.070 - keylime.tenant - WARNING - Node already existed at CV.  Deleting and re-adding...
2019-03-08 13:34:45.080 - keylime.tenant - INFO - Node D432FBB3-D2F1-4A97-9EF7-75BD81C00000 deleted from CV
2019-03-08 13:34:45.080 - keylime.tenant - DEBUG - b64_v:bsoXgk2ceWMVn42XlXiLhOPtzCRAMQ1fbVwCwCyqQcs=
```

The above are repeatably logged until the terminal session is `<ctrl-c>`


Changed files:
test/test_restful.py, keylime/cloud_verifier_tornado.py, keylime/tenant.py

diff --git a/keylime/cloud_verifier_tornado.py b/keylime/cloud_verifier_tornado.py
index c1cbed7..de75e9c 100644
--- a/keylime/cloud_verifier_tornado.py
+++ b/keylime/cloud_verifier_tornado.py
@@ -152,11 +152,12 @@ class InstancesHandler(BaseHandler):
         op_state == cloud_verifier_common.CloudInstance_Operational_State.FAILED or \\
         op_state == cloud_verifier_common.CloudInstance_Operational_State.INVALID_QUOTE:
             self.db.remove_instance(instance_id)
+            common.echo_json_response(self, 200, "Success")
+            logger.info('DELETE returning 200 response for instance id: ' + instance_id)
         else:            
             self.db.update_instance(instance_id, 'operational_state',cloud_verifier_common.CloudInstance_Operational_State.TERMINATED)
-
-        common.echo_json_response(self, 200, "Success")
-        logger.info('DELETE returning 200 response for instance id: ' + instance_id)
+            common.echo_json_response(self, 202, "Accepted")
+            logger.info('DELETE returning 202 response for instance id: ' + instance_id)
 
     @tornado.web.asynchronous                   
     def post(self):
diff --git a/keylime/tenant.py b/keylime/tenant.py
index 75aa0c5..064a2af 100755
--- a/keylime/tenant.py
+++ b/keylime/tenant.py
@@ -477,10 +477,8 @@ class Tenant():
         json_message = json.dumps(data)
         response = tornado_requests.request("POST","http://%s:%s/instances/%s"%(self.cloudverifier_ip,self.cloudverifier_port,self.node_uuid),data=json_message,context=self.context)
         if response.status_code == 409:
-            # this is a conflict, delete first then re-add
-            logger.warning("Node already existed at CV.  Deleting and re-adding...")
-            self.do_cvdelete()
-            self.do_cv()
+            # this is a conflict, need to update or delete it
+            raise Exception("Node %s already existed at CV.  Please use delete or update."%self.node_uuid)
         elif response.status_code != 200:
             common.log_http_response(logger,logging.ERROR,response.json())
             raise Exception("POST command response: %d Unexpected response from Cloud Verifier: %s"%(response.status_code,response.body))
@@ -502,11 +500,23 @@ class Tenant():
 
     def do_cvdelete(self):        
         response = tornado_requests.request("DELETE","http://%s:%s/instances/%s"%(self.cloudverifier_ip,self.cloudverifier_port,self.node_uuid),context=self.context)
-        if response.status_code != 200:
-            logger.error("Delete command response: %d Unexpected response from Cloud Verifier."%response.status_code)
-            common.log_http_response(logger,logging.ERROR,response.json())
+        if response.status_code == 202:
+            deleted = False
+            for _ in range(12):
+                response = tornado_requests.request("GET", "http://%s:%s/instances/%s"%(self.cloudverifier_ip,self.cloudverifier_port,self.node_uuid),context=self.context)
+                if response.status_code == 404:
+                    deleted=True
+                    break
+                time.sleep(.4)
+            if deleted:
+                logger.info("CV completed deletion of node %s"%(self.node_uuid))
+            else:
+                logger.error("Timed out waiting for delete of node %s to complete at CV"%self.node_uuid)
+        elif response.status_code == 200:
+            logger.info("Node %s deleted from the CV"%(self.node_uuid))
         else:
-            logger.info("Node %s deleted from CV"%(self.node_uuid))
+            #logger.error("Delete command response: %d Unexpected response from Cloud Verifier."%response.status_code)
+            common.log_http_response(logger,logging.ERROR,response.json())
 
     def do_regdelete(self):
         registrar_client.init_client_tls(config,'tenant')
@@ -670,7 +680,7 @@ class Tenant():
 
 def main(argv=sys.argv):    
     parser = argparse.ArgumentParser(argv[0])
-    parser.add_argument('-c', '--command',action='store',dest='command',default='add',help="valid commands are add,delete,status,reactivate,regdelete. defaults to add")
+    parser.add_argument('-c', '--command',action='store',dest='command',default='add',help="valid commands are add,delete,update,status,reactivate,regdelete. defaults to add")
     parser.add_argument('-t', '--targethost',action='store',dest='node_ip',help="the IP address of the host to provision")
     parser.add_argument('--cv_targethost',action='store',default=None,dest='cv_node_ip',help='the IP address of the host to provision that the verifier will use (optional).  Use only if different than argument to option -t/--targethost')
     parser.add_argument('-v', '--cv',action='store',dest='verifier_ip',help="the IP address of the cloud verifier")
@@ -742,10 +752,19 @@ def main(argv=sys.argv):
                 time.sleep(1)
                 #invalidate it eventually
                 logger.debug("invalidating PCR 15, forcing revocation")
+                tpm = tpm_obj.getTPM(need_hw_tpm=True)
                 tpm.extendPCR(15, tpm.hashdigest("garbage"))
                 time.sleep(5)
                 logger.debug("Deleting node from verifier")
                 mytenant.do_cvdelete()
+        elif args.command=='update':
+            mytenant.init_add(vars(args))
+            mytenant.do_cvdelete()
+            mytenant.preloop()
+            mytenant.do_cv()
+            mytenant.do_quote()
+            if args.verify:
+                mytenant.do_verify()
         elif args.command=='delete':
             mytenant.do_cvdelete()
         elif args.command=='status':
@@ -760,7 +779,7 @@ def main(argv=sys.argv):
             logger.error("Invalid command specified %s"%(args.command))
             sys.exit(2)
     except Exception as e:
-        logger.error(traceback.print_exc())
+        logger.debug(traceback.print_exc())
         logger.error("Error: %s "%str(e))
     
 if __name__=="__main__":
diff --git a/test/test_restful.py b/test/test_restful.py
index 15e77fb..a2b5a79 100644
--- a/test/test_restful.py
+++ b/test/test_restful.py
@@ -793,7 +793,7 @@ class TestRestful(unittest.TestCase):
                                             "http://%s:%s/v%s/instances/%s"%(tenant_templ.cloudverifier_ip,tenant_templ.cloudverifier_port,self.api_version,tenant_templ.node_uuid),
                                             context=tenant_templ.context
                                         )
-        self.assertEqual(response.status_code, 200, "Non-successful CV Instance Delete return code!")
+        self.assertEqual(response.status_code, 202, "Non-successful CV Instance Delete return code!")
         response_body = response.json()
 
         # Ensure response is well-formed