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 openvim.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.error("Refresing interfaces. "
 167                                                   "Found more than one interface at database for '{}'".format(where_))
 168                             elif len(db_ifaces)==0:
 169                                 self.logger.error("Refresing interfaces. "
 170                                                   "Not found any interface at database for '{}'".format(where_))
 171                             else:
 172                                 db_iface = db_ifaces[0]
 173                                 if db_iface.get("sdn_net_id") and interface.get("compute_node") and interface.get("pci"):
 174                                     sdn_net_id = db_iface["sdn_net_id"]
 175                                     sdn_port_name = sdn_net_id + "." + db_iface["vm_id"]
 176                                     sdn_port_name = sdn_port_name[:63]
 177                                     try:
 178                                         sdn_port_id = self.ovim.new_external_port(
 179                                             {"compute_node": interface["compute_node"],
 180                                              "pci": interface["pci"],
 181                                              "vlan": interface.get("vlan"),
 182                                              "net_id": sdn_net_id,
 183                                              "region": self.vim["config"]["datacenter_id"],
 184                                              "name": sdn_port_name,
 185                                              "mac": interface.get("mac_address")})
 186                                         interface["sdn_port_id"] = sdn_port_id
 187                                     except (ovimException, Exception) as e:
 188                                         self.logger.error(
 189                                             "ovimException creating new_external_port compute_node={} " \
 190                                             "pci={} vlan={} ".format(
 191                                                 interface["compute_node"],
 192                                                 interface["pci"],
 193                                                 interface.get("vlan")) + str(e),
 194                                             exc_info=True)
 195                                         # TODO Set error_msg at instance_nets
 196                                 with self.db_lock:
 197                                     self.db.update_rows('instance_interfaces', UPDATE=interface,
 198                                                     WHERE={'uuid': db_iface["iface_id"]})
 199                                 # TODO insert instance_id
 200                             interface["vim_net_id"] = vim_net_id
 201
 202                     task["vim_info"] = vim_info
 203                     if task["vim_info"]["status"] == "BUILD":
 204                         self._insert_refresh(task, now+5)  # 5seconds
 205                     else:
 206                         self._insert_refresh(task, now+300) # 5minutes
 207             except vimconn.vimconnException as e:
 208                 self.logger.error("vimconnException Exception when trying to refresh vms " + str(e))
 209                 self._insert_refresh(task, now + 300)  # 5minutes
 210
 211         if net_to_refresh_list:
 212             try:
 213                 vim_dict = self.vim.refresh_nets_status(net_to_refresh_list)
 214                 for vim_id, vim_info in vim_dict.items():
 215                     #look for task
 216                     task = net_to_refresh_dict[vim_id]
 217                     self.logger.debug("get-net net_id=%s result=%s", task["vim_id"], str(vim_info))
 218
 219                     #get database info
 220                     where_ = {"vim_net_id": vim_id, 'datacenter_tenant_id': self.datacenter_tenant_id}
 221                     with self.db_lock:
 222                         db_nets = self.db.get_rows(
 223                             FROM="instance_nets",
 224                             SELECT=("uuid as net_id", "sdn_net_id"),
 225                             WHERE=where_)
 226                     if len(db_nets) > 1:
 227                         self.logger.error("Refresing networks. "
 228                                           "Found more than one instance-networks at database for '{}'".format(where_))
 229                     elif len(db_nets) == 0:
 230                         self.logger.error("Refresing networks. "
 231                                           "Not found any instance-network at database for '{}'".format(where_))
 232                     else:
 233                         db_net = db_nets[0]
 234                         if db_net.get("sdn_net_id"):
 235                             # get ovim status
 236                             try:
 237                                 sdn_net = self.ovim.show_network(db_net["sdn_net_id"])
 238                                 if sdn_net["status"] == "ERROR":
 239                                     if not vim_info.get("error_msg"):
 240                                         vim_info["error_msg"] = sdn_net["error_msg"]
 241                                     else:
 242                                         vim_info["error_msg"] = "VIM_ERROR: {} && SDN_ERROR: {}".format(
 243                                             self._format_vim_error_msg(vim_info["error_msg"], 1024//2-14),
 244                                             self._format_vim_error_msg(sdn_net["error_msg"], 1024//2-14))
 245                                     if vim_info["status"] == "VIM_ERROR":
 246                                         vim_info["status"] = "VIM_SDN_ERROR"
 247                                     else:
 248                                         vim_info["status"] = "SDN_ERROR"
 249
 250                             except (ovimException, Exception) as e:
 251                                 self.logger.error(
 252                                     "ovimException getting network infor snd_net_id={}".format(db_net["sdn_net_id"]),
 253                                     exc_info=True)
 254                                 # TODO Set error_msg at instance_nets
 255
 256                     # update database
 257                     if vim_info.get("error_msg"):
 258                         vim_info["error_msg"] = self._format_vim_error_msg(vim_info["error_msg"])
 259                     if task["vim_info"].get("status") != vim_info["status"] or \
 260                                     task["vim_info"].get("error_msg") != vim_info.get("error_msg") or \
 261                                     task["vim_info"].get("vim_info") != vim_info["vim_info"]:
 262                         with self.db_lock:
 263                             temp_dict = {"status": vim_info["status"],
 264                                          "error_msg": vim_info.get("error_msg"),
 265                                          "vim_info": vim_info["vim_info"]}
 266                             self.db.update_rows('instance_nets', UPDATE=temp_dict, WHERE={"vim_net_id": vim_id})
 267
 268                     task["vim_info"] = vim_info
 269                     if task["vim_info"]["status"] == "BUILD":
 270                         self._insert_refresh(task, now+5)    # 5seconds
 271                     else:
 272                         self._insert_refresh(task, now+300)  # 5minutes
 273             except vimconn.vimconnException as e:
 274                 self.logger.error("vimconnException Exception when trying to refresh nets " + str(e))
 275                 self._insert_refresh(task, now + 300)  # 5minutes
 276
 277         if not items_to_refresh:
 278             time.sleep(1)
 279
 280     def _insert_refresh(self, task, threshold_time):
 281         """Insert a task at list of refreshing elements. The refreshing list is ordered by threshold_time (task['time']
 282         It is assumed that this is called inside this thread
 283         """
 284         task["time"] = threshold_time
 285         for index in range(0, len(self.refresh_list)):
 286             if self.refresh_list[index]["time"] > threshold_time:
 287                 self.refresh_list.insert(index, task)
 288                 break
 289         else:
 290             index = len(self.refresh_list)
 291             self.refresh_list.append(task)
 292         self.logger.debug("new refresh task={} name={}, time={} index={}".format(
 293             task["id"], task["name"], task["time"], index))
 294
 295     def _remove_refresh(self, task_name, vim_id):
 296         """Remove a task with this name and vim_id from the list of refreshing elements.
 297         It is assumed that this is called inside this thread outside _refres_elements method
 298         Return True if self.refresh_list is modified, task is found
 299         Return False if not found
 300         """
 301         index_to_delete = None
 302         for index in range(0, len(self.refresh_list)):
 303             if self.refresh_list[index]["name"] == task_name and self.refresh_list[index]["vim_id"] == vim_id:
 304                 index_to_delete = index
 305                 break
 306         else:
 307             return False
 308         if index_to_delete != None:
 309             del self.refresh_list[index_to_delete]
 310         return True
 311
 312     def insert_task(self, task):
 313         try:
 314             self.task_queue.put(task, False)
 315             return task["id"]
 316         except Queue.Full:
 317             raise vimconn.vimconnException(self.name + ": timeout inserting a task")
 318
 319     def del_task(self, task):
 320         with self.task_lock:
 321             if task["status"] == "enqueued":
 322                 task["status"] == "deleted"
 323                 return True
 324             else:   # task["status"] == "processing"
 325                 self.task_lock.release()
 326                 return False
 327
 328     def run(self):
 329         self.logger.debug("Starting")
 330         while True:
 331             #TODO reload service
 332             while True:
 333                 if not self.task_queue.empty():
 334                     task = self.task_queue.get()
 335                     self.task_lock.acquire()
 336                     if task["status"] == "deleted":
 337                         self.task_lock.release()
 338                         continue
 339                     task["status"] = "processing"
 340                     self.task_lock.release()
 341                 else:
 342                     self._refres_elements()
 343                     continue
 344                 self.logger.debug("processing task id={} name={} params={}".format(task["id"], task["name"],
 345                                                                                    str(task["params"])))
 346                 if task["name"] == 'exit' or task["name"] == 'reload':
 347                     result, content = self.terminate(task)
 348                 elif task["name"] == 'new-vm':
 349                     result, content = self.new_vm(task)
 350                 elif task["name"] == 'del-vm':
 351                     result, content = self.del_vm(task)
 352                 elif task["name"] == 'new-net':
 353                     result, content = self.new_net(task)
 354                 elif task["name"] == 'del-net':
 355                     result, content = self.del_net(task)
 356                 else:
 357                     error_text = "unknown task {}".format(task["name"])
 358                     self.logger.error(error_text)
 359                     result = False
 360                     content = error_text
 361                 self.logger.debug("task id={} name={} result={}:{} params={}".format(task["id"], task["name"],
 362                                                                                     result, content,
 363                                                                                     str(task["params"])))
 364
 365                 with self.task_lock:
 366                     task["status"] = "done" if result else "error"
 367                     task["result"] = content
 368                 self.task_queue.task_done()
 369
 370                 if task["name"] == 'exit':
 371                     return 0
 372                 elif task["name"] == 'reload':
 373                     break
 374
 375         self.logger.debug("Finishing")
 376
 377     def terminate(self, task):
 378         return True, None
 379
 380     def _format_vim_error_msg(self, error_text, len=1024):
 381         if error_text and len(error_text) >= len:
 382             return error_text[:len//2-3] + " ... " + error_text[-len//2+3:]
 383         return error_text
 384
 385     def new_net(self, task):
 386         try:
 387             task_id = task["id"]
 388             params = task["params"]
 389             net_id = self.vim.new_network(*params)
 390
 391             net_name = params[0]
 392             net_type = params[1]
 393
 394             network = None
 395             sdn_controller = self.vim.config.get('sdn-controller')
 396             if sdn_controller and (net_type == "data" or net_type == "ptp"):
 397                 network = {"name": net_name, "type": net_type}
 398
 399                 vim_net = self.vim.get_network(net_id)
 400                 if vim_net.get('encapsulation') != 'vlan':
 401                     raise vimconn.vimconnException(
 402                         "net '{}' defined as type '{}' has not vlan encapsulation '{}'".format(
 403                             net_name, net_type, vim_net['encapsulation']))
 404                 network["vlan"] = vim_net.get('segmentation_id')
 405                 sdn_net_id = None
 406                 try:
 407                     sdn_net_id = self.ovim.new_network(network)
 408                 except (ovimException, Exception) as e:
 409                     self.logger.error("task=%s cannot create SDN network vim_net_id=%s input='%s' ovimException='%s'",
 410                                       str(task_id), net_id, str(network), str(e))
 411             with self.db_lock:
 412                 self.db.update_rows("instance_nets", UPDATE={"vim_net_id": net_id, "sdn_net_id": sdn_net_id},
 413                                     WHERE={"vim_net_id": task_id})
 414             new_refresh_task = {"status": "enqueued",
 415                                 "id": task_id,
 416                                 "name": "get-net",
 417                                 "vim_id": net_id,
 418                                 "vim_info": {} }
 419             self._insert_refresh(new_refresh_task, time.time())
 420             return True, net_id
 421         except db_base_Exception as e:
 422             self.logger.error("Error updating database %s", str(e))
 423             return True, net_id
 424         except vimconn.vimconnException as e:
 425             self.logger.error("Error creating NET, task=%s: %s", str(task_id), str(e))
 426             try:
 427                 with self.db_lock:
 428                     self.db.update_rows("instance_nets",
 429                                         UPDATE={"error_msg": self._format_vim_error_msg(str(e)), "status": "VIM_ERROR"},
 430                                         WHERE={"vim_net_id": task_id})
 431             except db_base_Exception as e:
 432                 self.logger.error("Error updating database %s", str(e))
 433             return False, str(e)
 434         #except ovimException as e:
 435         #    self.logger.error("Error creating NET in ovim, task=%s: %s", str(task_id), str(e))
 436         #    return False, str(e)
 437
 438     def new_vm(self, task):
 439         try:
 440             params = task["params"]
 441             task_id = task["id"]
 442             depends = task.get("depends")
 443             net_list = params[5]
 444             error_text = ""
 445             for net in net_list:
 446                 if "net_id" in net and is_task_id(net["net_id"]):  # change task_id into network_id
 447                     try:
 448                         task_net = depends[net["net_id"]]
 449                         with self.task_lock:
 450                             if task_net["status"] == "error":
 451                                 error_text = "Cannot create VM because depends on a network that cannot be created: " +\
 452                                        str(task_net["result"])
 453                                 break
 454                             elif task_net["status"] == "enqueued" or task_net["status"] == "processing":
 455                                 error_text = "Cannot create VM because depends on a network still not created"
 456                                 break
 457                             network_id = task_net["result"]
 458                         net["net_id"] = network_id
 459                     except Exception as e:
 460                         error_text = "Error trying to map from task_id={} to task result: {}".format(
 461                             net["net_id"],str(e))
 462                         break
 463             if not error_text:
 464                 vm_id = self.vim.new_vminstance(*params)
 465             try:
 466                 with self.db_lock:
 467                     if error_text:
 468                         update = self.db.update_rows("instance_vms",
 469                                                      UPDATE={"status": "VIM_ERROR", "error_msg": error_text},
 470                                                      WHERE={"vim_vm_id": task_id})
 471                     else:
 472                         update = self.db.update_rows("instance_vms", UPDATE={"vim_vm_id": vm_id}, WHERE={"vim_vm_id": task_id})
 473                     if not update:
 474                         self.logger.error("task id={} name={} database not updated vim_vm_id={}".format(
 475                             task["id"], task["name"], vm_id))
 476             except db_base_Exception as e:
 477                 self.logger.error("Error updating database %s", str(e))
 478             if error_text:
 479                 return False, error_text
 480             new_refresh_task = {"status": "enqueued",
 481                                 "id": task_id,
 482                                 "name": "get-vm",
 483                                 "vim_id": vm_id,
 484                                 "vim_info": {"interfaces":[]} }
 485             self._insert_refresh(new_refresh_task, time.time())
 486             return True, vm_id
 487         except vimconn.vimconnException as e:
 488             self.logger.error("Error creating VM, task=%s: %s", str(task_id), str(e))
 489             try:
 490                 with self.db_lock:
 491                     self.db.update_rows("instance_vms",
 492                                         UPDATE={"error_msg": self._format_vim_error_msg(str(e)), "status": "VIM_ERROR"},
 493                                         WHERE={"vim_vm_id": task_id})
 494             except db_base_Exception as edb:
 495                 self.logger.error("Error updating database %s", str(edb))
 496             return False, str(e)
 497
 498     def del_vm(self, task):
 499         vm_id = task["params"][0]
 500         interfaces = task["params"][1]
 501         if is_task_id(vm_id):
 502             try:
 503                 task_create = task["depends"][vm_id]
 504                 with self.task_lock:
 505                     if task_create["status"] == "error":
 506                         return True, "VM was not created. It has error: " + str(task_create["result"])
 507                     elif task_create["status"] == "enqueued" or task_create["status"] == "processing":
 508                         return False, "Cannot delete VM vim_id={} because still creating".format(vm_id)
 509                     vm_id = task_create["result"]
 510             except Exception as e:
 511                 return False, "Error trying to get task_id='{}':".format(vm_id, str(e))
 512         try:
 513             self._remove_refresh("get-vm", vm_id)
 514             for iface in interfaces:
 515                 if iface.get("sdn_port_id"):
 516                     try:
 517                         self.ovim.delete_port(iface["sdn_port_id"])
 518                     except ovimException as e:
 519                         self.logger.error("ovimException deleting external_port={} at VM vim_id={} deletion ".format(
 520                             iface["sdn_port_id"], vm_id) + str(e), exc_info=True)
 521                         # TODO Set error_msg at instance_nets
 522
 523             return True, self.vim.delete_vminstance(vm_id)
 524         except vimconn.vimconnException as e:
 525             return False, str(e)
 526
 527     def del_net(self, task):
 528         net_id = task["params"][0]
 529         sdn_net_id = task["params"][1]
 530         if is_task_id(net_id):
 531             try:
 532                 task_create = task["depends"][net_id]
 533                 with self.task_lock:
 534                     if task_create["status"] == "error":
 535                         return True, "net was not created. It has error: " + str(task_create["result"])
 536                     elif task_create["status"] == "enqueued" or task_create["status"] == "processing":
 537                         return False, "Cannot delete net because still creating"
 538                     net_id = task_create["result"]
 539             except Exception as e:
 540                 return False, "Error trying to get task_id='{}':".format(net_id, str(e))
 541         try:
 542             self._remove_refresh("get-vm", net_id)
 543             result = self.vim.delete_network(net_id)
 544             if sdn_net_id:
 545                 with self.db_lock:
 546                     self.ovim.delete_network(sdn_net_id)
 547             return True, result
 548         except vimconn.vimconnException as e:
 549             return False, str(e)
 550         except ovimException as e:
 551             logging.error("Error deleting network from ovim. net_id: {}, sdn_net_id: {}".format(net_id, sdn_net_id))
 552             return False, str(e)
 553
 554