logging enhancement at dhcp_thread 21/1521/3
authortierno <alfonso.tiernosepulveda@telefonica.com>
Thu, 6 Apr 2017 16:58:24 +0000 (18:58 +0200)
committertierno <alfonso.tiernosepulveda@telefonica.com>
Mon, 17 Apr 2017 10:19:45 +0000 (12:19 +0200)
Change-Id: I2bccc3f0b10e6bc456da666be5488989c48758bf
Signed-off-by: tierno <alfonso.tiernosepulveda@telefonica.com>
dhcp_thread.py
ovim.py

index f482334..da7176b 100644 (file)
@@ -35,11 +35,12 @@ import Queue
 import paramiko
 import random
 import subprocess
+import logging
 
 #TODO: insert a logging system
 
 class dhcp_thread(threading.Thread):
-    def __init__(self, dhcp_params, db, db_lock, test, dhcp_nets, debug=None):
+    def __init__(self, dhcp_params, db, db_lock, test, dhcp_nets, logger_name=None, debug=None):
         '''Init a thread.
         Arguments: thread_info must be a dictionary with:
             'dhcp_params' dhcp server parameters with the following keys:
@@ -49,15 +50,20 @@ class dhcp_thread(threading.Thread):
             'test': in test mode no acces to a server is done, and ip is invented
         '''
         threading.Thread.__init__(self)
-        self.name = "dhcp_thread"
         self.dhcp_params = dhcp_params
-        self.debug = debug
         self.db = db
         self.db_lock = db_lock
         self.test = test
         self.dhcp_nets = dhcp_nets
         self.ssh_conn = None
-        
+        if logger_name:
+            self.logger_name = logger_name
+        else:
+            self.logger_name = "openvim.dhcp"
+        self.logger = logging.getLogger(self.logger_name)
+        if debug:
+            self.logger.setLevel(getattr(logging, debug))
+
         self.mac_status ={} #dictionary of mac_address to retrieve information
             #ip: None
             #retries: 
@@ -75,16 +81,15 @@ class dhcp_thread(threading.Thread):
             self.ssh_conn = paramiko.SSHClient()
             self.ssh_conn.set_missing_host_key_policy(paramiko.AutoAddPolicy())
             self.ssh_conn.load_system_host_keys()
-            self.ssh_conn.connect(self.dhcp_params["host"], port=self.dhcp_params.get("port",22),
-                                  username=self.dhcp_params["user"], password=self.dhcp_params.get("password"), key_filename=self.dhcp_params.get("key"),
-                                  timeout=2)
+            self.ssh_conn.connect(self.dhcp_params["host"], port=self.dhcp_params.get("port", 22),
+                                  username=self.dhcp_params["user"], password=self.dhcp_params.get("password"),
+                                  key_filename=self.dhcp_params.get("key"), timeout=2)
         except paramiko.ssh_exception.SSHException as e:
-            text = e.args[0]
-            print self.name, ": ssh_connect ssh Exception:", text
+            self.logger.error("ssh_connect ssh Exception " + str(e))
         
     def load_mac_from_db(self):
         #TODO get macs to follow from the database
