lightweight exception capturing, logging 46/5846/6 v3.0.3
authortierno <alfonso.tiernosepulveda@telefonica.com>
Tue, 6 Feb 2018 22:17:16 +0000 (23:17 +0100)
committertierno <alfonso.tiernosepulveda@telefonica.com>
Fri, 16 Feb 2018 12:42:51 +0000 (13:42 +0100)
Change-Id: I5933d3982775f97000e2e8b60f5fad1bff16d34a
Signed-off-by: tierno <alfonso.tiernosepulveda@telefonica.com>
13 files changed:
lcm/Dockerfile
lcm/osm_common/dbbase.py
lcm/osm_common/dbmemory.py
lcm/osm_common/dbmongo.py
lcm/osm_common/fsbase.py
lcm/osm_common/fslocal.py
lcm/osm_common/msgbase.py
lcm/osm_common/msgkafka.py
lcm/osm_common/msglocal.py
lcm/osm_lcm/ROclient.py
lcm/osm_lcm/lcm.cfg
lcm/osm_lcm/lcm.py
lcm/osm_lcm/vca.py

index 15e14ef..b603c13 100644 (file)
@@ -8,15 +8,15 @@ ADD . /app
 
 RUN apt-get update && apt-get install -y git  python3 \
     python3-pip python3-pymongo python3-yaml python3-aiohttp \
-    && pip3 install aiokafka \
+    && pip3 install aiokafka juju \
     && mkdir -p /app/storage/kafka && mkdir -p /app/log 
 
 
 
 LABEL Maintainer="alfonso.tiernosepulveda@telefonica.com" \
       Description="This implements a north bound interface for OSM" \
-      Version="1.0"
-      Author="Alfonso Tierno"
+      Version="1.0" \
+      Author="Alfonso Tierno"
 
 # Used for local storage
 VOLUME /app/storage
index a2768ae..b101cb4 100644 (file)
@@ -1,14 +1,17 @@
+from http import HTTPStatus
+
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
 
 
 class DbException(Exception):
 
-    def __init__(self, message, http_code=404):
+    def __init__(self, message, http_code=HTTPStatus.NOT_FOUND):
         # TODO change to http.HTTPStatus instead of int that allows .value and .name
         self.http_code = http_code
-        Exception.__init__(self, message)
+        Exception.__init__(self, "database exception " + message)
 
 
-class dbbase(object):
+class DbBase(object):
 
     def __init__(self):
         pass
index 75d1f88..cdb0482 100644 (file)
@@ -1,14 +1,22 @@
-from dbbase import DbException, dbbase
+import logging
+from dbbase import DbException, DbBase
 from http import HTTPStatus
 from uuid import uuid4
 from copy import deepcopy
 
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
 
-class dbmemory(dbbase):
 
-    def __init__(self):
+class DbMemory(DbBase):
+
+    def __init__(self, logger_name='db'):
+        self.logger = logging.getLogger(logger_name)
         self.db = {}
 
+    def db_connect(self, config):
+        if "logger_name" in config:
+            self.logger = logging.getLogger(config["logger_name"])
+
     @staticmethod
     def _format_filter(filter):
         return filter    # TODO
@@ -45,7 +53,7 @@ class dbmemory(dbbase):
                                       HTTPStatus.CONFLICT.value)
                 l = row
             if not l and fail_on_empty:
-                raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
             return deepcopy(l)
         except Exception as e:  # TODO refine
             raise DbException(str(e))
@@ -70,7 +78,7 @@ class dbmemory(dbbase):
                 break
             else:
                 if fail_on_empty:
-                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
                 return None
             del self.db[table][i]
             return {"deleted": 1}
@@ -83,7 +91,7 @@ class dbmemory(dbbase):
                 break
             else:
                 if fail_on_empty:
-                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
                 return None
             self.db[table][i] = deepcopy(indata)
             return {"upadted": 1}
index 38454b3..34e6faf 100644 (file)
@@ -1,20 +1,40 @@
 #import pymongo
-from pymongo import MongoClient
-from dbbase import DbException, dbbase
+import logging
+from pymongo import MongoClient, errors
+from dbbase import DbException, DbBase
 from http import HTTPStatus
+from time import time, sleep
 
-class dbmongo(dbbase):
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
 
-    def __init__(self):
-        pass
+
+class DbMongo(DbBase):
+    conn_initial_timout = 120
+    conn_timout = 10
+
+    def __init__(self, logger_name='db'):
+        self.logger = logging.getLogger(logger_name)
 
     def db_connect(self, config):
         try:
+            if "logger_name" in config:
+                self.logger = logging.getLogger(config["logger_name"])
             self.client = MongoClient(config["host"], config["port"])
             self.db = self.client[config["name"]]
+            if "loglevel" in config:
+                self.logger.setLevel(getattr(logging, config['loglevel']))
             # get data to try a connection
-            self.db.users.find_one({"username": "admin"})
-        except Exception as e:  # TODO refine
+            now = time()
+            while True:
+                try:
+                    self.db.users.find_one({"username": "admin"})
+                    return
+                except errors.ConnectionFailure as e:
+                    if time() - now >= self.conn_initial_timout:
+                        raise
+                    self.logger.info("Waiting to database up {}".format(e))
+                    sleep(2)
+        except errors.PyMongoError as e:
             raise DbException(str(e))
 
     def db_disconnect(self):
@@ -62,7 +82,7 @@ class dbmongo(dbbase):
             return db_filter
         except Exception as e:
             raise DbException("Invalid query string filter at {}:{}. Error: {}".format(query_k, v, e),
-                              http_code=HTTPStatus.BAD_REQUEST.value)
+                              http_code=HTTPStatus.BAD_REQUEST)
 
 
     def get_list(self, table, filter={}):
@@ -88,12 +108,12 @@ class dbmongo(dbbase):
             rows = collection.find(filter)
             if rows.count() == 0:
                 if fail_on_empty:
-                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
                 return None
             elif rows.count() > 1:
                 if fail_on_more:
                     raise DbException("Found more than one entry with filter='{}'".format(filter),
-                                      HTTPStatus.CONFLICT.value)
+                                      HTTPStatus.CONFLICT)
             return rows[0]
         except Exception as e:  # TODO refine
             raise DbException(str(e))
@@ -114,7 +134,7 @@ class dbmongo(dbbase):
             rows = collection.delete_one(self._format_filter(filter))
             if rows.deleted_count == 0:
                 if fail_on_empty:
-                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
                 return None
             return {"deleted": rows.deleted_count}
         except Exception as e:  # TODO refine
@@ -134,7 +154,7 @@ class dbmongo(dbbase):
             rows = collection.update_one(self._format_filter(filter), {"$set": update_dict})
             if rows.updated_count == 0:
                 if fail_on_empty:
-                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
                 return None
             return {"deleted": rows.deleted_count}
         except Exception as e:  # TODO refine
@@ -146,7 +166,7 @@ class dbmongo(dbbase):
             rows = collection.replace_one({"_id": id}, indata)
             if rows.modified_count == 0:
                 if fail_on_empty:
-                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND.value)
+                    raise DbException("Not found entry with filter='{}'".format(filter), HTTPStatus.NOT_FOUND)
                 return None
             return {"replace": rows.modified_count}
         except Exception as e:  # TODO refine
index 85562bd..7b6cd0c 100644 (file)
@@ -1,13 +1,16 @@
 
-class FsException(Exception):
+from http import HTTPStatus
+
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
+
 
-    def __init__(self, message, http_code=404):
+class FsException(Exception):
+    def __init__(self, message, http_code=HTTPStatus.INTERNAL_SERVER_ERROR):
         self.http_code = http_code
-        Exception.__init__(self, message)
+        Exception.__init__(self, "storage exception " + message)
 
 
 class FsBase(object):
-
     def __init__(self):
         pass
 
index b88475f..10ddf73 100644 (file)
@@ -1,13 +1,17 @@
 import os
+import logging
 import tarfile
 from http import HTTPStatus
 from shutil import rmtree
 from fsbase import FsBase, FsException
 
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
+
 
 class FsLocal(FsBase):
 
-    def __init__(self):
+    def __init__(self, logger_name='fs'):
+        self.logger = logging.getLogger(logger_name)
         self.path = None
 
     def get_params(self):
@@ -15,6 +19,8 @@ class FsLocal(FsBase):
 
     def fs_connect(self, config):
         try:
