From: tierno Date: Thu, 6 Apr 2017 16:58:24 +0000 (+0200) Subject: logging enhancement at dhcp_thread X-Git-Tag: v2.0.0~21 X-Git-Url: https://osm.etsi.org/gitweb/?a=commitdiff_plain;h=refs%2Fchanges%2F21%2F1521%2F3;p=osm%2Fopenvim.git logging enhancement at dhcp_thread Change-Id: I2bccc3f0b10e6bc456da666be5488989c48758bf Signed-off-by: tierno --- diff --git a/dhcp_thread.py b/dhcp_thread.py index f482334..da7176b 100644 --- a/dhcp_thread.py +++ b/dhcp_thread.py @@ -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 --- 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