osm_lcm/lcm.py

   1 #!/usr/bin/python3
   2 # -*- coding: utf-8 -*-
   3
   4 import asyncio
   5 import yaml
   6 import logging
   7 import logging.handlers
   8 import getopt
   9 import sys
  10 import ROclient
  11 import ns
  12 import vim_sdn
  13 import netslice
  14 from lcm_utils import versiontuple, LcmException, TaskRegistry
  15
  16 # from osm_lcm import version as lcm_version, version_date as lcm_version_date, ROclient
  17 from osm_common import dbmemory, dbmongo, fslocal, msglocal, msgkafka
  18 from osm_common import version as common_version
  19 from osm_common.dbbase import DbException
  20 from osm_common.fsbase import FsException
  21 from osm_common.msgbase import MsgException
  22 from os import environ, path
  23 from n2vc import version as n2vc_version
  24
  25
  26 __author__ = "Alfonso Tierno"
  27 min_RO_version = [0, 5, 72]
  28 min_n2vc_version = "0.0.2"
  29 min_common_version = "0.1.11"
  30 # uncomment if LCM is installed as library and installed, and get them from __init__.py
  31 lcm_version = '0.1.24'
  32 lcm_version_date = '2018-11-16'
  33
  34
  35 class Lcm:
  36
  37     ping_interval_pace = 120  # how many time ping is send once is confirmed all is running
  38     ping_interval_boot = 5    # how many time ping is sent when booting
  39
  40     def __init__(self, config_file, loop=None):
  41         """
  42         Init, Connect to database, filesystem storage, and messaging
  43         :param config: two level dictionary with configuration. Top level should contain 'database', 'storage',
  44         :return: None
  45         """
  46
  47         self.db = None
  48         self.msg = None
  49         self.fs = None
  50         self.pings_not_received = 1
  51
  52         # contains created tasks/futures to be able to cancel
  53         self.lcm_tasks = TaskRegistry()
  54         # logging
  55         self.logger = logging.getLogger('lcm')
  56         # load configuration
  57         config = self.read_config_file(config_file)
  58         self.config = config
  59         self.ro_config = {
  60             "endpoint_url": "http://{}:{}/openmano".format(config["RO"]["host"], config["RO"]["port"]),
  61             "tenant": config.get("tenant", "osm"),
  62             "logger_name": "lcm.ROclient",
  63             "loglevel": "ERROR",
  64         }
  65
  66         self.vca_config = config["VCA"]
  67
  68         self.loop = loop or asyncio.get_event_loop()
  69
  70         # logging
  71         log_format_simple = "%(asctime)s %(levelname)s %(name)s %(filename)s:%(lineno)s %(message)s"
  72         log_formatter_simple = logging.Formatter(log_format_simple, datefmt='%Y-%m-%dT%H:%M:%S')
  73         config["database"]["logger_name"] = "lcm.db"
  74         config["storage"]["logger_name"] = "lcm.fs"
  75         config["message"]["logger_name"] = "lcm.msg"
  76         if config["global"].get("logfile"):
  77             file_handler = logging.handlers.RotatingFileHandler(config["global"]["logfile"],
  78                                                                 maxBytes=100e6, backupCount=9, delay=0)
  79             file_handler.setFormatter(log_formatter_simple)
  80             self.logger.addHandler(file_handler)
  81         if not config["global"].get("nologging"):
  82             str_handler = logging.StreamHandler()
  83             str_handler.setFormatter(log_formatter_simple)
  84             self.logger.addHandler(str_handler)
  85
  86         if config["global"].get("loglevel"):
  87             self.logger.setLevel(config["global"]["loglevel"])
  88
  89         # logging other modules
  90         for k1, logname in {"message": "lcm.msg", "database": "lcm.db", "storage": "lcm.fs"}.items():
  91             config[k1]["logger_name"] = logname
  92             logger_module = logging.getLogger(logname)
  93             if config[k1].get("logfile"):
  94                 file_handler = logging.handlers.RotatingFileHandler(config[k1]["logfile"],
  95                                                                     maxBytes=100e6, backupCount=9, delay=0)
  96                 file_handler.setFormatter(log_formatter_simple)
  97                 logger_module.addHandler(file_handler)
  98             if config[k1].get("loglevel"):
  99                 logger_module.setLevel(config[k1]["loglevel"])
 100         self.logger.critical("starting osm/lcm version {} {}".format(lcm_version, lcm_version_date))
 101
 102         # check version of N2VC
 103         # TODO enhance with int conversion or from distutils.version import LooseVersion
 104         # or with list(map(int, version.split(".")))
 105         if versiontuple(n2vc_version) < versiontuple(min_n2vc_version):
 106             raise LcmException("Not compatible osm/N2VC version '{}'. Needed '{}' or higher".format(
 107                 n2vc_version, min_n2vc_version))
 108         # check version of common
 109         if versiontuple(common_version) < versiontuple(min_common_version):
 110             raise LcmException("Not compatible osm/common version '{}'. Needed '{}' or higher".format(
 111                 common_version, min_common_version))
 112
 113         try:
 114             # TODO check database version
 115             if config["database"]["driver"] == "mongo":
 116                 self.db = dbmongo.DbMongo()
 117                 self.db.db_connect(config["database"])
 118             elif config["database"]["driver"] == "memory":
 119                 self.db = dbmemory.DbMemory()
 120                 self.db.db_connect(config["database"])
 121             else:
 122                 raise LcmException("Invalid configuration param '{}' at '[database]':'driver'".format(
 123                     config["database"]["driver"]))
 124
 125             if config["storage"]["driver"] == "local":
 126                 self.fs = fslocal.FsLocal()
 127                 self.fs.fs_connect(config["storage"])
 128             else:
 129                 raise LcmException("Invalid configuration param '{}' at '[storage]':'driver'".format(
 130                     config["storage"]["driver"]))
 131
 132             if config["message"]["driver"] == "local":
 133                 self.msg = msglocal.MsgLocal()
 134                 self.msg.connect(config["message"])
 135             elif config["message"]["driver"] == "kafka":
 136                 self.msg = msgkafka.MsgKafka()
 137                 self.msg.connect(config["message"])
 138             else:
 139                 raise LcmException("Invalid configuration param '{}' at '[message]':'driver'".format(
 140                     config["storage"]["driver"]))
 141         except (DbException, FsException, MsgException) as e:
 142             self.logger.critical(str(e), exc_info=True)
 143             raise LcmException(str(e))
 144
 145         self.ns = ns.NsLcm(self.db, self.msg, self.fs, self.lcm_tasks, self.ro_config, self.vca_config, self.loop)
 146         self.netslice = netslice.NetsliceLcm(self.db, self.msg, self.fs, self.lcm_tasks, self.ro_config,
 147                                              self.vca_config, self.loop)
 148         self.vim = vim_sdn.VimLcm(self.db, self.msg, self.fs, self.lcm_tasks, self.ro_config, self.loop)
 149         self.sdn = vim_sdn.SdnLcm(self.db, self.msg, self.fs, self.lcm_tasks, self.ro_config, self.loop)
 150
 151     async def check_RO_version(self):
 152         try:
 153             RO = ROclient.ROClient(self.loop, **self.ro_config)
 154             RO_version = await RO.get_version()
 155             if RO_version < min_RO_version:
 156                 raise LcmException("Not compatible osm/RO version '{}.{}.{}'. Needed '{}.{}.{}' or higher".format(
 157                     *RO_version, *min_RO_version
 158                 ))
 159         except ROclient.ROClientException as e:
 160             error_text = "Error while conneting to osm/RO " + str(e)
 161             self.logger.critical(error_text, exc_info=True)
 162             raise LcmException(error_text)
 163
 164     async def test(self, param=None):
 165         self.logger.debug("Starting/Ending test task: {}".format(param))
 166
 167     async def kafka_ping(self):
 168         self.logger.debug("Task kafka_ping Enter")
 169         consecutive_errors = 0
 170         first_start = True
 171         kafka_has_received = False
 172         self.pings_not_received = 1
 173         while True:
 174             try:
 175                 await self.msg.aiowrite("admin", "ping", {"from": "lcm", "to": "lcm"}, self.loop)
 176                 # time between pings are low when it is not received and at starting
 177                 wait_time = self.ping_interval_boot if not kafka_has_received else self.ping_interval_pace
 178                 if not self.pings_not_received:
 179                     kafka_has_received = True
 180                 self.pings_not_received += 1
 181                 await asyncio.sleep(wait_time, loop=self.loop)
 182                 if self.pings_not_received > 10:
 183                     raise LcmException("It is not receiving pings from Kafka bus")
 184                 consecutive_errors = 0
 185                 first_start = False
 186             except LcmException:
 187                 raise
 188             except Exception as e:
 189                 # if not first_start is the first time after starting. So leave more time and wait
 190                 # to allow kafka starts
 191                 if consecutive_errors == 8 if not first_start else 30:
 192                     self.logger.error("Task kafka_read task exit error too many errors. Exception: {}".format(e))
 193                     raise
 194                 consecutive_errors += 1
 195                 self.logger.error("Task kafka_read retrying after Exception {}".format(e))
 196                 wait_time = 1 if not first_start else 5
 197                 await asyncio.sleep(wait_time, loop=self.loop)
 198
 199     async def kafka_read(self):
 200         self.logger.debug("Task kafka_read Enter")
 201         order_id = 1
 202         # future = asyncio.Future()
 203         consecutive_errors = 0
 204         first_start = True
 205         while consecutive_errors < 10:
 206             try:
 207                 topics = ("admin", "ns", "vim_account", "sdn", "nsi")
 208                 topic, command, params = await self.msg.aioread(topics, self.loop)
 209                 if topic != "admin" and command != "ping":
 210                     self.logger.debug("Task kafka_read receives {} {}: {}".format(topic, command, params))
 211                 consecutive_errors = 0
 212                 first_start = False
 213                 order_id += 1
 214                 if command == "exit":
 215                     print("Bye!")
 216                     break
 217                 elif command.startswith("#"):
 218                     continue
 219                 elif command == "echo":
 220                     # just for test
 221                     print(params)
 222                     sys.stdout.flush()
 223                     continue
 224                 elif command == "test":
 225                     asyncio.Task(self.test(params), loop=self.loop)
 226                     continue
 227
 228                 if topic == "admin":
 229                     if command == "ping" and params["to"] == "lcm" and params["from"] == "lcm":
 230                         self.pings_not_received = 0
 231                     continue
 232                 elif topic == "ns":
 233                     if command == "instantiate":
 234                         # self.logger.debug("Deploying NS {}".format(nsr_id))
 235                         nslcmop = params
 236                         nslcmop_id = nslcmop["_id"]
 237                         nsr_id = nslcmop["nsInstanceId"]
 238                         task = asyncio.ensure_future(self.ns.instantiate(nsr_id, nslcmop_id))
 239                         self.lcm_tasks.register("ns", nsr_id, nslcmop_id, "ns_instantiate", task)
 240                         continue
 241                     elif command == "terminate":
 242                         # self.logger.debug("Deleting NS {}".format(nsr_id))
 243                         nslcmop = params
 244                         nslcmop_id = nslcmop["_id"]
 245                         nsr_id = nslcmop["nsInstanceId"]
 246                         self.lcm_tasks.cancel(topic, nsr_id)
 247                         task = asyncio.ensure_future(self.ns.terminate(nsr_id, nslcmop_id))
 248                         self.lcm_tasks.register("ns", nsr_id, nslcmop_id, "ns_terminate", task)
 249                         continue
 250                     elif command == "action":
 251                         # self.logger.debug("Update NS {}".format(nsr_id))
 252                         nslcmop = params
 253                         nslcmop_id = nslcmop["_id"]
 254                         nsr_id = nslcmop["nsInstanceId"]
 255                         task = asyncio.ensure_future(self.ns.action(nsr_id, nslcmop_id))
 256                         self.lcm_tasks.register("ns", nsr_id, nslcmop_id, "ns_action", task)
 257                         continue
 258                     elif command == "scale":
 259                         # self.logger.debug("Update NS {}".format(nsr_id))
 260                         nslcmop = params
 261                         nslcmop_id = nslcmop["_id"]
 262                         nsr_id = nslcmop["nsInstanceId"]
 263                         task = asyncio.ensure_future(self.ns.scale(nsr_id, nslcmop_id))
 264                         self.lcm_tasks.register("ns", nsr_id, nslcmop_id, "ns_scale", task)
 265                         continue
 266                     elif command == "show":
 267                         try:
 268                             db_nsr = self.db.get_one("nsrs", {"_id": nsr_id})
 269                             print("nsr:\n    _id={}\n    operational-status: {}\n    config-status: {}"
 270                                   "\n    detailed-status: {}\n    deploy: {}\n    tasks: {}"
 271                                   "".format(nsr_id, db_nsr["operational-status"], db_nsr["config-status"],
 272                                             db_nsr["detailed-status"],
 273                                             db_nsr["_admin"]["deployed"], self.lcm_ns_tasks.get(nsr_id)))
 274                         except Exception as e:
 275                             print("nsr {} not found: {}".format(nsr_id, e))
 276                         sys.stdout.flush()
 277                         continue
 278                     elif command == "deleted":
 279                         continue  # TODO cleaning of task just in case should be done
 280                     elif command in ("terminated", "instantiated", "scaled", "actioned"):  # "scaled-cooldown-time"
 281                         continue
 282                 elif topic == "nsi":  # netslice LCM processes (instantiate, terminate, etc)
 283                     if command == "instantiate":
 284                         # self.logger.debug("Instantiating Network Slice {}".format(nsilcmop["netsliceInstanceId"]))
 285                         nsilcmop = params
 286                         nsilcmop_id = nsilcmop["_id"]                               # slice operation id
 287                         nsir_id = nsilcmop["netsliceInstanceId"]                    # slice record id
 288                         task = asyncio.ensure_future(self.netslice.instantiate(nsir_id, nsilcmop_id))
 289                         self.lcm_tasks.register("nsi", nsir_id, nsilcmop_id, "nsi_instantiate", task)
 290                         continue
 291                     elif command == "terminate":
 292                         # self.logger.debug("Terminating Network Slice NS {}".format(nsilcmop["netsliceInstanceId"]))
 293                         nsilcmop = params
 294                         nsilcmop_id = nsilcmop["_id"]                               # slice operation id
 295                         nsir_id = nsilcmop["netsliceInstanceId"]                    # slice record id
 296                         self.lcm_tasks.cancel(topic, nsir_id)
 297                         task = asyncio.ensure_future(self.netslice.terminate(nsir_id, nsilcmop_id))
 298                         self.lcm_tasks.register("nsi", nsir_id, nsilcmop_id, "nsi_terminate", task)
 299                         continue
 300                     elif command == "show":
 301                         try:
 302                             db_nsir = self.db.get_one("nsirs", {"_id": nsir_id})
 303                             print("nsir:\n    _id={}\n    operational-status: {}\n    config-status: {}"
 304                                   "\n    detailed-status: {}\n    deploy: {}\n    tasks: {}"
 305                                   "".format(nsir_id, db_nsir["operational-status"], db_nsir["config-status"],
 306                                             db_nsir["detailed-status"],
 307                                             db_nsir["_admin"]["deployed"], self.lcm_netslice_tasks.get(nsir_id)))
 308                         except Exception as e:
 309                             print("nsir {} not found: {}".format(nsir_id, e))
 310                         sys.stdout.flush()
 311                         continue
 312                     elif command == "deleted":
 313                         continue  # TODO cleaning of task just in case should be done
 314                     elif command in ("terminated", "instantiated", "scaled", "actioned"):  # "scaled-cooldown-time"
 315                         continue
 316                 elif topic == "vim_account":
 317                     vim_id = params["_id"]
 318                     if command == "create":
 319                         task = asyncio.ensure_future(self.vim.create(params, order_id))
 320                         self.lcm_tasks.register("vim_account", vim_id, order_id, "vim_create", task)
 321                         continue
 322                     elif command == "delete":
 323                         self.lcm_tasks.cancel(topic, vim_id)
 324                         task = asyncio.ensure_future(self.vim.delete(vim_id, order_id))
 325                         self.lcm_tasks.register("vim_account", vim_id, order_id, "vim_delete", task)
 326                         continue
 327                     elif command == "show":
 328                         print("not implemented show with vim_account")
 329                         sys.stdout.flush()
 330                         continue
 331                     elif command == "edit":
 332                         task = asyncio.ensure_future(self.vim.edit(params, order_id))
 333                         self.lcm_tasks.register("vim_account", vim_id, order_id, "vim_edit", task)
 334                         continue
 335                 elif topic == "sdn":
 336                     _sdn_id = params["_id"]
 337                     if command == "create":
 338                         task = asyncio.ensure_future(self.sdn.create(params, order_id))
 339                         self.lcm_tasks.register("sdn", _sdn_id, order_id, "sdn_create", task)
 340                         continue
 341                     elif command == "delete":
 342                         self.lcm_tasks.cancel(topic, _sdn_id)
 343                         task = asyncio.ensure_future(self.sdn.delete(_sdn_id, order_id))
 344                         self.lcm_tasks.register("sdn", _sdn_id, order_id, "sdn_delete", task)
 345                         continue
 346                     elif command == "edit":
 347                         task = asyncio.ensure_future(self.sdn.edit(params, order_id))
 348                         self.lcm_tasks.register("sdn", _sdn_id, order_id, "sdn_edit", task)
 349                         continue
 350                 self.logger.critical("unknown topic {} and command '{}'".format(topic, command))
 351             except Exception as e:
 352                 # if not first_start is the first time after starting. So leave more time and wait
 353                 # to allow kafka starts
 354                 if consecutive_errors == 8 if not first_start else 30:
 355                     self.logger.error("Task kafka_read task exit error too many errors. Exception: {}".format(e))
 356                     raise
 357                 consecutive_errors += 1
 358                 self.logger.error("Task kafka_read retrying after Exception {}".format(e))
 359                 wait_time = 2 if not first_start else 5
 360                 await asyncio.sleep(wait_time, loop=self.loop)
 361
 362         # self.logger.debug("Task kafka_read terminating")
 363         self.logger.debug("Task kafka_read exit")
 364
 365     def health_check(self):
 366
 367         global exit_code
 368         task = None
 369         exit_code = 1
 370
 371         def health_check_callback(topic, command, params):
 372             global exit_code
 373             print("receiving callback {} {} {}".format(topic, command, params))
 374             if topic == "admin" and command == "ping" and params["to"] == "lcm" and params["from"] == "lcm":
 375                 # print("received LCM ping")
 376                 exit_code = 0
 377                 task.cancel()
 378
 379         try:
 380             task = asyncio.ensure_future(self.msg.aioread(("admin",), self.loop, health_check_callback))
 381             self.loop.run_until_complete(task)
 382         except Exception:
 383             pass
 384         exit(exit_code)
 385
 386     def start(self):
 387
 388         # check RO version
 389         self.loop.run_until_complete(self.check_RO_version())
 390
 391         self.loop.run_until_complete(asyncio.gather(
 392             self.kafka_read(),
 393             self.kafka_ping()
 394         ))
 395         # TODO
 396         # self.logger.debug("Terminating cancelling creation tasks")
 397         # self.lcm_tasks.cancel("ALL", "create")
 398         # timeout = 200
 399         # while self.is_pending_tasks():
 400         #     self.logger.debug("Task kafka_read terminating. Waiting for tasks termination")
 401         #     await asyncio.sleep(2, loop=self.loop)
 402         #     timeout -= 2
 403         #     if not timeout:
 404         #         self.lcm_tasks.cancel("ALL", "ALL")
 405         self.loop.close()
 406         self.loop = None
 407         if self.db:
 408             self.db.db_disconnect()
 409         if self.msg:
 410             self.msg.disconnect()
 411         if self.fs:
 412             self.fs.fs_disconnect()
 413
 414     def read_config_file(self, config_file):
 415         # TODO make a [ini] + yaml inside parser
 416         # the configparser library is not suitable, because it does not admit comments at the end of line,
 417         # and not parse integer or boolean
 418         try:
 419             with open(config_file) as f:
 420                 conf = yaml.load(f)
 421             for k, v in environ.items():
 422                 if not k.startswith("OSMLCM_"):
 423                     continue
 424                 k_items = k.lower().split("_")
 425                 if len(k_items) < 3:
 426                     continue
 427                 if k_items[1] in ("ro", "vca"):
 428                     # put in capital letter
 429                     k_items[1] = k_items[1].upper()
 430                 c = conf
 431                 try:
 432                     for k_item in k_items[1:-1]:
 433                         c = c[k_item]
 434                     if k_items[-1] == "port":
 435                         c[k_items[-1]] = int(v)
 436                     else:
 437                         c[k_items[-1]] = v
 438                 except Exception as e:
 439                     self.logger.warn("skipping environ '{}' on exception '{}'".format(k, e))
 440
 441             return conf
 442         except Exception as e:
 443             self.logger.critical("At config file '{}': {}".format(config_file, e))
 444             exit(1)
 445
 446
 447 def usage():
 448     print("""Usage: {} [options]
 449         -c|--config [configuration_file]: loads the configuration file (default: ./nbi.cfg)
 450         --health-check: do not run lcm, but inspect kafka bus to determine if lcm is healthy
 451         -h|--help: shows this help
 452         """.format(sys.argv[0]))
 453     # --log-socket-host HOST: send logs to this host")
 454     # --log-socket-port PORT: send logs using this port (default: 9022)")
 455
 456
 457 if __name__ == '__main__':
 458     try:
 459         # load parameters and configuration
 460         opts, args = getopt.getopt(sys.argv[1:], "hc:", ["config=", "help", "health-check"])
 461         # TODO add  "log-socket-host=", "log-socket-port=", "log-file="
 462         config_file = None
 463         health_check = None
 464         for o, a in opts:
 465             if o in ("-h", "--help"):
 466                 usage()
 467                 sys.exit()
 468             elif o in ("-c", "--config"):
 469                 config_file = a
 470             elif o == "--health-check":
 471                 health_check = True
 472             # elif o == "--log-socket-port":
 473             #     log_socket_port = a
 474             # elif o == "--log-socket-host":
 475             #     log_socket_host = a
 476             # elif o == "--log-file":
 477             #     log_file = a
 478             else:
 479                 assert False, "Unhandled option"
 480         if config_file:
 481             if not path.isfile(config_file):
 482                 print("configuration file '{}' not exist".format(config_file), file=sys.stderr)
 483                 exit(1)
 484         else:
 485             for config_file in (__file__[:__file__.rfind(".")] + ".cfg", "./lcm.cfg", "/etc/osm/lcm.cfg"):
 486                 if path.isfile(config_file):
 487                     break
 488             else:
 489                 print("No configuration file 'lcm.cfg' found neither at local folder nor at /etc/osm/", file=sys.stderr)
 490                 exit(1)
 491         lcm = Lcm(config_file)
 492         if health_check:
 493             lcm.health_check()
 494         else:
 495             lcm.start()
 496     except (LcmException, getopt.GetoptError) as e:
 497         print(str(e), file=sys.stderr)
 498         # usage()
 499         exit(1)