osm_ro/vim_thread.py

   1 # -*- coding: utf-8 -*-
   2
   3 ##
   4 # Copyright 2015 Telefónica Investigación y Desarrollo, S.A.U.
   5 # This file is part of openvim
   6 # All Rights Reserved.
   7 #
   8 # Licensed under the Apache License, Version 2.0 (the "License"); you may
   9 # not use this file except in compliance with the License. You may obtain
  10 # a copy of the License at
  11 #
  12 #         http://www.apache.org/licenses/LICENSE-2.0
  13 #
  14 # Unless required by applicable law or agreed to in writing, software
  15 # distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
  16 # WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
  17 # License for the specific language governing permissions and limitations
  18 # under the License.
  19 #
  20 # For those usages not covered by the Apache License, Version 2.0 please
  21 # contact with: nfvlabs@tid.es
  22 ##
  23
  24 '''
  25 This is thread that interact with the host and the libvirt to manage VM
  26 One thread will be launched per host
  27 '''
  28 __author__ = "Alfonso Tierno, Pablo Montes"
  29 __date__ = "$10-feb-2017 12:07:15$"
  30
  31 import threading
  32 import time
  33 import Queue
  34 import logging
  35 import vimconn
  36 from db_base import db_base_Exception
  37 from ovim import ovimException
  38
  39
  40 # from logging import Logger
  41 # import auxiliary_functions as af
  42
  43
  44 def is_task_id(id):
  45     return True if id[:5] == "TASK." else False
  46
  47
  48 class vim_thread(threading.Thread):
  49
  50     def __init__(self, vimconn, task_lock, name=None, datacenter_name=None, datacenter_tenant_id=None, db=None, db_lock=None, ovim=None):
  51         """Init a thread.
  52         Arguments:
  53             'id' number of thead
  54             'name' name of thread
  55             'host','user':  host ip or name to manage and user
  56             'db', 'db_lock': database class and lock to use it in exclusion
  57         """
  58         self.tasksResult = {}
  59         """ It will contain a dictionary with
  60             task_id:
  61                 status: enqueued,done,error,deleted,processing
  62                 result: VIM result,
  63         """
  64         threading.Thread.__init__(self)
  65         self.vim = vimconn
  66         self.datacenter_name = datacenter_name
  67         self.datacenter_tenant_id = datacenter_tenant_id
  68         self.ovim = ovim
  69         if not name:
  70             self.name = vimconn["id"] + "." + vimconn["config"]["datacenter_tenant_id"]
  71         else:
  72             self.name = name
  73
  74         self.logger = logging.getLogger('openmano.vim.'+self.name)
  75         self.db = db
  76         self.db_lock = db_lock
  77
  78         self.task_lock = task_lock
  79         self.task_queue = Queue.Queue(2000)
  80         self.refresh_list = []
  81         """Contains time ordered task list for refreshing the status of VIM VMs and nets"""
  82
  83     def _refres_elements(self):
  84         """Call VIM to get VMs and networks status until 10 elements"""
  85         now = time.time()
  86         vm_to_refresh_list = []
  87         net_to_refresh_list = []
  88         vm_to_refresh_dict = {}
  89         net_to_refresh_dict = {}
  90         items_to_refresh = 0
  91         while self.refresh_list:
  92             task = self.refresh_list[0]
  93             with self.task_lock:
  94                 if task['status'] == 'deleted':
  95                     self.refresh_list.pop(0)
  96                     continue
  97                 if task['time'] > now:
  98                     break
  99                 task["status"] = "processing"
 100             self.refresh_list.pop(0)
 101             if task["name"] == 'get-vm':
 102                 vm_to_refresh_list.append(task["vim_id"])
 103                 vm_to_refresh_dict[task["vim_id"]] = task
 104             elif task["name"] == 'get-net':
 105                 net_to_refresh_list.append(task["vim_id"])
 106                 net_to_refresh_dict[task["vim_id"]] = task
 107             else:
 108                 error_text = "unknown task {}".format(task["name"])
 109                 self.logger.error(error_text)
 110             items_to_refresh += 1
 111             if items_to_refresh == 10:
 112                 break
 113
 114         if vm_to_refresh_list:
 115             try:
 116                 vim_dict = self.vim.refresh_vms_status(vm_to_refresh_list)
 117                 for vim_id, vim_info in vim_dict.items():
 118                     #look for task
 119                     task = vm_to_refresh_dict[vim_id]
 120                     self.logger.debug("get-vm vm_id=%s result=%s", task["vim_id"], str(vim_info))
 121
 122                     # update database
 123                     if vim_info.get("error_msg"):
 124                         vim_info["error_msg"] = self._format_vim_error_msg(vim_info["error_msg"])
 125                     if task["vim_info"].get("status") != vim_info["status"] or \
 126                         task["vim_info"].get("error_msg") != vim_info.get("error_msg") or \
 127                         task["vim_info"].get("vim_info") != vim_info["vim_info"]:
 128                         with self.db_lock:
 129                             temp_dict = {"status": vim_info["status"],
 130                                          "error_msg": vim_info.get("error_msg"),
 131                                          "vim_info": vim_info["vim_info"]}
 132                             self.db.update_rows('instance_vms', UPDATE=temp_dict, WHERE={"vim_vm_id": vim_id})
 133                     for interface in vim_info["interfaces"]:
 134                         for task_interface in task["vim_info"]["interfaces"]:
 135                             if task_interface["vim_net_id"] == interface["vim_net_id"]:
 136                                 break
 137                         else:
 138                             task_interface = {"vim_net_id": interface["vim_net_id"]}
 139                             task["vim_info"]["interfaces"].append(task_interface)
 140                         if task_interface != interface:
 141                             #delete old port
 142                             if task_interface.get("sdn_port_id"):
 143                                 try:
 144                                     self.ovim.delete_port(task_interface["sdn_port_id"])
 145                                     task_interface["sdn_port_id"] = None
 146                                 except ovimException as e:
 147                                     self.logger.error("ovimException deleting external_port={} ".format(
 148                                         task_interface["sdn_port_id"]) + str(e), exc_info=True)
 149                                     # TODO Set error_msg at instance_nets
 150                             vim_net_id = interface.pop("vim_net_id")
 151                             sdn_net_id = None
 152                             sdn_port_name = None
 153                             with self.db_lock:
 154                                 where_= {'iv.vim_vm_id': vim_id, "ine.vim_net_id": vim_net_id,
 155                                             'ine.datacenter_tenant_id': self.datacenter_tenant_id}
 156                                 # TODO check why vim_interface_id is not present at database
 157                                 # if interface.get("vim_interface_id"):
 158                                 #     where_["vim_interface_id"] = interface["vim_interface_id"]
 159                                 db_ifaces = self.db.get_rows(
 160                                     FROM="instance_interfaces as ii left join instance_nets as ine on "
 161                                          "ii.instance_net_id=ine.uuid left join instance_vms as iv on "
 162                                          "ii.instance_vm_id=iv.uuid",
 163                                     SELECT=("ii.uuid as iface_id", "ine.uuid as net_id", "iv.uuid as vm_id", "sdn_net_id"),
 164                                     WHERE=where_)
 165                             if len(db_ifaces)>1:
 166                                 self.logger.critical("Refresing interfaces. "
 167                                                   "Found more than one interface at database for '{}'".format(where_))
 168                             elif len(db_ifaces)==0:
 169                                 self.logger.critical("Refresing interfaces. "
 170                                                   "Not found any interface at database for '{}'".format(where_))
 171                                 continue
 172                             else:
 173                                 db_iface = db_ifaces[0]
 174                                 if db_iface.get("sdn_net_id") and interface.get("compute_node") and interface.get("pci"):
 175                                     sdn_net_id = db_iface["sdn_net_id"]
 176                                     sdn_port_name = sdn_net_id + "." + db_iface["vm_id"]
 177                                     sdn_port_name = sdn_port_name[:63]
 178                                     try:
 179                                         sdn_port_id = self.ovim.new_external_port(
 180                                             {"compute_node": interface["compute_node"],
 181                                              "pci": interface["pci"],
 182                                              "vlan": interface.get("vlan"),
 183                                              "net_id": sdn_net_id,
 184                                              "region": self.vim["config"]["datacenter_id"],
 185                                              "name": sdn_port_name,
 186                                              "mac": interface.get("mac_address")})
 187                                         interface["sdn_port_id"] = sdn_port_id
 188                                     except (ovimException, Exception) as e:
 189                                         self.logger.error(
 190                                             "ovimException creating new_external_port compute_node={} " \
 191                                             "pci={} vlan={} ".format(
 192                                                 interface["compute_node"],
 193                                                 interface["pci"],
 194                                                 interface.get("vlan")) + str(e),
 195                                             exc_info=True)
 196                                         # TODO Set error_msg at instance_nets
 197                                 with self.db_lock:
 198                                     self.db.update_rows('instance_interfaces', UPDATE=interface,
 199                                                     WHERE={'uuid': db_iface["iface_id"]})
 200                                 # TODO insert instance_id
 201                             interface["vim_net_id"] = vim_net_id
 202
 203                     task["vim_info"] = vim_info
 204                     if task["vim_info"]["status"] == "BUILD":
 205                         self._insert_refresh(task, now+5)  # 5seconds
 206                     else:
 207                         self._insert_refresh(task, now+300) # 5minutes
 208             except vimconn.vimconnException as e:
 209                 self.logger.error("vimconnException Exception when trying to refresh vms " + str(e))
 210                 self._insert_refresh(task, now + 300)  # 5minutes
 211
 212         if net_to_refresh_list:
 213             try:
 214                 vim_dict = self.vim.refresh_nets_status(net_to_refresh_list)
 215                 for vim_id, vim_info in vim_dict.items():
 216                     #look for task
 217                     task = net_to_refresh_dict[vim_id]
 218                     self.logger.debug("get-net net_id=%s result=%s", task["vim_id"], str(vim_info))
 219
 220                     #get database info
 221                     where_ = {"vim_net_id": vim_id, 'datacenter_tenant_id': self.datacenter_tenant_id}
 222                     with self.db_lock:
 223                         db_nets = self.db.get_rows(
 224                             FROM="instance_nets",
 225                             SELECT=("uuid as net_id", "sdn_net_id"),
 226                             WHERE=where_)
 227                     if len(db_nets) > 1:
 228                         self.logger.critical("Refresing networks. "
 229                                           "Found more than one instance-networks at database for '{}'".format(where_))
 230                     elif len(db_nets) == 0:
 231                         self.logger.critical("Refresing networks. "
 232                                           "Not found any instance-network at database for '{}'".format(where_))
 233                         continue
 234                     else:
 235                         db_net = db_nets[0]
 236                         if db_net.get("sdn_net_id"):
 237                             # get ovim status
 238                             try:
 239                                 sdn_net = self.ovim.show_network(db_net["sdn_net_id"])
 240                                 if sdn_net["status"] == "ERROR":
 241                                     if not vim_info.get("error_msg"):
 242                                         vim_info["error_msg"] = sdn_net["error_msg"]
 243                                     else:
 244                                         vim_info["error_msg"] = "VIM_ERROR: {} && SDN_ERROR: {}".format(
 245                                             self._format_vim_error_msg(vim_info["error_msg"], 1024//2-14),
 246                                             self._format_vim_error_msg(sdn_net["error_msg"], 1024//2-14))
 247                                     if vim_info["status"] == "VIM_ERROR":
 248                                         vim_info["status"] = "VIM_SDN_ERROR"
 249                                     else:
 250                                         vim_info["status"] = "SDN_ERROR"
 251
 252                             except (ovimException, Exception) as e:
 253                                 self.logger.error(
 254                                     "ovimException getting network infor snd_net_id={}".format(db_net["sdn_net_id"]),
 255                                     exc_info=True)
 256                                 # TODO Set error_msg at instance_nets
 257
 258                     # update database
 259                     if vim_info.get("error_msg"):
 260                         vim_info["error_msg"] = self._format_vim_error_msg(vim_info["error_msg"])
 261                     if task["vim_info"].get("status") != vim_info["status"] or \
 262                                     task["vim_info"].get("error_msg") != vim_info.get("error_msg") or \
 263                                     task["vim_info"].get("vim_info") != vim_info["vim_info"]:
 264                         with self.db_lock:
 265                             temp_dict = {"status": vim_info["status"],
 266                                          "error_msg": vim_info.get("error_msg"),
 267                                          "vim_info": vim_info["vim_info"]}
 268                             self.db.update_rows('instance_nets', UPDATE=temp_dict, WHERE={"vim_net_id": vim_id})
 269
 270                     task["vim_info"] = vim_info
 271                     if task["vim_info"]["status"] == "BUILD":
 272                         self._insert_refresh(task, now+5)    # 5seconds
 273                     else:
 274                         self._insert_refresh(task, now+300)  # 5minutes
 275             except vimconn.vimconnException as e:
 276                 self.logger.error("vimconnException Exception when trying to refresh nets " + str(e))
 277                 self._insert_refresh(task, now + 300)  # 5minutes
 278
 279         if not items_to_refresh:
 280             time.sleep(1)
 281
 282     def _insert_refresh(self, task, threshold_time):
 283         """Insert a task at list of refreshing elements. The refreshing list is ordered by threshold_time (task['time']
 284         It is assumed that this is called inside this thread
 285         """
 286         task["time"] = threshold_time
 287         for index in range(0, len(self.refresh_list)):
 288             if self.refresh_list[index]["time"] > threshold_time:
 289                 self.refresh_list.insert(index, task)
 290                 break
 291         else:
 292             index = len(self.refresh_list)
 293             self.refresh_list.append(task)
 294         self.logger.debug("new refresh task={} name={}, time={} index={}".format(
 295             task["id"], task["name"], task["time"], index))
 296
 297     def _remove_refresh(self, task_name, vim_id):
 298         """Remove a task with this name and vim_id from the list of refreshing elements.
 299         It is assumed that this is called inside this thread outside _refres_elements method
 300         Return True if self.refresh_list is modified, task is found
 301         Return False if not found
 302         """
 303         index_to_delete = None
 304         for index in range(0, len(self.refresh_list)):
 305             if self.refresh_list[index]["name"] == task_name and self.refresh_list[index]["vim_id"] == vim_id:
 306                 index_to_delete = index
 307                 break
 308         else:
 309             return False
 310         if index_to_delete != None:
 311             del self.refresh_list[index_to_delete]
 312         return True
 313
 314     def insert_task(self, task):
 315         try:
 316             self.task_queue.put(task, False)
 317             return task["id"]
 318         except Queue.Full:
 319             raise vimconn.vimconnException(self.name + ": timeout inserting a task")
 320
 321     def del_task(self, task):
 322         with self.task_lock:
 323             if task["status"] == "enqueued":
 324                 task["status"] == "deleted"
 325                 return True
 326             else:   # task["status"] == "processing"
 327                 self.task_lock.release()
 328                 return False
 329
 330     def run(self):
 331         self.logger.debug("Starting")
 332         while True:
 333             #TODO reload service
 334             while True:
 335                 try:
 336                     if not self.task_queue.empty():
 337                         task = self.task_queue.get()
 338                         self.task_lock.acquire()
 339                         if task["status"] == "deleted":
 340                             self.task_lock.release()
 341                             continue
 342                         task["status"] = "processing"
 343                         self.task_lock.release()
 344                     else:
 345                         self._refres_elements()
 346                         continue
 347                     self.logger.debug("processing task id={} name={} params={}".format(task["id"], task["name"],
 348                                                                                        str(task["params"])))
 349                     if task["name"] == 'exit' or task["name"] == 'reload':
 350                         result, content = self.terminate(task)
 351                     elif task["name"] == 'new-vm':
 352                         result, content = self.new_vm(task)
 353                     elif task["name"] == 'del-vm':
 354                         result, content = self.del_vm(task)
 355                     elif task["name"] == 'new-net':
 356                         result, content = self.new_net(task)
 357                     elif task["name"] == 'del-net':
 358                         result, content = self.del_net(task)
 359                     else:
 360                         error_text = "unknown task {}".format(task["name"])
 361                         self.logger.error(error_text)
 362                         result = False
 363                         content = error_text
 364                     self.logger.debug("task id={} name={} result={}:{} params={}".format(task["id"], task["name"],
 365                                                                                         result, content,
 366                                                                                         str(task["params"])))
 367
 368                     with self.task_lock:
 369                         task["status"] = "done" if result else "error"
 370                         task["result"] = content
 371                     self.task_queue.task_done()
 372
 373                     if task["name"] == 'exit':
 374                         return 0
 375                     elif task["name"] == 'reload':
 376                         break
 377                 except Exception as e:
 378                     self.logger.critical("Unexpected exception at run: " + str(e), exc_info=True)
 379
 380         self.logger.debug("Finishing")
 381
 382     def terminate(self, task):
 383         return True, None
 384
 385     def _format_vim_error_msg(self, error_text, max_length=1024):
 386         if error_text and len(error_text) >= max_length:
 387             return error_text[:max_length//2-3] + " ... " + error_text[-max_length//2+3:]
 388         return error_text
 389
 390     def new_net(self, task):
 391         try:
 392             task_id = task["id"]
 393             params = task["params"]
 394             net_id = self.vim.new_network(*params)
 395
 396             net_name = params[0]
 397             net_type = params[1]
 398
 399             network = None
 400             sdn_net_id = None
 401             sdn_controller = self.vim.config.get('sdn-controller')
 402             if sdn_controller and (net_type == "data" or net_type == "ptp"):
 403                 network = {"name": net_name, "type": net_type}
 404
 405                 vim_net = self.vim.get_network(net_id)
 406                 if vim_net.get('encapsulation') != 'vlan':
 407                     raise vimconn.vimconnException(
 408                         "net '{}' defined as type '{}' has not vlan encapsulation '{}'".format(
 409                             net_name, net_type, vim_net['encapsulation']))
 410                 network["vlan"] = vim_net.get('segmentation_id')
 411                 try:
 412                     sdn_net_id = self.ovim.new_network(network)
 413                 except (ovimException, Exception) as e:
 414                     self.logger.error("task=%s cannot create SDN network vim_net_id=%s input='%s' ovimException='%s'",
 415                                       str(task_id), net_id, str(network), str(e))
 416             with self.db_lock:
 417                 self.db.update_rows("instance_nets", UPDATE={"vim_net_id": net_id, "sdn_net_id": sdn_net_id},
 418                                     WHERE={"vim_net_id": task_id})
 419             new_refresh_task = {"status": "enqueued",
 420                                 "id": task_id,
 421                                 "name": "get-net",
 422                                 "vim_id": net_id,
 423                                 "vim_info": {} }
 424             self._insert_refresh(new_refresh_task, time.time())
 425             return True, net_id
 426         except db_base_Exception as e:
 427             self.logger.error("Error updating database %s", str(e))
 428             return True, net_id
 429         except vimconn.vimconnException as e:
 430             self.logger.error("Error creating NET, task=%s: %s", str(task_id), str(e))
 431             try:
 432                 with self.db_lock:
 433                     self.db.update_rows("instance_nets",
 434                                         UPDATE={"error_msg": self._format_vim_error_msg(str(e)), "status": "VIM_ERROR"},
 435                                         WHERE={"vim_net_id": task_id})
 436             except db_base_Exception as e:
 437                 self.logger.error("Error updating database %s", str(e))
 438             return False, str(e)
 439         #except ovimException as e:
 440         #    self.logger.error("Error creating NET in ovim, task=%s: %s", str(task_id), str(e))
 441         #    return False, str(e)
 442
 443     def new_vm(self, task):
 444         try:
 445             params = task["params"]
 446             task_id = task["id"]
 447             depends = task.get("depends")
 448             net_list = params[5]
 449             error_text = ""
 450             for net in net_list:
 451                 if "net_id" in net and is_task_id(net["net_id"]):  # change task_id into network_id
 452                     try:
 453                         task_net = depends[net["net_id"]]
 454                         with self.task_lock:
 455                             if task_net["status"] == "error":
 456                                 error_text = "Cannot create VM because depends on a network that cannot be created: " +\
 457                                        str(task_net["result"])
 458                                 break
 459                             elif task_net["status"] == "enqueued" or task_net["status"] == "processing":
 460                                 error_text = "Cannot create VM because depends on a network still not created"
 461                                 break
 462                             network_id = task_net["result"]
 463                         net["net_id"] = network_id
 464                     except Exception as e:
 465                         error_text = "Error trying to map from task_id={} to task result: {}".format(
 466                             net["net_id"],str(e))
 467                         break
 468             if not error_text:
 469                 vm_id = self.vim.new_vminstance(*params)
 470             try:
 471                 with self.db_lock:
 472                     if error_text:
 473                         update = self.db.update_rows("instance_vms",
 474                                                      UPDATE={"status": "VIM_ERROR", "error_msg": error_text},
 475                                                      WHERE={"vim_vm_id": task_id})
 476                     else:
 477                         update = self.db.update_rows("instance_vms", UPDATE={"vim_vm_id": vm_id}, WHERE={"vim_vm_id": task_id})
 478                     if not update:
 479                         self.logger.error("task id={} name={} database not updated vim_vm_id={}".format(
 480                             task["id"], task["name"], vm_id))
 481             except db_base_Exception as e:
 482                 self.logger.error("Error updating database %s", str(e))
 483             if error_text:
 484                 return False, error_text
 485             new_refresh_task = {"status": "enqueued",
 486                                 "id": task_id,
 487                                 "name": "get-vm",
 488                                 "vim_id": vm_id,
 489                                 "vim_info": {"interfaces":[]} }
 490             self._insert_refresh(new_refresh_task, time.time())
 491             return True, vm_id
 492         except vimconn.vimconnException as e:
 493             self.logger.error("Error creating VM, task=%s: %s", str(task_id), str(e))
 494             try:
 495                 with self.db_lock:
 496                     self.db.update_rows("instance_vms",
 497                                         UPDATE={"error_msg": self._format_vim_error_msg(str(e)), "status": "VIM_ERROR"},
 498                                         WHERE={"vim_vm_id": task_id})
 499             except db_base_Exception as edb:
 500                 self.logger.error("Error updating database %s", str(edb))
 501             return False, str(e)
 502
 503     def del_vm(self, task):
 504         vm_id = task["params"][0]
 505         interfaces = task["params"][1]
 506         if is_task_id(vm_id):
 507             try:
 508                 task_create = task["depends"][vm_id]
 509                 with self.task_lock:
 510                     if task_create["status"] == "error":
 511                         return True, "VM was not created. It has error: " + str(task_create["result"])
 512                     elif task_create["status"] == "enqueued" or task_create["status"] == "processing":
 513                         return False, "Cannot delete VM vim_id={} because still creating".format(vm_id)
 514                     vm_id = task_create["result"]
 515             except Exception as e:
 516                 return False, "Error trying to get task_id='{}':".format(vm_id, str(e))
 517         try:
 518             self._remove_refresh("get-vm", vm_id)
 519             for iface in interfaces:
 520                 if iface.get("sdn_port_id"):
 521                     try:
 522                         self.ovim.delete_port(iface["sdn_port_id"])
 523                     except ovimException as e:
 524                         self.logger.error("ovimException deleting external_port={} at VM vim_id={} deletion ".format(
 525                             iface["sdn_port_id"], vm_id) + str(e), exc_info=True)
 526                         # TODO Set error_msg at instance_nets
 527
 528             return True, self.vim.delete_vminstance(vm_id)
 529         except vimconn.vimconnException as e:
 530             return False, str(e)
 531
 532     def del_net(self, task):
 533         net_id = task["params"][0]
 534         sdn_net_id = task["params"][1]
 535         if is_task_id(net_id):
 536             try:
 537                 task_create = task["depends"][net_id]
 538                 with self.task_lock:
 539                     if task_create["status"] == "error":
 540                         return True, "net was not created. It has error: " + str(task_create["result"])
 541                     elif task_create["status"] == "enqueued" or task_create["status"] == "processing":
 542                         return False, "Cannot delete net because still creating"
 543                     net_id = task_create["result"]
 544             except Exception as e:
 545                 return False, "Error trying to get task_id='{}':".format(net_id, str(e))
 546         try:
 547             self._remove_refresh("get-net", net_id)
 548             result = self.vim.delete_network(net_id)
 549             if sdn_net_id:
 550                 with self.db_lock:
 551                     self.ovim.delete_network(sdn_net_id)
 552             return True, result
 553         except vimconn.vimconnException as e:
 554             return False, str(e)
 555         except ovimException as e:
 556             logging.error("Error deleting network from ovim. net_id: {}, sdn_net_id: {}".format(net_id, sdn_net_id))
 557             return False, str(e)
 558
 559