down with stack traces and more consistent handling of exceptions

demo/node_monitor/tenant_node_monitor.py

@@ -152,7 +152,7 @@ def initthread():
         except Exception as e:
             common.echo_json_response(self, 400, "Exception error: %s"%e)
             logger.warning("POST returning 400 response. Exception error: %s"%e)
-            logger.warning(traceback.format_exc())
+            logger.exception(e)
 
     def put(self):
         """This method handles the PUT requests to add instances to the Node Monitor. 

keylime/cloud_verifier_tornado.py

@@ -221,7 +221,7 @@ def post(self):
         except Exception as e:
             common.echo_json_response(self, 400, "Exception error: %s"%e)
             logger.warning("POST returning 400 response. Exception error: %s"%e)
-            logger.warning(traceback.format_exc())
+            logger.exception(e)
 
         self.finish()
 
@@ -272,7 +272,7 @@ def put(self):
         except Exception as e:
             common.echo_json_response(self, 400, "Exception error: %s"%e)
             logger.warning("PUT returning 400 response. Exception error: %s"%e)
-            logger.warning(traceback.format_exc())
+            logger.exception(e)
 
 
         self.finish()
@@ -332,8 +332,7 @@ def on_get_quote_response(self, instance, url, response):
 #                     self.get_q_log_file.flush()  
 
             except Exception as e:
-                logger.debug(traceback.print_exc())
-                logger.critical("Unexpected exception occurred in worker_get_quote.  Error: %s"%e )            
+                logger.exception(e)            
 
 
 
@@ -364,8 +363,6 @@ def on_provide_v_response(self, instance, url_with_params, response):
     def process_instance(self, instance, new_operational_state):
         try:
             if instance is None:
-                #import traceback
-                traceback.print_stack()
             main_instance_operational_state = instance['operational_state']
             stored_instance = self.db.get_instance(instance['instance_id'])
 
@@ -462,8 +459,8 @@ def process_instance(self, instance, new_operational_state):
             raise Exception("nothing should ever fall out of this!")
 
         except Exception as e:
-            logger.warning("Polling thread Exception error: %s"%e)
-            logger.warning("Polling thread trace: " + traceback.format_exc())        
+            logger.error("Polling thread error: %s"%e)
+            logger.exception(e)      
 
 def start_tornado(tornado_server, port):
     tornado_server.listen(port)

keylime/openstack.py

@@ -21,7 +21,6 @@
 import common
 import uuid
 import tornado_requests
-import traceback
 
 logger = common.init_logging('openstack')
 
@@ -37,6 +36,5 @@ def get_openstack_uuid(uuid_service_ip='169.254.169.254',
         logger.debug("Forcing using locally generated uuid.")
         return str(uuid.uuid4())
     except Exception:
-        logger.debug(traceback.format_exc())
-        logger.debug("Exception: Using locally generated uuid.")
+        logger.debug("Using locally generated uuid.  Error getting UUID from openstack: %s\n"%(e))
         return str(uuid.uuid4())

keylime/registrar_client.py

@@ -20,7 +20,6 @@
 
 import json
 import tornado_requests
-import traceback
 import crypto
 import base64
 import common
@@ -119,8 +118,7 @@ def getKeys(registrar_ip,registrar_port,instance_id):
 
         return response_body["results"]
     except Exception as e:
-        logger.critical(traceback.format_exc())
-        logger.critical("An unexpected error occurred: " + str(e))
+        logger.exception(e)
 
     return None
 

keylime/registrar_common.py

@@ -29,7 +29,6 @@
 from urlparse import urlparse
 import json
 import threading
-import traceback
 import sys
 import crypto
 import base64
@@ -254,7 +253,7 @@ def do_POST(self):
         except Exception as e:
             common.echo_json_response(self, 400, "Error: %s"%e)
             logger.warning("POST for " + instance_id + " returning 400 response. Error: %s"%e)
-            logger.warning(traceback.format_exc())
+            logger.exception(e)
             return
 
 
@@ -344,7 +343,7 @@ def do_PUT(self):
         except Exception as e:
             common.echo_json_response(self, 400, "Error: %s"%e)
             logger.warning("PUT for " + instance_id + " returning 400 response. Error: %s"%e)
-            logger.warning(traceback.format_exc())
+            logger.exception(e)
             return
 
 

keylime/tenant_webapp.py

@@ -290,8 +290,7 @@ def get_instance_state(self, instance_id):
                                         "http://%s:%s/instances/%s"%(tenant_templ.cloudverifier_ip,tenant_templ.cloudverifier_port,instance_id),context=tenant_templ.context)
         except Exception as e:
             logger.error("Status command response: %s:%s Unexpected response from Cloud Verifier."%(tenant_templ.cloudverifier_ip,tenant_templ.cloudverifier_port))
-            logger.error(traceback.print_exc())
-            logger.error("Error: %s "%str(e))
+            logger.exception(e)
             common.echo_json_response(self, 500, "Unexpected response from Cloud Verifier", str(e))
             return
 
@@ -356,8 +355,7 @@ def get(self):
                                         "http://%s:%s/instances/"%(tenant_templ.registrar_ip,tenant_templ.registrar_port),context=tenant_templ.context)
         except Exception as e:
             logger.error("Status command response: %s:%s Unexpected response from Registrar."%(tenant_templ.registrar_ip,tenant_templ.registrar_port))
-            logger.error(traceback.print_exc())
-            logger.error("Error: %s "%str(e))
+            logger.exception(e)
             common.echo_json_response(self, 500, "Unexpected response from Registrar", str(e))
             return
 

keylime/tpm1.py

@@ -39,7 +39,6 @@
 import time
 from tpm_abstract import *
 from tpm_ek_ca import *
-import traceback
 
 logger = common.init_logging('tpm1')
 
@@ -418,7 +417,7 @@ def encryptAIK(self,uuid,pubaik,pubek,ek_tpm,aik_name):
 
         except Exception as e:
             logger.error("Error encrypting AIK: "+str(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return False
         finally:
             if pubaikFile is not None:
@@ -465,7 +464,7 @@ def activate_identity(self,keyblob):
 
         except Exception as e:
             logger.error("Error decrypting AIK: "+str(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return False
         finally:
             if keyblobFile is not None:
@@ -682,7 +681,7 @@ def check_deep_quote(self,nonce,data,quote,vAIK,hAIK,vtpm_policy={},tpm_policy={
             retout = self.__checkdeepquote_c(hAIKFile.name, vAIKFile.name, quoteFile.name, nonce)
         except Exception as e:
             logger.error("Error verifying quote: %s"%(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return False
         finally:
             if vAIKFile is not None:
@@ -770,7 +769,7 @@ def check_quote(self,nonce,data,quote,aikFromRegistrar,tpm_policy={},ima_measure
             retout = self.__check_quote_c(aikFile.name, quoteFile.name, nonce)
         except Exception as e:
             logger.error("Error verifying quote: "+str(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return False
         finally:
             if aikFile is not None:

keylime/tpm2.py

@@ -29,7 +29,6 @@
 import tempfile
 import threading
 import time
-import traceback
 
 import M2Crypto
 from M2Crypto import m2
@@ -553,7 +552,7 @@ def encryptAIK(self, uuid, pubaik, pubek, ek_tpm, aik_name):
 
         except Exception as e:
             logger.error("Error encrypting AIK: "+str(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return None
         finally:
             if pubekFile is not None:
@@ -597,7 +596,7 @@ def activate_identity(self, keyblob):
 
         except Exception as e:
             logger.error("Error decrypting AIK: "+str(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return False
         finally:
             if keyblobFile is not None:
@@ -814,7 +813,7 @@ def check_quote(self, nonce, data, quote, aikFromRegistrar, tpm_policy={}, ima_m
             code = retDict['code']
         except Exception as e:
             logger.error("Error verifying quote: "+str(e))
-            logger.error(traceback.format_exc())
+            logger.exception(e)
             return False
         finally:
             if aikFile is not None:

scripts/script_check_quote.py

@@ -31,7 +31,6 @@
 import os
 import tempfile
 import subprocess
-import traceback
 import base64
 
 logging.basicConfig(stream=sys.stdout, level=logging.WARN,format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
@@ -76,8 +75,7 @@
 #         print(line)
     print("check_quote(raw): %d runs, total time %f, avg %f ms per run" % (runs,c,c/runs*1000))
 except Exception as e:
-    logger.error("Error verifying quote: "+str(e))
-    logger.error(traceback.format_exc())
+    logger.exception(e)
 finally:
     if aikFile is not None:
         os.remove(aikFile.name)
@@ -152,8 +150,7 @@
     print("check_deep_quote (raw): %d runs, total time %f, avg %f ms per run" % (runs,c,c/runs*1000))
 
 except Exception as e:
-    logger.error("Error verifying quote: "+str(e))
-    logger.error(traceback.format_exc())
+    logger.exception(e)
 finally:
     if vAIKFile is not None:
         os.remove(vAIKFile.name)

scripts/script_check_quote_raw.py

@@ -31,7 +31,6 @@
 import os
 import tempfile
 import subprocess
-import traceback
 import base64
 
 logging.basicConfig(stream=sys.stdout, level=logging.WARN,format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
@@ -75,8 +74,7 @@
         print("=output="+line)
     print("check_quote (raw sig): %d runs, total time %f, avg %f us per run" % (runs,c,c/runs*1000*1000))
 except Exception as e:
-    logger.error("Error verifying quote: "+str(e))
-    logger.error(traceback.format_exc())
+    logger.exception(e)
 finally:
     if aikFile is not None:
         os.remove(aikFile.name)
@@ -133,8 +131,7 @@
     print("check_deep_quote (raw sig): %d runs, total time %f, avg %f us per run" % (runs,c,c/runs*1000*1000))
 
 except Exception as e:
-    logger.error("Error verifying quote: "+str(e))
-    logger.error(traceback.format_exc())
+    logger.exception(e)
 finally:
     if vAIKFile is not None:
         os.remove(vAIKFile.name)