+            if "logger_name" in config:
+                self.logger = logging.getLogger(config["logger_name"])
             self.path = config["path"]
             if not self.path.endswith("/"):
                 self.path += "/"
@@ -38,7 +44,7 @@ class FsLocal(FsBase):
         try:
             os.mkdir(self.path + folder)
         except Exception as e:
-            raise FsException(str(e), http_code=HTTPStatus.INTERNAL_SERVER_ERROR.value)
+            raise FsException(str(e), http_code=HTTPStatus.INTERNAL_SERVER_ERROR)
 
     def file_exists(self, storage):
         """
@@ -105,4 +111,4 @@ class FsLocal(FsBase):
         if os.path.exists(f):
             rmtree(f)
         elif not ignore_non_exist:
-            raise FsException("File {} does not exist".format(storage), http_code=HTTPStatus.BAD_REQUEST.value)
+            raise FsException("File {} does not exist".format(storage), http_code=HTTPStatus.BAD_REQUEST)
index 745df7f..a105414 100644 (file)
@@ -1,6 +1,8 @@
 
 from http import HTTPStatus
 
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
+
 
 class MsgException(Exception):
     """
@@ -14,7 +16,7 @@ class MsgException(Exception):
         :param http_code: <http.HTTPStatus> type. It contains ".value" (http error code) and ".name" (http error name
         """
         self.http_code = http_code
-        Exception.__init__(self, message)
+        Exception.__init__(self, "messaging exception " + message)
 
 
 class MsgBase(object):
index f350745..90c9c7f 100644 (file)
@@ -1,13 +1,16 @@
+import logging
+import asyncio
+import yaml
 from aiokafka import AIOKafkaConsumer
 from aiokafka import AIOKafkaProducer
 from aiokafka.errors import KafkaError
 from msgbase import MsgBase, MsgException
-import asyncio
-import yaml
 #import json
 
+
 class MsgKafka(MsgBase):
-    def __init__(self):
+    def __init__(self, logger_name='msg'):
+        self.logger = logging.getLogger(logger_name)
         self.host = None
         self.port = None
         self.consumer = None
@@ -17,6 +20,8 @@ class MsgKafka(MsgBase):
 
     def connect(self, config):
         try:
+            if "logger_name" in config:
+                self.logger = logging.getLogger(config["logger_name"])
             self.host = config["host"]
             self.port = config["port"]
             self.topic_lst = []
index a380e61..238ee35 100644 (file)
@@ -1,18 +1,24 @@
+import logging
 import os
 import yaml
 import asyncio
 from msgbase import MsgBase, MsgException
 
+__author__ = "Alfonso Tierno <alfonso.tiernosepulveda@telefonica.com>"
 
-class msgLocal(MsgBase):
 
-    def __init__(self):
+class MsgLocal(MsgBase):
+
+    def __init__(self, logger_name='msg'):
+        self.logger = logging.getLogger(logger_name)
         self.path = None
         # create a different file for each topic
         self.files = {}
 
     def connect(self, config):
         try:
+            if "logger_name" in config:
+                self.logger = logging.getLogger(config["logger_name"])
             self.path = config["path"]
             if not self.path.endswith("/"):
                 self.path += "/"
@@ -48,9 +54,16 @@ class msgLocal(MsgBase):
 
     def read(self, topic):
         try:
+            msg = ""
             if topic not in self.files:
-                self.files[topic] = open(self.path + topic, "r+")
-            msg = self.files[topic].read()
+                self.files[topic] = open(self.path + topic, "a+")
+                # ignore previous content
+                for line in self.files[topic]:
+                    if not line.endswith("\n"):
+                        msg = line
+            msg += self.files[topic].readline()
+            if not msg.endswith("\n"):
+                return None
             msg_dict = yaml.load(msg)
             assert len(msg_dict) == 1
             for k, v in msg_dict.items():
@@ -60,16 +73,18 @@ class msgLocal(MsgBase):
 
     async def aioread(self, topic, loop=None):
         try:
+            msg = ""
             if not loop:
                 loop = asyncio.get_event_loop()
             if topic not in self.files:
-                self.files[topic] = open(self.path + topic, "r+")
+                self.files[topic] = open(self.path + topic, "a+")
                 # ignore previous content
-                while self.files[topic].read():
-                    pass
+                for line in self.files[topic]:
+                    if not line.endswith("\n"):
+                        msg = line
             while True:
-                msg = self.files[topic].read()
-                if msg:
+                msg += self.files[topic].readline()
+                if msg.endswith("\n"):
                     break
                 await asyncio.sleep(2, loop=loop)
             msg_dict = yaml.load(msg)
index bbea5fe..ecaa950 100644 (file)
@@ -35,6 +35,7 @@ import logging
 import sys
 from urllib.parse import quote
 from uuid import UUID
+from copy import deepcopy
 
 __author__ = "Alfonso Tierno, Pablo Montes"
 __date__ = "$09-Jan-2018 09:09:48$"
@@ -125,9 +126,10 @@ class ROClient:
         self.tenant = None
         self.datacenter_id_name = kwargs.get("datacenter")
         self.datacenter = None
-        self.logger = logging.getLogger(kwargs.get('logger', 'ROClient'))
-        if kwargs.get("debug"):
-            self.logger.setLevel(logging.DEBUG)
+        logger_name = kwargs.get('logger_name', 'ROClient')
+        self.logger = logging.getLogger(logger_name)
+        if kwargs.get("loglevel"):
+            self.logger.setLevel(kwargs["loglevel"])
         global requests
         requests = kwargs.get("TODO remove")
 
@@ -286,21 +288,24 @@ class ROClient:
         :param filter_by: dictionary with filtering
         :return: a list of dict. It can be empty. Raises ROClientException on Error,
         """
-        if item not in self.client_to_RO:
-            raise ROClientException("Invalid item {}".format(item))
-        if item == 'tenant':
-            all_tenants = None
-        with aiohttp.ClientSession(loop=self.loop) as session:
-            content = await self._list_item(session, self.client_to_RO[item], all_tenants=all_tenants,
-                                            filter_dict=filter_by)
-        if isinstance(content, dict):
-            if len(content) == 1:
-                for _, v in content.items():
-                    return v
-                return content.values()[0]
-            else:
-                raise ROClientException("Output not a list neither dict with len equal 1", http_code=500)
-            return content
+        try:
+            if item not in self.client_to_RO:
+                raise ROClientException("Invalid item {}".format(item))
+            if item == 'tenant':
+                all_tenants = None
+            with aiohttp.ClientSession(loop=self.loop) as session:
+                content = await self._list_item(session, self.client_to_RO[item], all_tenants=all_tenants,
+                                                filter_dict=filter_by)
+            if isinstance(content, dict):
+                if len(content) == 1:
+                    for _, v in content.items():
+                        return v
+                    return content.values()[0]
+                else:
+                    raise ROClientException("Output not a list neither dict with len equal 1", http_code=500)
+                return content
+        except aiohttp.errors.ClientOSError as e:
+            raise ROClientException(e, http_code=504)
 
     async def _get_item_uuid(self, session, item, item_id_name, all_tenants=False):
         if all_tenants:
@@ -510,17 +515,20 @@ class ROClient:
         :param all_tenants: True if not filtering by tenant. Only allowed for admin
         :return: dictionary with the information or raises ROClientException on Error, NotFound, found several
         """
-        if item not in self.client_to_RO:
-            raise ROClientException("Invalid item {}".format(item))
-        if item == 'tenant':
-            all_tenants = None
-
-        with aiohttp.ClientSession(loop=self.loop) as session:
-            content = await self._get_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants)
-        if len(content) == 1:
-            return content.values()[0]
-        else:
-            return content
+        try:
+            if item not in self.client_to_RO:
+                raise ROClientException("Invalid item {}".format(item))
+            if item == 'tenant':
+                all_tenants = None
+
+            with aiohttp.ClientSession(loop=self.loop) as session:
+                content = await self._get_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants)
+            if len(content) == 1:
+                return content.values()[0]
+            else:
+                return content
+        except aiohttp.errors.ClientOSError as e:
+            raise ROClientException(e, http_code=504)
 
     async def delete(self, item, item_id_name=None, all_tenants=False):
         """
@@ -530,17 +538,20 @@ class ROClient:
         :param all_tenants: True if not filtering by tenant. Only allowed for admin
         :return: dictionary with the information or raises ROClientException on Error, NotFound, found several
         """
-        if item not in self.client_to_RO:
-            raise ROClientException("Invalid item {}".format(item))
-        if item == 'tenant':
-            all_tenants = None
-
-        with aiohttp.ClientSession(loop=self.loop) as session:
-            if item == 'vim':
-                # check that exist
-                item_id = await self._get_item_uuid(session, "datacenters", item_id_name, all_tenants=True)
+        try:
+            if item not in self.client_to_RO:
+                raise ROClientException("Invalid item {}".format(item))
+            if item == 'tenant':
                 all_tenants = None
-            return await self._del_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants)
+
+            with aiohttp.ClientSession(loop=self.loop) as session:
+                if item == 'vim':
+                    # check that exist
+                    item_id = await self._get_item_uuid(session, "datacenters", item_id_name, all_tenants=True)
+                    all_tenants = None
+                return await self._del_item(session, self.client_to_RO[item], item_id_name, all_tenants=all_tenants)
+        except aiohttp.errors.ClientOSError as e:
+            raise ROClientException(e, http_code=504)
 
     async def create(self, item, descriptor=None, descriptor_format=None, **kwargs):
         """
@@ -552,60 +563,67 @@ class ROClient:
                keys can be a dot separated list to specify elements inside dict
         :return: dictionary with the information or raises ROClientException on Error
         """
-        if isinstance(descriptor, str):
-            descriptor = self._parse(descriptor, descriptor_format)
-        elif descriptor:
-            pass
-        else:
-            descriptor = {}
-
-        if item not in self.client_to_RO:
-            raise ROClientException("Invalid item {}".format(item))
-        desc, enveloped = remove_envelop(item, descriptor)
-
-        # Override descriptor with kwargs
-        if kwargs:
-            try:
-                for k, v in kwargs.items():
-                    update_content = desc
-                    kitem_old = None
-                    klist = k.split(".")
-                    for kitem in klist:
-                        if kitem_old is not None:
-                            update_content = update_content[kitem_old]
-                        if isinstance(update_content, dict):
-                            kitem_old = kitem
-                        elif isinstance(update_content, list):
-                            kitem_old = int(kitem)
+        try:
+            if isinstance(descriptor, str):
+                descriptor = self._parse(descriptor, descriptor_format)
+            elif descriptor:
+                pass
+            else:
+                descriptor = {}
+
+            if item not in self.client_to_RO:
+                raise ROClientException("Invalid item {}".format(item))
+            desc, enveloped = remove_envelop(item, descriptor)
+
+            # Override descriptor with kwargs
+            if kwargs:
+                desc = deepcopy(desc)  # do not modify original descriptor
+                try:
+                    for k, v in kwargs.items():
+                        update_content = desc
+                        kitem_old = None
+                        klist = k.split(".")
+                        for kitem in klist:
+                            if kitem_old is not None:
+                                update_content = update_content[kitem_old]
+                            if isinstance(update_content, dict):
+                                kitem_old = kitem
+                            elif isinstance(update_content, list):
+                                kitem_old = int(kitem)
+                            else:
+                                raise ROClientException(
+                                    "Invalid query string '{}'. Descriptor is not a list nor dict at '{}'".format(k, kitem))
+                        if v == "__DELETE__":
+                            del update_content[kitem_old]
                         else:
-                            raise ROClientException(
-                                "Invalid query string '{}'. Descriptor is not a list nor dict at '{}'".format(k, kitem))
-                    update_content[kitem_old] = v
-            except KeyError:
-                raise ROClientException(
-                    "Invalid query string '{}'. Descriptor does not contain '{}'".format(k, kitem_old))
-            except ValueError:
-                raise ROClientException("Invalid query string '{}'. Expected integer index list instead of '{}'".format(
-                    k, kitem))
-            except IndexError:
-                raise ROClientException(
-                    "Invalid query string '{}'. Index '{}' out of  range".format(k, kitem_old))
-
-        for mandatory in self.mandatory_for_create[item]:
-            if mandatory not in desc:
-                raise ROClientException("'{}' is mandatory parameter for {}".format(mandatory, item))
-
-        all_tenants = False
-        if item in ('tenant', 'vim'):
-            all_tenants = None
+                            update_content[kitem_old] = v
+                except KeyError:
+                    raise ROClientException(
+                        "Invalid query string '{}'. Descriptor does not contain '{}'".format(k, kitem_old))
+                except ValueError:
+                    raise ROClientException("Invalid query string '{}'. Expected integer index list instead of '{}'".format(
+                        k, kitem))
+                except IndexError:
+                    raise ROClientException(
+                        "Invalid query string '{}'. Index '{}' out of  range".format(k, kitem_old))
+
+            for mandatory in self.mandatory_for_create[item]:
+                if mandatory not in desc:
+                    raise ROClientException("'{}' is mandatory parameter for {}".format(mandatory, item))
+
+            all_tenants = False
+            if item in ('tenant', 'vim'):
+                all_tenants = None
 
-        if not enveloped:
-            create_desc = self._create_envelop(item, desc)
-        else:
-            create_desc = descriptor
+            if not enveloped:
+                create_desc = self._create_envelop(item, desc)
+            else:
+                create_desc = descriptor
 
-        with aiohttp.ClientSession(loop=self.loop) as session:
-            return await self._create_item(session, self.client_to_RO[item], create_desc, all_tenants)
+            with aiohttp.ClientSession(loop=self.loop) as session:
+                return await self._create_item(session, self.client_to_RO[item], create_desc, all_tenants)
+        except aiohttp.errors.ClientOSError as e:
+            raise ROClientException(e, http_code=504)
 
     def edit_tenant(self, uuid=None, name=None, descriptor=None, descriptor_format=None, new_name=None, new_description=None):
         """Edit the parameters of a tenant
@@ -618,24 +636,27 @@ class ROClient:
         Return: Raises an exception on error, not found or found several
                 Obtain a dictionary with format {'tenant':{newtenant_info}}
         """
-        # TODO revise
-        if isinstance(descriptor, str):
-            descriptor = self.parse(descriptor, descriptor_format)
-        elif descriptor:
-            pass
-        elif new_name or new_description:
-            descriptor={"tenant": {}}
-        else:
-            raise ROClientException("Missing descriptor")
+        try:
+            # TODO revise
+            if isinstance(descriptor, str):
+                descriptor = self.parse(descriptor, descriptor_format)
+            elif descriptor:
+                pass
+            elif new_name or new_description:
+                descriptor={"tenant": {}}
+            else:
+                raise ROClientException("Missing descriptor")
 
-        if 'tenant' not in descriptor or len(descriptor)!=1:
-            raise ROClientException("Descriptor must contain only one 'tenant' field")
-        if new_name:
-            descriptor['tenant']['name'] = new_name
-        if new_description:
-            descriptor['tenant']['description'] = new_description
+            if 'tenant' not in descriptor or len(descriptor)!=1:
+                raise ROClientException("Descriptor must contain only one 'tenant' field")
+            if new_name:
+                descriptor['tenant']['name'] = new_name
+            if new_description:
+                descriptor['tenant']['description'] = new_description
 
-        return self._edit_item("tenants", descriptor, uuid, name, all_tenants=None)
+            return self._edit_item("tenants", descriptor, uuid, name, all_tenants=None)
+        except aiohttp.errors.ClientOSError as e:
+            raise ROClientException(e, http_code=504)
 
     #DATACENTERS
 
@@ -867,8 +888,8 @@ class ROClient:
 
 if __name__ == '__main__':
     RO_URL = "http://localhost:9090/openmano"
-    RO_TENANT = "2c94f639-cefc-4f3a-a8f9-bbab0471946a"
-    RO_VIM = "3e70deb6-aea1-11e7-af13-080027429aaf"
+    RO_TENANT = "osm"
+    RO_VIM = "myvim"
 
     streamformat = "%(asctime)s %(name)s %(levelname)s: %(message)s"
     logging.basicConfig(format=streamformat)
index a44ee75..fdc8b69 100644 (file)
@@ -1,10 +1,10 @@
 
-# TODO currently is a pure yaml format. Transform it to [ini] style with yaml inside to be coherent with other modules
+# TODO currently is a pure yaml format. Consider to change it to [ini] style with yaml inside to be coherent with other modules
 
 #[global]
 global:
-    log_file:   ""
-    log_level:  DEBUG
+    loglevel: DEBUG
+    #logfile:  /var/log/osm/lcm.log
 
 #[RO]
 RO:
@@ -12,6 +12,8 @@ RO:
     host:   localhost
     port:   9090
     tenant: osm
+    loglevel: DEBUG
+    #logfile:  /var/log/osm/lcm-ro.log
 
 #[VCA]
 VCA:
@@ -19,6 +21,8 @@ VCA:
     port:   17070
     user:   admin
     secret:   secret
+    loglevel: DEBUG
+    #logfile:  /var/log/osm/lcm-vca.log
 
 #[database]
 database:
@@ -28,12 +32,16 @@ database:
     name:   osm
     user:   user
     password:   password
+    loglevel: DEBUG
+    #logfile:  /var/log/osm/lcm-database.log
 
 #[storage]
 storage:
     driver: local       # local filesystem
     # for local provide file path
     path:   /app/storage
+    loglevel: DEBUG
+    #logfile:  /var/log/osm/lcm-storage.log
 
 #[message]
 message:
@@ -43,3 +51,5 @@ message:
     # for kafka provide host and port
     host:   kafka
     port:   9092
+    loglevel: DEBUG
+    #logfile:  /var/log/osm/lcm-message.log
index 9bff8c1..3b4ab60 100644 (file)
@@ -9,17 +9,15 @@ import dbmongo
 import fslocal
 import msglocal
 import msgkafka
+import logging
+import functools
 from dbbase import DbException
 from fsbase import FsException
 from msgbase import MsgException
 from os import environ
-import logging
 from vca import DeployApplication, RemoveApplication
-
-#streamformat = "%(asctime)s %(name)s %(levelname)s: %(message)s"
-streamformat = "%(name)s %(levelname)s: %(message)s"
-logging.basicConfig(format=streamformat, level=logging.DEBUG)
-
+from copy import deepcopy
+from http import HTTPStatus
 
 class LcmException(Exception):
     pass
@@ -40,16 +38,52 @@ class Lcm:
         # load configuration
         config = self.read_config_file(config_file)
         self.config = config
-        self.ro_url = "http://{}:{}/openmano".format(config["RO"]["host"], config["RO"]["port"])
-        self.ro_tenant = config["RO"]["tenant"]
+        self.ro_config={
+            "endpoint_url": "http://{}:{}/openmano".format(config["RO"]["host"], config["RO"]["port"]),
+            "tenant":  config.get("tenant", "osm"),
+            "logger_name": "lcm.ROclient",
+            "loglevel": "ERROR",
+        }
         self.vca = config["VCA"]  # TODO VCA
         self.loop = None
+
+        # logging
+        log_format_simple = "%(asctime)s %(levelname)s %(name)s %(filename)s:%(lineno)s %(message)s"
+        log_formatter_simple = logging.Formatter(log_format_simple, datefmt='%Y-%m-%dT%H:%M:%S')
+        config["database"]["logger_name"] = "lcm.db"
+        config["storage"]["logger_name"] = "lcm.fs"
+        config["message"]["logger_name"] = "lcm.msg"
+        if "logfile" in config["global"]:
+            file_handler = logging.handlers.RotatingFileHandler(config["global"]["logfile"],
+                                                                maxBytes=100e6, backupCount=9, delay=0)
+            file_handler.setFormatter(log_formatter_simple)
+            self.logger.addHandler(file_handler)
+        else:
+            str_handler = logging.StreamHandler()
+            str_handler.setFormatter(log_formatter_simple)
+            self.logger.addHandler(str_handler)
+
+        if config["global"].get("loglevel"):
+            self.logger.setLevel(config["global"]["loglevel"])
+
+        # logging other modules
+        for k1, logname in {"message": "lcm.msg", "database": "lcm.db", "storage": "lcm.fs"}.items():
+            config[k1]["logger_name"] = logname
+            logger_module = logging.getLogger(logname)
+            if "logfile" in config[k1]:
+                file_handler = logging.handlers.RotatingFileHandler(config[k1]["logfile"],
+                                                                    maxBytes=100e6, backupCount=9, delay=0)
+                file_handler.setFormatter(log_formatter_simple)
+                logger_module.addHandler(file_handler)
+            if "loglevel" in config[k1]:
+                logger_module.setLevel(config[k1]["loglevel"])
+
         try:
             if config["database"]["driver"] == "mongo":
-                self.db = dbmongo.dbmongo()
+                self.db = dbmongo.DbMongo()
                 self.db.db_connect(config["database"])
             elif config["database"]["driver"] == "memory":
-                self.db = dbmemory.dbmemory()
+                self.db = dbmemory.DbMemory()
                 self.db.db_connect(config["database"])
             else:
                 raise LcmException("Invalid configuration param '{}' at '[database]':'driver'".format(
@@ -63,7 +97,7 @@ class Lcm:
                     config["storage"]["driver"]))
 
             if config["message"]["driver"] == "local":
-                self.msg = msglocal.msgLocal()
+                self.msg = msglocal.MsgLocal()
                 self.msg.connect(config["message"])
             elif config["message"]["driver"] == "kafka":
                 self.msg = msgkafka.MsgKafka()
@@ -75,92 +109,156 @@ class Lcm:
             self.logger.critical(str(e), exc_info=True)
             raise LcmException(str(e))
 
-    # def update_nsr_db(self, nsr_id, nsr_desc):
-    #    self.db.replace("nsrs", nsr_id, nsr_desc)
-
-    async def create_ns(self, nsr_id):
-        self.logger.debug("create_ns task nsr_id={} Enter".format(nsr_id))
-        db_nsr = self.db.get_one("nsrs", {"_id": nsr_id})
-        nsr_lcm = {
-            "id": nsr_id,
-            "RO": {"vnfd_id": {}, "nsd_id": None, "nsr_id": None, "nsr_status": "SCHEDULED"},
-            "nsr_ip": {},
-            "VCA": {}, # "TODO"
-        }
-        db_nsr["_admin"]["deploy"] = nsr_lcm
-        db_nsr["detailed-status"] = "creating"
-        db_nsr["operational-status"] = "init"
-
-        deloyment_timeout = 120
+    def update_nsr_db(self, nsr_id, nsr_desc):
+        try:
+            self.db.replace("nsrs", nsr_id, nsr_desc)
+        except DbException as e:
+            self.logger.error("Updating nsr_id={}: {}".format(nsr_id, e))
+
+    def vca_deploy_callback(self, db_nsr, vnf_index, status, task):
+        # TODO study using this callback when VCA.DeployApplication success from VCAMonitor
+        # By the moment this callback is used only to capture exception conditions from VCA DeployApplication
+        nsr_id = db_nsr["_id"]
+        self.logger.debug("Task create_ns={} vca_deploy_callback Enter".format(nsr_id))
+        try:
+            if task.cancelled():
+                return
+            if task.done():
+                exc = task.exception()
+                if exc:
+                    nsr_lcm = db_nsr["_admin"]["deploy"]
+                    nsr_lcm["VCA"][vnf_index]['operational-status'] = "failed"
+                    db_nsr["detailed-status"] = "fail configuring vnf_index={} {}".format(vnf_index, exc)
+                    db_nsr["config-status"] = "failed"
+                    self.update_nsr_db(nsr_id, db_nsr)
+            else:
+                # TODO may be used to be called when VCA monitor status changes
+                pass
+        # except DbException as e:
+        #     self.logger.error("Task create_ns={} vca_deploy_callback Exception {}".format(nsr_id, e))
+        except Exception as e:
+            self.logger.critical("Task create_ns={} vca_deploy_callback Exception {}".format(nsr_id, e), exc_info=True)
+
+    async def create_ns(self, nsr_id, order_id):
+        logging_text = "Task create_ns={} ".format(nsr_id)
+        self.logger.debug(logging_text + "Enter")
+        # get all needed from database
+        db_nsr = None
+        exc = None
+        step = "Getting nsr from db"
         try:
+            db_nsr = self.db.get_one("nsrs", {"_id": nsr_id})
             nsd = db_nsr["nsd"]
-            RO = ROclient.ROClient(self.loop, endpoint_url=self.ro_url, tenant=self.ro_tenant,
-                                   datacenter=db_nsr["datacenter"])
-
-            # get vnfds, instantiate at RO
+            needed_vnfd = {}
             for c_vnf in nsd["constituent-vnfd"]:
                 vnfd_id = c_vnf["vnfd-id-ref"]
-                self.logger.debug("create_ns task nsr_id={} RO vnfd={} creating".format(nsr_id, vnfd_id))
-                db_nsr["detailed-status"] = "Creating vnfd {} at RO".format(vnfd_id)
-                vnfd = self.db.get_one("vnfds", {"id": vnfd_id})
-                vnfd.pop("_admin", None)
-                vnfd.pop("_id", None)
+                if vnfd_id not in needed_vnfd:
+                    step = "Getting vnfd={} from db".format(vnfd_id)
+                    needed_vnfd[vnfd_id] = self.db.get_one("vnfds", {"id": vnfd_id})
+
+            nsr_lcm = {
+                "id": nsr_id,
+                "RO": {"vnfd_id": {}, "nsd_id": None, "nsr_id": None, "nsr_status": "SCHEDULED"},
+                "nsr_ip": {},
+                "VCA": {},
+            }
+            db_nsr["_admin"]["deploy"] = nsr_lcm
+            db_nsr["detailed-status"] = "creating"
+            db_nsr["operational-status"] = "init"
+
+            deloyment_timeout = 120
+
+            RO = ROclient.ROClient(self.loop, datacenter=db_nsr["datacenter"], **self.ro_config)
+
+            # get vnfds, instantiate at RO
+            for vnfd_id, vnfd in needed_vnfd.items():
+                step = db_nsr["detailed-status"] = "Creating vnfd={} at RO".format(vnfd_id)
+                self.logger.debug(logging_text + step)
+                vnfd_id_RO = nsr_id + "." + vnfd_id[:200]
 
                 # look if present
-                vnfd_list = await RO.get_list("vnfd", filter_by={"osm_id": vnfd_id})
+                vnfd_list = await RO.get_list("vnfd", filter_by={"osm_id": vnfd_id_RO})
                 if vnfd_list:
                     nsr_lcm["RO"]["vnfd_id"][vnfd_id] = vnfd_list[0]["uuid"]
-                    self.logger.debug("create_ns task nsr_id={} RO vnfd={} exist. Using RO_id={}".format(
-                        nsr_id, vnfd_id, vnfd_list[0]["uuid"]))
+                    self.logger.debug(logging_text + "RO vnfd={} exist. Using RO_id={}".format(
+                        vnfd_id, vnfd_list[0]["uuid"]))
                 else:
-                    desc = await RO.create("vnfd", descriptor=vnfd)
+                    vnfd_RO = deepcopy(vnfd)
+                    vnfd_RO.pop("_id", None)
+                    vnfd_RO.pop("_admin", None)
+                    vnfd_RO["id"] = vnfd_id_RO
+                    desc = await RO.create("vnfd", descriptor=vnfd_RO)
                     nsr_lcm["RO"]["vnfd_id"][vnfd_id] = desc["uuid"]
-                self.db.replace("nsrs", nsr_id, db_nsr)
-
-                # db_new("vnfr", vnfr)
-                # db_update("ns_request", nsr_id, ns_request)
+                self.update_nsr_db(nsr_id, db_nsr)
 
             # create nsd at RO
-            nsd_id = db_nsr["nsd"]["id"]
-            self.logger.debug("create_ns task nsr_id={} RO nsd={} creating".format(nsr_id, nsd_id))
-            db_nsr["detailed-status"] = "Creating nsd {} at RO".format(nsd_id)
-            nsd = self.db.get_one("nsds", {"id": nsd_id})
-            nsd.pop("_admin", None)
-            nsd.pop("_id", None)
-
-            nsd_list = await RO.get_list("nsd", filter_by={"osm_id": nsd_id})
+            nsd_id = nsd["id"]
+            step = db_nsr["detailed-status"] = "Creating nsd={} at RO".format(nsd_id)
+            self.logger.debug(logging_text + step)
+
+            nsd_id_RO = nsd_id + "." + nsd_id[:200]
+            nsd_list = await RO.get_list("nsd", filter_by={"osm_id": nsd_id_RO})
             if nsd_list:
                 nsr_lcm["RO"]["nsd_id"] = nsd_list[0]["uuid"]
-                self.logger.debug("create_ns task nsr_id={} RO nsd={} exist. Using RO_id={}".format(
-                    nsr_id, nsd_id, nsd_list[0]["uuid"]))
+                self.logger.debug(logging_text + "RO nsd={} exist. Using RO_id={}".format(
+                    nsd_id, nsd_list[0]["uuid"]))
             else:
-                desc = await RO.create("nsd", descriptor=nsd)
+                nsd_RO = deepcopy(nsd)
+                nsd_RO["id"] = nsd_id_RO
+                nsd_RO.pop("_id", None)
+                nsd_RO.pop("_admin", None)
+                for c_vnf in nsd_RO["constituent-vnfd"]:
+                    vnfd_id = c_vnf["vnfd-id-ref"]
+                    c_vnf["vnfd-id-ref"] = nsr_id + "." + vnfd_id[:200]
+                desc = await RO.create("nsd", descriptor=nsd_RO)
                 nsr_lcm["RO"]["nsd_id"] = desc["uuid"]
-            self.db.replace("nsrs", nsr_id, db_nsr)
+            self.update_nsr_db(nsr_id, db_nsr)
 
             # Crate ns at RO
-            self.logger.debug("create_ns task nsr_id={} RO ns creating".format(nsr_id))
-            db_nsr["detailed-status"] = "Creating ns at RO"
-            desc = await RO.create("ns", name=db_nsr["name"], datacenter=db_nsr["datacenter"],
-                                   scenario=nsr_lcm["RO"]["nsd_id"])
-            RO_nsr_id = desc["uuid"]
-            nsr_lcm["RO"]["nsr_id"] = RO_nsr_id
-            nsr_lcm["RO"]["nsr_status"] = "BUILD"
-            self.db.replace("nsrs", nsr_id, db_nsr)
+            # if present use it unless in error status
+            RO_nsr_id = nsr_lcm["RO"].get("nsr_id")
+            if RO_nsr_id:
+                try:
+                    step = db_nsr["detailed-status"] = "Looking for existing ns at RO"
+                    self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsr_id))
+                    desc = await RO.show("ns", RO_nsr_id)
+                except ROclient.ROClientException as e:
+                    if e.http_code != HTTPStatus.NOT_FOUND:
+                        raise
+                    RO_nsr_id = nsr_lcm["RO"]["nsr_id"] = None
+                if RO_nsr_id:
+                    ns_status, ns_status_info = RO.check_ns_status(desc)
+                    nsr_lcm["RO"]["nsr_status"] = ns_status
+                    if ns_status == "ERROR":
+                        step = db_nsr["detailed-status"] = "Deleting ns at RO"
+                        self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsr_id))
+                        await RO.delete("ns", RO_nsr_id)
+                        RO_nsr_id = nsr_lcm["RO"]["nsr_id"] = None
+
+            if not RO_nsr_id:
+                step = db_nsr["detailed-status"] = "Creating ns at RO"
+                self.logger.debug(logging_text + step)
+
+                desc = await RO.create("ns", name=db_nsr["name"], datacenter=db_nsr["datacenter"],
+                                       scenario=nsr_lcm["RO"]["nsd_id"])
+                RO_nsr_id = nsr_lcm["RO"]["nsr_id"] = desc["uuid"]
+                nsr_lcm["RO"]["nsr_status"] = "BUILD"
+            self.update_nsr_db(nsr_id, db_nsr)
 
             # wait until NS is ready
-            self.logger.debug("create_ns task nsr_id={} RO ns_id={} waiting to be ready".format(nsr_id, RO_nsr_id))
+            step = ns_status_detailed = "Waiting ns ready at RO"
+            db_nsr["detailed-status"] = ns_status_detailed
+            self.logger.debug(logging_text + step + " RO_ns_id={}".format(RO_nsr_id))
             deloyment_timeout = 600
             while deloyment_timeout > 0:
-                ns_status_detailed = "Waiting ns ready at RO"
-                db_nsr["detailed-status"] = ns_status_detailed
                 desc = await RO.show("ns", RO_nsr_id)
                 ns_status, ns_status_info = RO.check_ns_status(desc)
                 nsr_lcm["RO"]["nsr_status"] = ns_status
                 if ns_status == "ERROR":
                     raise ROclient.ROClientException(ns_status_info)
                 elif ns_status == "BUILD":
-                    db_nsr["detailed-status"] = ns_status_detailed + "; nsr_id: '{}', {}".format(nsr_id, ns_status_info)
+                    db_nsr["detailed-status"] = ns_status_detailed + "; {}".format(ns_status_info)
+                    self.update_nsr_db(nsr_id, db_nsr)
                 elif ns_status == "ACTIVE":
                     nsr_lcm["nsr_ip"] = RO.get_ns_vnf_ip(desc)
                     break
@@ -170,20 +268,20 @@ class Lcm:
                 await asyncio.sleep(5, loop=self.loop)
                 deloyment_timeout -= 5
             if deloyment_timeout <= 0:
-                raise ROclient.ROClientException("Timeot wating ns to be ready")
+                raise ROclient.ROClientException("Timeout waiting ns to be ready")
             db_nsr["detailed-status"] = "Configuring vnfr"
-            self.db.replace("nsrs", nsr_id, db_nsr)
+            self.update_nsr_db(nsr_id, db_nsr)
 
-            #for nsd in nsr_lcm["descriptors"]["nsd"]:
-
-            self.logger.debug("create_ns task nsr_id={} VCA look for".format(nsr_id))
+            vnfd_to_config = 0
+            step = "Looking for needed vnfd to configure"
+            self.logger.debug(logging_text + step)
             for c_vnf in nsd["constituent-vnfd"]:
                 vnfd_id = c_vnf["vnfd-id-ref"]
-                vnfd_index = str(c_vnf["member-vnf-index"])
-                vnfd = self.db.get_one("vnfds", {"id": vnfd_id})
-                db_nsr["config-status"] = "config_not_needed"
+                vnf_index = str(c_vnf["member-vnf-index"])
+                vnfd = needed_vnfd[vnfd_id]
                 if vnfd.get("vnf-configuration") and vnfd["vnf-configuration"].get("juju"):
-                    db_nsr["config-status"] = "configuring"
+                    nsr_lcm["VCA"][vnf_index] = {}
+                    vnfd_to_config += 1
                     proxy_charm = vnfd["vnf-configuration"]["juju"]["charm"]
 
                     # Note: The charm needs to exist on disk at the location
@@ -201,124 +299,139 @@ class Lcm:
                             self.db,
                             db_nsr,
                             vnfd,
-                            vnfd_index,
+                            vnf_index,
                             charm_path,
                         )
                     )
-
-            db_nsr["detailed-status"] = "Done"
+                    task.add_done_callback(functools.partial(self.vca_deploy_callback, db_nsr, vnf_index, None))
+                    self.lcm_tasks[nsr_id][order_id]["create_charm:" + vnf_index] = task
+            db_nsr["config-status"] = "configuring" if vnfd_to_config else "configured"
+            db_nsr["detailed-status"] = "Configuring 1/{}".format(vnfd_to_config) if vnfd_to_config else "done"
             db_nsr["operational-status"] = "running"
-            self.db.replace("nsrs", nsr_id, db_nsr)
+            self.update_nsr_db(nsr_id, db_nsr)
 
             self.logger.debug("create_ns task nsr_id={} Exit Ok".format(nsr_id))
             return nsr_lcm
 
-        except (ROclient.ROClientException, Exception) as e:
-            db_nsr["operational-status"] = "failed"
-            db_nsr["detailed-status"] += ": ERROR {}".format(e)
-            self.db.replace("nsrs", nsr_id, db_nsr)
-            self.logger.debug(
-                "create_ns nsr_id={} Exit Exception on '{}': {}".format(nsr_id, db_nsr["detailed-status"], e),
-                exc_info=True)
-
-    async def delete_ns(self, nsr_id):
-        self.logger.debug("delete_ns task nsr_id={}, Delete_ns task nsr_id={} Enter".format(nsr_id, nsr_id))
-        db_nsr = self.db.get_one("nsrs", {"_id": nsr_id})
-        nsr_lcm = db_nsr["_admin"]["deploy"]
-
-        db_nsr["operational-status"] = "terminate"
-        db_nsr["config-status"] = "terminate"
-        db_nsr["detailed-status"] = "Deleting charms"
-        self.db.replace("nsrs", nsr_id, db_nsr)
-
+        except (ROclient.ROClientException, DbException) as e:
+            self.logger.error(logging_text + "Exit Exception {}".format(e))
+            exc = e
+        except Exception as e:
+            self.logger.critical(logging_text + "Exit Exception {}".format(e), exc_info=True)
+            exc = e
+        finally:
+            if exc and db_nsr:
+                db_nsr["detailed-status"] = "ERROR {}: {}".format(step , exc)
+                db_nsr["operational-status"] = "failed"
+                self.update_nsr_db(nsr_id, db_nsr)
+
+    async def delete_ns(self, nsr_id, order_id):
+        logging_text = "Task delete_ns={} ".format(nsr_id)
+        self.logger.debug(logging_text + "Enter")
+        db_nsr = None
+        exc = None
+        step = "Getting nsr from db"
         try:
-            self.logger.debug("Deleting charms")
+            db_nsr = self.db.get_one("nsrs", {"_id": nsr_id})
             nsd = db_nsr["nsd"]
-            for c_vnf in nsd["constituent-vnfd"]:
-                vnfd_id = c_vnf["vnfd-id-ref"]
-                vnfd_index = str(c_vnf["member-vnf-index"])
-                vnfd = self.db.get_one("vnfds", {"id": vnfd_id})
-                if vnfd.get("vnf-configuration") and vnfd["vnf-configuration"].get("juju"):
-                    asyncio.ensure_future(
-                        RemoveApplication(
-                            self.config['VCA'],
-                            self.db,
-                            db_nsr,
-                            vnfd,
-                            vnfd_index,
-                        )
-                    )
-        except Exception as e:
-            self.logger.debug("Failed while deleting charms: {}".format(e))
-        # remove from RO
-
-        RO = ROclient.ROClient(self.loop, endpoint_url=self.ro_url, tenant=self.ro_tenant,
-                               datacenter=db_nsr["datacenter"])
-        # Delete ns
-        RO_nsr_id = nsr_lcm["RO"]["nsr_id"]
-        if RO_nsr_id:
+            nsr_lcm = db_nsr["_admin"]["deploy"]
+
+            db_nsr["operational-status"] = "terminate"
+            db_nsr["config-status"] = "terminate"
+            db_nsr["detailed-status"] = "Deleting charms"
+            self.update_nsr_db(nsr_id, db_nsr)
+
             try:
-                db_nsr["detailed-status"] = "Deleting ns at RO"
-                desc = await RO.delete("ns", RO_nsr_id)
-                self.logger.debug("delete_ns task nsr_id={} RO ns={} deleted".format(nsr_id, RO_nsr_id))
-                nsr_lcm["RO"]["nsr_id"] = None
-                nsr_lcm["RO"]["nsr_status"] = "DELETED"
-            except ROclient.ROClientException as e:
-                if e.http_code == 404:  # not found
+                step = db_nsr["detailed-status"] = "Deleting charms"
+                self.logger.debug(logging_text + step)
+                for vnf_index, deploy_info in nsr_lcm["VCA"].items():
+                    if deploy_info and deploy_info.get("appliation"):
+                        task = asyncio.ensure_future(
+                            RemoveApplication(
+                                self.config['VCA'],
+                                self.db,
+                                db_nsr,
+                                vnf_index,
+                            )
+                        )
+                        self.lcm_tasks[nsr_id][order_id]["delete_charm:" + vnf_index] = task
+            except Exception as e:
+                self.logger.debug(logging_text + "Failed while deleting charms: {}".format(e))
+            # remove from RO
+
+            RO = ROclient.ROClient(self.loop, datacenter=db_nsr["datacenter"], **self.ro_config)
+            # Delete ns
+            RO_nsr_id = nsr_lcm["RO"]["nsr_id"]
+            if RO_nsr_id:
+                try:
+                    step = db_nsr["detailed-status"] = "Deleting ns at RO"
+                    self.logger.debug(logging_text + step)
+                    desc = await RO.delete("ns", RO_nsr_id)
                     nsr_lcm["RO"]["nsr_id"] = None
                     nsr_lcm["RO"]["nsr_status"] = "DELETED"
-                    self.logger.debug("delete_ns task nsr_id={} RO ns={} already deleted".format(nsr_id, RO_nsr_id))
-                elif e.http_code == 409:   #conflict
-                    self.logger.debug("delete_ns task nsr_id={} RO ns={} delete conflict: {}".format(nsr_id, RO_nsr_id,
-                                                                                                     e))
-                else:
-                    self.logger.error("delete_ns task nsr_id={} RO ns={} delete error: {}".format(nsr_id, RO_nsr_id, e))
-            self.db.replace("nsrs", nsr_id, db_nsr)
+                except ROclient.ROClientException as e:
+                    if e.http_code == 404:  # not found
+                        nsr_lcm["RO"]["nsr_id"] = None
+                        nsr_lcm["RO"]["nsr_status"] = "DELETED"
+                        self.logger.debug(logging_text + "RO_ns_id={} already deleted".format(RO_nsr_id))
+                    elif e.http_code == 409:   #conflict
+                        self.logger.debug(logging_text + "RO_ns_id={} delete conflict: {}".format(RO_nsr_id, e))
+                    else:
+                        self.logger.error(logging_text + "RO_ns_id={} delete error: {}".format(RO_nsr_id, e))
+                self.update_nsr_db(nsr_id, db_nsr)
 
-        # Delete nsd
-        RO_nsd_id = nsr_lcm["RO"]["nsd_id"]
-        if RO_nsd_id:
-            try:
-                db_nsr["detailed-status"] = "Deleting nsd at RO"
-                desc = await RO.delete("nsd", RO_nsd_id)
-                self.logger.debug("delete_ns task nsr_id={} RO nsd={} deleted".format(nsr_id, RO_nsd_id))
-                nsr_lcm["RO"]["nsd_id"] = None
-            except ROclient.ROClientException as e:
-                if e.http_code == 404:  # not found
+            # Delete nsd
+            RO_nsd_id = nsr_lcm["RO"]["nsd_id"]
+            if RO_nsd_id:
+                try:
+                    step = db_nsr["detailed-status"] = "Deleting nsd at RO"
+                    desc = await RO.delete("nsd", RO_nsd_id)
+                    self.logger.debug(logging_text + "RO_nsd_id={} deleted".format(RO_nsd_id))
                     nsr_lcm["RO"]["nsd_id"] = None
-                    self.logger.debug("delete_ns task nsr_id={} RO nsd={} already deleted".format(nsr_id, RO_nsd_id))
-                elif e.http_code == 409:   #conflict
-                    self.logger.debug("delete_ns task nsr_id={} RO nsd={} delete conflict: {}".format(nsr_id, RO_nsd_id,
-                                                                                                      e))
-                else:
-                    self.logger.error("delete_ns task nsr_id={} RO nsd={} delete error: {}".format(nsr_id, RO_nsd_id,
-                                                                                                   e))
-            self.db.replace("nsrs", nsr_id, db_nsr)
+                except ROclient.ROClientException as e:
+                    if e.http_code == 404:  # not found
+                        nsr_lcm["RO"]["nsd_id"] = None
+                        self.logger.debug(logging_text + "RO_nsd_id={} already deleted".format(RO_nsd_id))
+                    elif e.http_code == 409:   #conflict
+                        self.logger.debug(logging_text + "RO_nsd_id={} delete conflict: {}".format(RO_nsd_id, e))
+                    else:
+                        self.logger.error(logging_text + "RO_nsd_id={} delete error: {}".format(RO_nsd_id, e))
+                self.update_nsr_db(nsr_id, db_nsr)
 
-        for vnf_id, RO_vnfd_id in nsr_lcm["RO"]["vnfd_id"].items():
-            if not RO_vnfd_id:
-                continue
-            try:
-                db_nsr["detailed-status"] = "Deleting vnfd {} at RO".format(vnf_id)
-                desc = await RO.delete("vnfd", RO_vnfd_id)
-                self.logger.debug("delete_ns task nsr_id={} RO vnfd={} deleted".format(nsr_id, RO_vnfd_id))
-                nsr_lcm["RO"]["vnfd_id"][vnf_id] = None
-            except ROclient.ROClientException as e:
-                if e.http_code == 404:  # not found
+            for vnf_id, RO_vnfd_id in nsr_lcm["RO"]["vnfd_id"].items():
+                if not RO_vnfd_id:
+                    continue
+                try:
+                    step = db_nsr["detailed-status"] = "Deleting vnfd={} at RO".format(vnf_id)
+                    desc = await RO.delete("vnfd", RO_vnfd_id)
+                    self.logger.debug(logging_text + "RO_vnfd_id={} deleted".format(RO_vnfd_id))
                     nsr_lcm["RO"]["vnfd_id"][vnf_id] = None
-                    self.logger.debug("delete_ns task nsr_id={} RO vnfd={} already deleted ".format(nsr_id, RO_vnfd_id))
-                elif e.http_code == 409:   #conflict
-                    self.logger.debug("delete_ns task nsr_id={} RO vnfd={} delete conflict: {}".format(
-                        nsr_id, RO_vnfd_id, e))
-                else:
-                    self.logger.error("delete_ns task nsr_id={} RO vnfd={} delete error: {}".format(
-                        nsr_id, RO_vnfd_id, e))
-            self.db.replace("nsrs", nsr_id, db_nsr)
+                except ROclient.ROClientException as e:
+                    if e.http_code == 404:  # not found
+                        nsr_lcm["RO"]["vnfd_id"][vnf_id] = None
+                        self.logger.debug(logging_text + "RO_vnfd_id={} already deleted ".format(RO_vnfd_id))
+                    elif e.http_code == 409:   #conflict
+                        self.logger.debug(logging_text + "RO_vnfd_id={} delete conflict: {}".format(RO_vnfd_id, e))
+                    else:
+                        self.logger.error(logging_text + "RO_vnfd_id={} delete error: {}".format(RO_vnfd_id, e))
+                self.update_nsr_db(nsr_id, db_nsr)
 
-        # TODO delete from database or mark as deleted???
-        db_nsr["operational-status"] = "terminated"
-        self.db.del_one("nsrs", {"_id": nsr_id})
-        self.logger.debug("delete_ns task nsr_id={} Exit".format(nsr_id))
+            # TODO delete from database or mark as deleted???
+            db_nsr["operational-status"] = "terminated"
+            self.db.del_one("nsrs", {"_id": nsr_id})
+            self.logger.debug(logging_text + "Exit")
+
+        except (ROclient.ROClientException, DbException) as e:
+            self.logger.error(logging_text + "Exit Exception {}".format(e))
+            exc = e
+        except Exception as e:
+            self.logger.critical(logging_text + "Exit Exception {}".format(e), exc_info=True)
+            exc = e
+        finally:
+            if exc and db_nsr:
+                db_nsr["detailed-status"] = "ERROR {}: {}".format(step , exc)
+                db_nsr["operational-status"] = "failed"
+                self.update_nsr_db(nsr_id, db_nsr)
 
     async def test(self, param=None):
         self.logger.debug("Starting/Ending test task: {}".format(param))
@@ -352,6 +465,7 @@ class Lcm:
             elif command.startswith("#"):
                 continue
             elif command == "echo":
+                # just for test
                 print(params)
             elif command == "test":
                 asyncio.Task(self.test(params), loop=self.loop)
@@ -360,7 +474,7 @@ class Lcm:
             elif command == "create":
                 nsr_id = params.strip()
                 self.logger.debug("Deploying NS {}".format(nsr_id))
-                task = asyncio.ensure_future(self.create_ns(nsr_id))
+                task = asyncio.ensure_future(self.create_ns(nsr_id, order_id))
                 if nsr_id not in self.lcm_tasks:
                     self.lcm_tasks[nsr_id] = {}
                 self.lcm_tasks[nsr_id][order_id] = {"create_ns": task}
@@ -368,18 +482,24 @@ class Lcm:
                 nsr_id = params.strip()
                 self.logger.debug("Deleting NS {}".format(nsr_id))
                 self.cancel_tasks(nsr_id)
-                task = asyncio.ensure_future(self.delete_ns(nsr_id))
+                task = asyncio.ensure_future(self.delete_ns(nsr_id, order_id))
                 if nsr_id not in self.lcm_tasks:
                     self.lcm_tasks[nsr_id] = {}
                 self.lcm_tasks[nsr_id][order_id] = {"delete_ns": task}
             elif command == "show":
+                # just for test
                 nsr_id = params.strip()
-                nsr_lcm = self.db.get_one("nsr_lcm", {"id": nsr_id})
-                print("nsr_lcm", nsr_lcm)
-                print("self.lcm_tasks", self.lcm_tasks.get(nsr_id))
+                try:
+                    db_nsr = self.db.get_one("nsrs", {"_id": nsr_id})
+                    print("nsr:\n    _id={}\n    operational-status: {}\n    config-status: {}\n    detailed-status: "
+                          "{}\n    deploy: {}\n    tasks: {}".format(
+                                nsr_id, db_nsr["operational-status"],
+                                db_nsr["config-status"], db_nsr["detailed-status"],
+                                db_nsr["_admin"]["deploy"], self.lcm_tasks.get(nsr_id)))
+                except Exception as e:
+                    print("nsr {} not found: {}".format(nsr_id, e))
             else:
-                self.logger.debug("unknown command '{}'".format(command))
-                print("Usage:\n  echo: <>\n  create: <ns1|ns2>\n  delete: <ns1|ns2>\n  show: <ns1|ns2>")
+                self.logger.critical("unknown command '{}'".format(command))
         self.logger.debug("kafka task Exit")
 
 
@@ -425,41 +545,4 @@ if __name__ == '__main__':
     config_file = "lcm.cfg"
     lcm = Lcm(config_file)
 
-    # # FOR TEST
-    # RO_VIM = "OST2_MRT"
-    #
-    # #FILL DATABASE
-    # with open("/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/ping_vnf/src/ping_vnfd.yaml") as f:
-    #     vnfd = yaml.load(f)
-    #     vnfd_clean, _ = ROclient.remove_envelop("vnfd", vnfd)
-    #     vnfd_clean["_admin"] = {"storage": "/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/ping_vnf"}
-    #     lcm.db.create("vnfd", vnfd_clean)
-    # with open("/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/pong_vnf/src/pong_vnfd.yaml") as f:
-    #     vnfd = yaml.load(f)
-    #     vnfd_clean, _ = ROclient.remove_envelop("vnfd", vnfd)
-    #     vnfd_clean["_admin"] = {"storage": "/home/atierno/OSM/osm/devops/descriptor-packages/vnfd/pong_vnf"}
-    #     lcm.db.create("vnfd", vnfd_clean)
-    # with open("/home/atierno/OSM/osm/devops/descriptor-packages/nsd/ping_pong_ns/src/ping_pong_nsd.yaml") as f:
-    #     nsd = yaml.load(f)
-    #     nsd_clean, _ = ROclient.remove_envelop("nsd", nsd)
-    #     nsd_clean["_admin"] = {"storage": "/home/atierno/OSM/osm/devops/descriptor-packages/nsd/ping_pong_ns"}
-    #     lcm.db.create("nsd", nsd_clean)
-    #
-    # ns_request = {
-    #     "id": "ns1",
-    #     "nsr_id": "ns1",
-    #     "name": "pingpongOne",
-    #     "vim": RO_VIM,
-    #     "nsd_id": nsd_clean["id"],  # nsd_ping_pong
-    # }
-    # lcm.db.create("ns_request", ns_request)
-    # ns_request = {
-    #     "id": "ns2",
-    #     "nsr_id": "ns2",
-    #     "name": "pingpongTwo",
-    #     "vim": RO_VIM,
-    #     "nsd_id": nsd_clean["id"],  # nsd_ping_pong
-    # }
-    # lcm.db.create("ns_request", ns_request)
-
     lcm.start()
index b2b2663..d582096 100644 (file)
@@ -17,7 +17,7 @@ class VCAMonitor(ModelObserver):
         """React to changes in the Juju model."""
         status = None
         db_nsr = self.context['db_nsr']
-        vnf_id = self.context['vnf_id']
+        vnf_index = self.context['vnf_index']
 
         nsr_lcm = db_nsr["_admin"]["deploy"]
         nsr_id = nsr_lcm["id"]
@@ -39,15 +39,15 @@ class VCAMonitor(ModelObserver):
                     status = "DELETING"
 
         if status:
-            nsr_lcm["VCA"][vnf_id]['operational-status'] = status
+            nsr_lcm["VCA"][vnf_index]['operational-status'] = status
 
             # TODO: Clean this up, and make it work with deletes (if we need
             # TODO: to update the database post-delete)
             # Figure out if we're finished configuring
             count = len(nsr_lcm["VCA"])
             active = 0
-            for vnf_id in nsr_lcm["VCA"]:
-                if nsr_lcm["VCA"][vnf_id]['operational-status'] == "ACTIVE":
+            for vnf_index in nsr_lcm["VCA"]:
+                if nsr_lcm["VCA"][vnf_index]['operational-status'] == "ACTIVE":
                     active += 1
             if active == count:
                 db_nsr["config-status"] = "done"
@@ -78,7 +78,6 @@ class VCAMonitor(ModelObserver):
 def GetJujuApi(config):
     # Quiet logging from the websocket library. If you want to see
     # everything sent over the wire, set this to DEBUG.
-    logging.basicConfig(level=logging.DEBUG)
 
     ws_logger = logging.getLogger('websockets.protocol')
     ws_logger.setLevel(logging.INFO)
@@ -121,7 +120,7 @@ def get_initial_config(initial_config_primitive, mgmt_ip):
 
 
 async def DeployApplication(vcaconfig, db, db_nsr, vnfd,
-                            vnfd_index, charm_path):
+                            vnf_index, charm_path):
     """
     Deploy a charm.
 
@@ -136,7 +135,7 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd,
     DeployApplication(...)
     """
     nsr_lcm = db_nsr["_admin"]["deploy"]
-    nsr_id = nsr_lcm["id"]
+    nsr_id = db_nsr["_id"]
     vnf_id = vnfd['id']
 
     if "proxy" in vnfd["vnf-configuration"]["juju"]:
@@ -147,8 +146,8 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd,
 
     application = get_vnf_unique_name(
         db_nsr["name"].lower().strip(),
-        vnfd['id'],
-        vnfd_index,
+        vnf_id,
+        vnf_index,
     )
 
     api = GetJujuApi(vcaconfig)
@@ -159,16 +158,16 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd,
 
         # Set the INIT state; further operational status updates
         # will be made by the VCAMonitor
-        nsr_lcm["VCA"][vnf_id] = {}
-        nsr_lcm["VCA"][vnf_id]['operational-status'] = 'INIT'
-        nsr_lcm["VCA"][vnf_id]['application'] = application
+        nsr_lcm["VCA"][vnf_index] = {}
+        nsr_lcm["VCA"][vnf_index]['operational-status'] = 'INIT'
+        nsr_lcm["VCA"][vnf_index]['application'] = application
 
         db.replace("nsrs", nsr_id, db_nsr)
 
         model = await api.get_model()
         context = {
             'application': application,
-            'vnf_id': vnf_id,
+            'vnf_index': vnf_index,
             'db_nsr': db_nsr,
             'db': db,
         }
@@ -186,7 +185,7 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd,
             vnfd["vnf-configuration"].get(
                 "initial-config-primitive"
             ),
-            nsr_lcm['nsr_ip'][vnfd_index]
+            nsr_lcm['nsr_ip'][vnf_index]
         )
 
         await api.apply_config(cfg, application)
@@ -194,7 +193,7 @@ async def DeployApplication(vcaconfig, db, db_nsr, vnfd,
     await api.logout()
 
 
-async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index):
+async def RemoveApplication(vcaconfig, db, db_nsr, vnf_index):
     """
     Remove an application from the Juju Controller
 
@@ -208,9 +207,9 @@ async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index):
     RemoveApplication(loop, "ping_vnf")
     RemoveApplication(loop, "pong_vnf")
     """
+    nsr_id = db_nsr["_id"]
     nsr_lcm = db_nsr["_admin"]["deploy"]
-    vnf_id = vnfd['id']
-    application = nsr_lcm["VCA"][vnf_id]['application']
+    application = nsr_lcm["VCA"][vnf_index]['application']
 
     api = GetJujuApi(vcaconfig)
 
@@ -219,7 +218,7 @@ async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index):
         model = await api.get_model()
         context = {
             'application': application,
-            'vnf_id': vnf_id,
+            'vnf_index': vnf_index,
             'db_nsr': db_nsr,
             'db': db,
         }
@@ -230,4 +229,6 @@ async def RemoveApplication(vcaconfig, db, db_nsr, vnfd, vnfd_index):
 
         print("VCA: Removing application {}".format(application))
         await api.remove_application(application)
+        nsr_lcm["VCA"][vnf_index]['application'] = None
+        db.replace("nsrs", nsr_id, db_nsr)
     await api.logout()