-        print self.name, " load macs from db"
+        self.logger.debug("load macs from db")
         self.db_lock.acquire()
         r,c = self.db.get_table(SELECT=('mac','ip_address','nets.uuid as net_id', ),
                                 FROM='ports join nets on ports.net_id=nets.uuid', 
@@ -93,7 +98,7 @@ class dhcp_thread(threading.Thread):
         now = time.time()
         self.mac_status ={}
         if r<0:
-            print self.name, ": Error getting data from database:", c
+            self.logger.error("Error getting data from database: " + c)
             return
         for port in c:
             if port["net_id"] in self.dhcp_nets:
@@ -106,53 +111,55 @@ class dhcp_thread(threading.Thread):
             self.queueLock.release()
             return 1, None
         except Queue.Full:
-            return -1, "timeout inserting a task over host " + self.name
+            return -1, "timeout inserting a task over dhcp_thread"
 
     def run(self):
-        print self.name, " starting, nets", self.dhcp_nets 
+        self.logger.debug("starting, nets: " + str(self.dhcp_nets))
         next_iteration = time.time() + 10
         while True:
             self.load_mac_from_db()
             while True:
-                self.queueLock.acquire()
-                if not self.taskQueue.empty():
-                    task = self.taskQueue.get()
-                else:
-                    task = None
-                self.queueLock.release()
-    
-                if task is None:
-                    now=time.time()
-                    if now >= next_iteration:
-                        next_iteration = self.get_ip_from_dhcp()
+                try:
+                    self.queueLock.acquire()
+                    if not self.taskQueue.empty():
+                        task = self.taskQueue.get()
                     else:
-                        time.sleep(1)
-                    continue        
-    
-                if task[0] == 'add':
-                    print self.name, ": processing task add mac", task[1]
-                    now=time.time()
-                    self.mac_status[task[1] ] = {"ip": None, "next_reading": now, "created": now, "retries":0}
-                    next_iteration = now
-                elif task[0] == 'del':
-                    print self.name, ": processing task del mac", task[1]
-                    if task[1] in self.mac_status:
-                        del self.mac_status[task[1] ]
-                elif task[0] == 'exit':
-                    print self.name, ": processing task exit"
-                    self.terminate()
-                    return 0
-                else:
-                    print self.name, ": unknown task", task
+                        task = None
+                    self.queueLock.release()
+
+                    if task is None:
+                        now=time.time()
+                        if now >= next_iteration:
+                            next_iteration = self.get_ip_from_dhcp()
+                        else:
+                            time.sleep(1)
+                        continue
+
+                    if task[0] == 'add':
+                        self.logger.debug("processing task add mac " + str(task[1]))
+                        now=time.time()
+                        self.mac_status[task[1] ] = {"ip": None, "next_reading": now, "created": now, "retries":0}
+                        next_iteration = now
+                    elif task[0] == 'del':
+                        self.logger.debug("processing task del mac " + str(task[1]))
+                        if task[1] in self.mac_status:
+                            del self.mac_status[task[1] ]
+                    elif task[0] == 'exit':
+                        self.logger.debug("processing task exit")
+                        self.terminate()
+                        return 0
+                    else:
+                        self.logger.error("unknown task: " + str(task))
+                except Exception as e:
+                    self.logger.critical("Unexpected exception at run: " + str(e), exc_info=True)
           
     def terminate(self):
         try:
             if self.ssh_conn:
                 self.ssh_conn.close()
         except Exception as e:
-            text = str(e)
-            print self.name, ": terminate Exception:", text
-        print self.name, ": exit from host_thread" 
+            self.logger.error("terminate Exception: " + str(e))
+        self.logger.debug("exit from dhcp_thread")
 
     def get_ip_from_dhcp(self):
         
@@ -175,7 +182,7 @@ class dhcp_thread(threading.Thread):
                 if r>0:
                     self.mac_status[mac_address]["active"] = now
                     self.mac_status[mac_address]["next_reading"] = (int(now)/2 +1)* 2
-                    print self.name, "mac %s  VM ACTIVE" % (mac_address)
+                    self.logger.debug("mac %s VM ACTIVE", mac_address)
                     self.mac_status[mac_address]["retries"] = 0
                 else:
                     #print self.name, "mac %s  VM INACTIVE" % (mac_address)
@@ -186,7 +193,7 @@ class dhcp_thread(threading.Thread):
                             r,c = self.db.update_rows("ports", {"ip_address": "0.0.0.0"}, {"mac": mac_address})
                             self.db_lock.release()
                             self.mac_status[mac_address]["ip"] = "0.0.0.0"
-                            print self.name, "mac %s >> set to 0.0.0.0 because of timeout" % (mac_address)
+                            self.logger.debug("mac %s >> set to 0.0.0.0 because of timeout", mac_address)
                         self.mac_status[mac_address]["next_reading"] = (int(now)/60 +1)* 60
                     else:
                         self.mac_status[mac_address]["next_reading"] = (int(now)/6 +1)* 6
@@ -205,8 +212,7 @@ class dhcp_thread(threading.Thread):
                     command = ['get_dhcp_lease.sh',  mac_address]
                     content = subprocess.check_output(command)
                 except Exception as e:
-                    text = str(e)
-                    print self.name, ": get_ip_from_dhcp subprocess Exception", text
+                    self.logger.error("get_ip_from_dhcp subprocess Exception " + str(e))
                     content = None
             else:
                 try:
@@ -216,13 +222,11 @@ class dhcp_thread(threading.Thread):
                     (_, stdout, _) = self.ssh_conn.exec_command(command)
                     content = stdout.read()
                 except paramiko.ssh_exception.SSHException as e:
-                    text = e.args[0]
-                    print self.name, ": get_ip_from_dhcp: ssh_Exception:", text
+                    self.logger.error("get_ip_from_dhcp: ssh_Exception: " + srt(e))
                     content = None
                     self.ssh_conn = None
                 except Exception as e:
-                    text = str(e)
-                    print self.name, ": get_ip_from_dhcp: Exception:", text
+                    self.logger.error("get_ip_from_dhcp: Exception: " + str(e))
                     content = None
                     self.ssh_conn = None
 
@@ -233,13 +237,13 @@ class dhcp_thread(threading.Thread):
                 r,c = self.db.update_rows("ports", {"ip_address": content}, {"mac": mac_address})
                 self.db_lock.release()
                 if r<0:
-                    print self.name, ": Database update error:", c
+                    self.logger.error("Database update error: " + c)
                 else:
                     self.mac_status[mac_address]["retries"] = 0
                     self.mac_status[mac_address]["next_reading"] = (int(now)/3600 +1)* 36000 # 10 hores
                     if self.mac_status[mac_address]["next_reading"] < next_iteration:
                         next_iteration = self.mac_status[mac_address]["next_reading"]
-                    print self.name, "mac %s >> %s" % (mac_address, content)
+                    self.logger.debug("mac %s >> %s", mac_address, content)
                     continue
             #a fail has happen
             self.mac_status[mac_address]["retries"] +=1
@@ -251,7 +255,7 @@ class dhcp_thread(threading.Thread):
                     r,c = self.db.update_rows("ports", {"ip_address": "0.0.0.0"}, {"mac": mac_address})
                     self.db_lock.release()
                     self.mac_status[mac_address]["ip"] = "0.0.0.0"
-                    print self.name, "mac %s >> set to 0.0.0.0 because of timeout" % (mac_address)
+                    self.logger.debug("mac %s >> set to 0.0.0.0 because of timeout", mac_address)
             
             if now - self.mac_status[mac_address]["active"] > 60:
                 self.mac_status[mac_address]["next_reading"] = (int(now)/6 +1)* 6
@@ -265,7 +269,7 @@ class dhcp_thread(threading.Thread):
         return next_iteration    
     
     def get_fake_ip(self):
-        fake_ip=   "192.168.%d.%d" % (random.randint(1,254), random.randint(1,254) )
+        fake_ip = "192.168.{}.{}".format(random.randint(1,254), random.randint(1,254) )
         while True:
             #check not already provided
             already_used = False
diff --git a/ovim.py b/ovim.py
index a1eaffa..b369594 100755 (executable)
--- a/ovim.py
+++ b/ovim.py
@@ -227,7 +227,8 @@ class ovim():
         dhcp_params = self.config.get("dhcp_server")
         if dhcp_params:
             thread = dt.dhcp_thread(dhcp_params=dhcp_params, test=host_test_mode, dhcp_nets=self.config["dhcp_nets"],
-                                    db=self.db_of, db_lock=self.db_lock, debug=self.config['log_level_of'])
+                                    db=self.db_of, db_lock=self.db_lock, logger_name=self.logger_name + ".dhcp",
+                                    debug=self.config.get('log_level_of'))
             thread.start()
             self.config['dhcp_thread'] = thread