[CORD-2550] Fixing profile/enodeb update and adding debug info
[CORD-2714] Not adding profiles to the same handover

Change-Id: I7f84362c8de43753f9712f53fbf1bead3ece58f3
diff --git a/xos/synchronizer/steps/helpers.py b/xos/synchronizer/steps/helpers.py
index 8f07a66..333566a 100644
--- a/xos/synchronizer/steps/helpers.py
+++ b/xos/synchronizer/steps/helpers.py
@@ -47,7 +47,8 @@
     @staticmethod
     def get_progran_rest_errors(res):
         res = res.json()
-        if res['Result'] == -2:
+        if res['Result'] == -2 or res['Result'] == -1:
+            log.error('Error from ONOS Progran', error=res)
             raise Exception(res['ErrCode'])
 
     @staticmethod
@@ -62,8 +63,8 @@
         for k, v in dict.iteritems():
             if hasattr(model, k):
                 setattr(model, k, v)
-            else:
-                log.warn("%s does not have a '%s' property, not updating it" % (model.model_name, k))
+            # else:
+            #     log.debug("%s does not have a '%s' property, not updating it" % (model.model_name, k))
         return model
 
     @staticmethod
diff --git a/xos/synchronizer/steps/sync_enodeb.py b/xos/synchronizer/steps/sync_enodeb.py
index db5bca9..7579763 100644
--- a/xos/synchronizer/steps/sync_enodeb.py
+++ b/xos/synchronizer/steps/sync_enodeb.py
@@ -16,14 +16,14 @@
 
 import os
 import sys
-from synchronizers.new_base.SyncInstanceUsingAnsible import SyncInstanceUsingAnsible
-from synchronizers.new_base.ansible_helper import run_template
+from synchronizers.new_base.SyncInstanceUsingAnsible import SyncStep
 from synchronizers.new_base.modelaccessor import ENodeB
 
 from xosconfig import Config
 from multistructlog import create_logger
 import json
-
+import requests
+from requests.auth import HTTPBasicAuth
 
 log = create_logger(Config().get('logging'))
 
@@ -34,16 +34,11 @@
 
 from helpers import ProgranHelpers
 
-class SyncProgranEnodeB(SyncInstanceUsingAnsible):
+class SyncProgranEnodeB(SyncStep):
     provides = [ENodeB]
 
     observes = ENodeB
 
-    def skip_ansible_fields(self, o):
-        # FIXME This model does not have an instance, this is a workaroung to make it work,
-        # but it need to be cleaned up creating a general SyncUsingAnsible base class
-        return True
-
     def get_progran_enodeb_field(self, o):
 
         enodeb = {
@@ -51,37 +46,35 @@
 	        "Description": o.description,
 	        "IpAddr": o.ipAddr
         }
-        enodeb = json.dumps(enodeb)
         return enodeb
 
-    def get_extra_attributes(self, o):
+    def sync_record(self, o):
+        log.info("sync'ing enodeb", object=str(o), **o.tologdict())
+
         onos = ProgranHelpers.get_progran_onos_info()
-        fields = {
-            'onos_url': onos['url'],
-            'onos_username': onos['username'],
-            'onos_password': onos['password'],
-            'onos_port': onos['port'],
-            'endpoint': 'enodeb',
-            'body': self.get_progran_enodeb_field(o),
-            'method': 'POST'
-        }
 
-        return fields
+        enodeb_url = "http://%s:%s/onos/progran/enodeb/" % (onos['url'], onos['port'])
+        data = self.get_progran_enodeb_field(o)
+        log.debug("Sync'ing enodeb with data", request_data=data)
 
-    # FIXME we need to override this as the default expect to ssh into a VM
-    def run_playbook(self, o, fields):
-        run_template("progran_curl.yaml", fields, object=o)
+        if o.previously_sync == False:
+            log.debug("Sending POST")
+            r = requests.post(enodeb_url, data=json.dumps(data), auth=HTTPBasicAuth(onos['username'], onos['password']))
+        else:
+            log.debug("Sending PUT")
+            r = requests.put(enodeb_url, data=json.dumps(data),
+                              auth=HTTPBasicAuth(onos['username'], onos['password']))
+
+        ProgranHelpers.get_progran_rest_errors(r)
+        log.info("Enodeb synchronized", response=r.json())
+
+        o.previously_sync = True
+        o.save()
 
     def delete_record(self, o):
-        log.info("deleting object", object=str(o), **o.tologdict())
+        log.info("deleting enodeb", object=str(o), **o.tologdict())
         onos = ProgranHelpers.get_progran_onos_info()
-        fields = {
-            'onos_url': onos['url'],
-            'onos_username': onos['username'],
-            'onos_password': onos['password'],
-            'onos_port': onos['port'],
-            'endpoint': 'enodeb/%s' % o.enbId,
-            'profile': '',
-            'method': 'DELETE'
-        }
-        res = self.run_playbook(o, fields)
\ No newline at end of file
+        enode_url = "http://%s:%s/onos/progran/enodeb/%s" % (onos['url'], onos['port'], o.enbId)
+        r = requests.delete(enode_url, auth=HTTPBasicAuth(onos['username'], onos['password']))
+        ProgranHelpers.get_progran_rest_errors(r)
+        log.info("enodeb deleted", response=r.json())
\ No newline at end of file
diff --git a/xos/synchronizer/steps/sync_imsi.py b/xos/synchronizer/steps/sync_imsi.py
index 1cc6338..3ad0250 100644
--- a/xos/synchronizer/steps/sync_imsi.py
+++ b/xos/synchronizer/steps/sync_imsi.py
@@ -16,14 +16,14 @@
 
 import os
 import sys
-from synchronizers.new_base.SyncInstanceUsingAnsible import SyncInstanceUsingAnsible
-from synchronizers.new_base.ansible_helper import run_template
+from synchronizers.new_base.SyncInstanceUsingAnsible import SyncStep
 from synchronizers.new_base.modelaccessor import MCordSubscriberInstance
 
 from xosconfig import Config
 from multistructlog import create_logger
 import json
 import requests
+from requests.auth import HTTPBasicAuth
 
 
 log = create_logger(Config().get('logging'))
@@ -33,72 +33,32 @@
 sys.path.insert(0, os.path.dirname(__file__))
 from helpers import ProgranHelpers
 
-class SyncProgranIMSI(SyncInstanceUsingAnsible):
+class SyncProgranIMSI(SyncStep):
     provides = [MCordSubscriberInstance]
 
     observes = MCordSubscriberInstance
 
-    def skip_ansible_fields(self, o):
-        # FIXME This model does not have an instance, this is a workaroung to make it work,
-        # but it need to be cleaned up creating a general SyncUsingAnsible base class
-        return True
-
     def get_progran_imsi_field(self, o):
 
         imsi = {
             "IMSI": o.imsi_number,
         }
-        imsi = json.dumps(imsi)
         return imsi
 
-    def get_fields(self, o):
-        onos = ProgranHelpers.get_progran_onos_info()
-        fields = {
-            'onos_url': onos['url'],
-            'onos_username': onos['username'],
-            'onos_password': onos['password'],
-            'onos_port': onos['port'],
-        }
-
-        return fields
-
     def sync_record(self, o):
-        # NOTE overriding the default method as we need to read from progran
-        base_fields = self.get_fields(o)
+        log.info("sync'ing imsi", object=str(o), **o.tologdict())
+        onos = ProgranHelpers.get_progran_onos_info()
+        imsi_url = "http://%s:%s/onos/progran/imsi/" % (onos['url'], onos['port'])
+        data = self.get_progran_imsi_field(o)
+        r = requests.post(imsi_url, data=json.dumps(data), auth=HTTPBasicAuth(onos['username'], onos['password']))
 
-        create_fields = {
-            'endpoint': 'imsi',
-            'body': self.get_progran_imsi_field(o),
-            'method': 'POST'
-        }
-
-        create_fields["ansible_tag"] = getattr(o, "ansible_tag", o.__class__.__name__ + "_" + str(o.id))
-        create_fields.update(base_fields)
-
-        self.run_playbook(o, create_fields)
-
-        # fetch the IMSI we just created
-        # NOTE we won't need this method once we'll have polling in place
-        # imsi_url = "http://%s:%s/onos/progran/imsi/%s" % (base_fields['onos_url'], base_fields['onos_port'], o.imsi_number)
-        # r = requests.get(imsi_url)
-        # o.ue_status = r.json()['ImsiArray'][0]['UeStatus']
-
-        o.save()
-
-    # FIXME we need to override this as the default expect to ssh into a VM
-    def run_playbook(self, o, fields):
-        return run_template("progran_curl.yaml", fields, object=o)
+        ProgranHelpers.get_progran_rest_errors(r)
+        log.info("Profile synchronized", response=r.json())
 
     def delete_record(self, o):
-        log.info("deleting object", object=str(o), **o.tologdict())
-        onos = ProgranHelpers.get_progran_onos_info()
-        fields = {
-            'onos_url': onos['url'],
-            'onos_username': onos['username'],
-            'onos_password': onos['password'],
-            'onos_port': onos['port'],
-            'endpoint': 'imsi/%s' % o.imsi_number,
-            'body': '',
-            'method': 'DELETE'
-        }
-        res = self.run_playbook(o, fields)
\ No newline at end of file
+        log.info("deleting imsi", object=str(o), **o.tologdict())
+        onos = ProgranHelpers.get_onos_info_from_si(o)
+        profile_url = "http://%s:%s/onos/progran/imsi/%s" % (onos['url'], onos['port'], o.imsi_number)
+        r = requests.delete(profile_url, auth=HTTPBasicAuth(onos['username'], onos['password']))
+        o.active_enodeb_id = 0  # removing the value because it has been deleted
+        log.info("IMSI synchronized", response=r.json())
\ No newline at end of file
diff --git a/xos/synchronizer/steps/sync_imsi_back.py b/xos/synchronizer/steps/sync_imsi_back.py
index 9398c76..b5a9a3e 100644
--- a/xos/synchronizer/steps/sync_imsi_back.py
+++ b/xos/synchronizer/steps/sync_imsi_back.py
@@ -53,14 +53,13 @@
             # NOTE we won't it to run only after the delete has completed
             return
 
-        log.info("Reading IMSI from progran")
+        log.debug("Reading IMSI from progran")
         onos = ProgranHelpers.get_progran_onos_info()
         imsi_url = "http://%s:%s/onos/progran/imsi/" % (onos['url'], onos['port'])
         r = requests.get(imsi_url, auth=HTTPBasicAuth(onos['username'], onos['password']))
         res = r.json()['ImsiArray']
 
-        print res
-
+        log.debug("Received IMSIs: ", imsis=res)
 
         field_mapping = {
             'IMSI': 'imsi_number',
@@ -70,18 +69,18 @@
         updated_imsi = []
 
         for i in res:
-            # imsi for profiles
             try:
                 si = MCordSubscriberInstance.objects.get(imsi_number=i['IMSI'])
-                log.info("IMSI %s already exists, updating it" % i['IMSI'])
+                log.debug("IMSI %s already exists, updating it" % i['IMSI'])
             except IndexError:
                 si = MCordSubscriberInstance()
 
                 si.no_sync = True
                 si.backend_code = 1
                 si.backend_status = "OK"
+                si.created_by = "Progran"
 
-                log.info("IMSI %s is new, creating it" % i['IMSI'])
+                log.debug("IMSI %s is new, creating it" % i['IMSI'])
 
             si = ProgranHelpers.update_fields(si, i, field_mapping,)
 
@@ -93,7 +92,10 @@
         deleted_imsi = ProgranHelpers.list_diff(existing_imsi, updated_imsi)
 
         if len(deleted_imsi) > 0:
-            log.info("Profiles %s have been removed in progran, removing them from XOS" % str(deleted_imsi))
+            log.debug("Profiles %s have been removed in progran, removing them from XOS" % str(deleted_imsi))
             for p in deleted_imsi:
                 si = MCordSubscriberInstance.objects.get(imsi_number=p)
+                # if si.created_by == 'XOS' and si.previously_sync == False:
+                    # don't delete if the imsi has been created by XOS and it hasn't been sync'ed yet
+                    # continue
                 si.delete()
diff --git a/xos/synchronizer/steps/sync_imsi_link.py b/xos/synchronizer/steps/sync_imsi_link.py
index 3b1ba98..863af21 100644
--- a/xos/synchronizer/steps/sync_imsi_link.py
+++ b/xos/synchronizer/steps/sync_imsi_link.py
@@ -16,8 +16,7 @@
 
 import os
 import sys
-from synchronizers.new_base.SyncInstanceUsingAnsible import SyncStep
-from synchronizers.new_base.ansible_helper import run_template
+from synchronizers.new_base.syncstep import SyncStep
 from synchronizers.new_base.modelaccessor import MCordSubscriberInstance, ServiceInstanceLink, ProgranServiceInstance
 
 from xosconfig import Config
@@ -72,7 +71,7 @@
             url = "http://%s:%s/onos/progran/profile/%s/imsi" % (onos['url'], onos['port'], profile_name)
 
             r = requests.post(url, data=json.dumps(data), auth=HTTPBasicAuth(onos['username'], onos['password']))
-            print r.json()
+            ProgranHelpers.get_progran_rest_errors(r)
 
     def delete_record(self, o):
 
@@ -87,4 +86,4 @@
             url = "http://%s:%s/onos/progran/profile/%s/%s" % (onos['url'], onos['port'], profile_name, imsi_number)
 
             r = requests.delete(url, auth=HTTPBasicAuth(onos['username'], onos['password']))
-            print r.json()
\ No newline at end of file
+            ProgranHelpers.get_progran_rest_errors(r)
\ No newline at end of file
diff --git a/xos/synchronizer/steps/sync_progranserviceinstance.py b/xos/synchronizer/steps/sync_progranserviceinstance.py
index 11d679d..69a860e 100644
--- a/xos/synchronizer/steps/sync_progranserviceinstance.py
+++ b/xos/synchronizer/steps/sync_progranserviceinstance.py
@@ -16,7 +16,7 @@
 
 import os
 import sys
-from synchronizers.new_base.SyncInstanceUsingAnsible import SyncStep
+from synchronizers.new_base.syncstep import SyncStep
 from synchronizers.new_base.modelaccessor import ProgranServiceInstance, ENodeB, Handover
 
 from xosconfig import Config
@@ -40,9 +40,6 @@
 
     observes = ProgranServiceInstance
 
-    # Poll every 5 loops of self.call
-    poll = 0
-
     def sync_record(self, o):
         onos = ProgranHelpers.get_progran_onos_info()
 
@@ -50,13 +47,19 @@
 
         profile_url = "http://%s:%s/onos/progran/profile/" % (onos['url'], onos['port'])
         data = self.get_progran_profile_field(o)
+        log.debug("Sync'ing profile with data", request_data=data)
 
-        r = requests.post(profile_url, data=json.dumps(data), auth=HTTPBasicAuth(onos['username'], onos['password']))
+        if o.previously_sync == False:
+            log.debug("Sending POST")
+            r = requests.post(profile_url, data=json.dumps(data), auth=HTTPBasicAuth(onos['username'], onos['password']))
+        else:
+            log.debug("Sending PUT")
+            r = requests.put(profile_url, data=json.dumps(data),
+                              auth=HTTPBasicAuth(onos['username'], onos['password']))
 
         ProgranHelpers.get_progran_rest_errors(r)
         log.info("Profile synchronized", response=r.json())
 
-        log.info("sync'ing enodeb", object=str(o), **o.tologdict())
         if o.enodeb_id:
             log.info("adding profile %s to enodeb %s" % (o.id, o.enodeb.enbId), object=str(o), **o.tologdict())
             enodeb_url = "http://%s:%s/onos/progran/enodeb/%s/profile" % (onos['url'], onos['port'], o.enodeb.enbId)
@@ -65,6 +68,7 @@
                     o.name
                 ]
             }
+            log.debug("Adding enodeb to profile with data", request_data=data)
             r = requests.post(enodeb_url, data=json.dumps(data), auth=HTTPBasicAuth(onos['username'], onos['password']))
             ProgranHelpers.get_progran_rest_errors(r)
             o.active_enodeb_id = o.enodeb_id # storing the value to know when it will be deleted
@@ -78,7 +82,7 @@
             o.active_enodeb_id = 0 # removing the value because it has been deleted
             log.info("EnodeB synchronized", response=r.json())
 
-        o.save()
+        o.previously_sync = True
 
     def get_handover_for_profile(self, o):
         return {
@@ -124,103 +128,4 @@
         log.info("Profile synchronized", response=r.json())
 
     def fetch_pending(self, deleted):
-        # self.read_profiles_from_progran()
         return super(SyncProgranServiceInstance, self).fetch_pending(deleted)
-
-    @staticmethod
-    def date_to_time(d):
-        if len(d) == 0:
-            return 0
-        return time.mktime(datetime.datetime.strptime(d, "%d.%m.%Y %H:%S").timetuple())
-
-    @staticmethod
-    def update_fields(model, dict, mapping={}, transformations={}):
-        dict = SyncProgranServiceInstance.convert_keys(dict, mapping, transformations)
-        for k, v in dict.iteritems():
-            if hasattr(model, k):
-                setattr(model, k, v)
-            else:
-                log.warn("%s does not have a '%s' property, not updating it" % (model.model_name, k))
-        return model
-
-    @staticmethod
-    def convert_keys(dict, mapping={}, transformations={}):
-        for k, v in dict.iteritems():
-            if k in mapping:
-                # apply custom transformations to the data
-                if k in transformations:
-                    dict[k] = transformations[k](v)
-
-                # NOTE we may have different names that the field in the dict
-                dict[mapping[k]] = dict[k]
-                del dict[k]
-        return dict
-
-
-    def my_call(self, failed=[], deletion=False):
-        """
-        Read profile from progran and save them in xos
-        """
-        if self.poll < 5:
-            self.poll = self.poll + 1
-        else:
-            self.poll = 0
-            onos = ProgranHelpers.get_progran_onos_info()
-            profile_url = "http://%s:%s/onos/progran/profile/" % (onos['url'], onos['port'])
-            r = requests.get(profile_url, auth=HTTPBasicAuth(onos['username'], onos['password']))
-            res = r.json()['ProfileArray']
-
-            # remove default profiles
-            res = [p for p in res if "Default" not in p['Name']]
-
-            field_mapping = {
-                'Name': 'name',
-                'Start': 'start',
-                'End': 'end'
-            }
-
-            field_transformations = {
-                'Start': SyncProgranServiceInstance.date_to_time,
-                'End': SyncProgranServiceInstance.date_to_time
-            }
-
-            handover_mapping = {
-                'A5Hysteresis': 'HysteresisA5',
-                'A3Hysteresis': 'HysteresisA3'
-            }
-
-            for p in res:
-
-                # checking for handovers
-                handover_dict = p['Handover']
-                handover_dict = SyncProgranServiceInstance.convert_keys(handover_dict, handover_mapping)
-                del p['Handover']
-
-                try:
-                    handover = Handover.objects.get(**handover_dict)
-                    log.info("handover already exists, updating it", handover=handover_dict)
-                except IndexError:
-                    handover = Handover()
-                    handover = SyncProgranServiceInstance.update_fields(handover, handover_dict)
-                    log.info("handover is new, creating it", handover=handover_dict)
-
-                handover.save()
-
-                # checking for profiles
-                try:
-                    si = ProgranServiceInstance.objects.get(name=p['Name'])
-                    log.info("Profile %s already exists, updating it" % p['Name'])
-                except IndexError:
-                    si = ProgranServiceInstance()
-                    si.name = p['Name']
-                    log.info("Profile %s is new, creating it" % p['Name'])
-
-                si = SyncProgranServiceInstance.update_fields(si, p, field_mapping, field_transformations)
-                si.handover = handover
-
-
-
-                # TODO keep track of the deleted profiles
-                # existing profiles - updated profiles = deleted profiles
-
-                si.save()
diff --git a/xos/synchronizer/steps/sync_progranserviceinstance_back.py b/xos/synchronizer/steps/sync_progranserviceinstance_back.py
index a7c2b73..9195f2b 100644
--- a/xos/synchronizer/steps/sync_progranserviceinstance_back.py
+++ b/xos/synchronizer/steps/sync_progranserviceinstance_back.py
@@ -20,7 +20,7 @@
 import datetime
 import time
 
-from synchronizers.new_base.SyncInstanceUsingAnsible import SyncStep
+from synchronizers.new_base.syncstep import SyncStep
 from synchronizers.new_base.modelaccessor import ProgranServiceInstance, ENodeB, Handover
 
 from xosconfig import Config
@@ -53,12 +53,14 @@
             # NOTE we won't it to run only after the delete has completed
             return
 
-        log.info("Reading profiles from progran")
+        log.debug("Reading profiles from progran")
         onos = ProgranHelpers.get_progran_onos_info()
         profile_url = "http://%s:%s/onos/progran/profile/" % (onos['url'], onos['port'])
         r = requests.get(profile_url, auth=HTTPBasicAuth(onos['username'], onos['password']))
         res = r.json()['ProfileArray']
 
+        log.debug("Received Profiles: ", profiles=res)
+
         # remove default profiles
         res = [p for p in res if "Default" not in p['Name']]
 
@@ -82,35 +84,44 @@
 
         for p in res:
 
+
+            # checking for profiles
+            try:
+                si = ProgranServiceInstance.objects.get(name=p['Name'])
+                log.debug("Profile %s already exists, updating it" % p['Name'])
+            except IndexError:
+                si = ProgranServiceInstance()
+
+                si.no_sync = True
+                si.created_by = "Progran"
+
+                log.debug("Profile %s is new, creating it" % p['Name'])
+
+            si = ProgranHelpers.update_fields(si, p, field_mapping, field_transformations)
+
             # checking for handovers
             handover_dict = p['Handover']
             handover_dict = ProgranHelpers.convert_keys(handover_dict, handover_mapping)
             del p['Handover']
 
-            try:
-                handover = Handover.objects.get(**handover_dict)
-                log.info("handover already exists, updating it", handover=handover_dict)
-            except IndexError:
+            if si.handover_id:
+                handover = si.handover
+                log.debug("handover already exists, updating it", handover=handover_dict)
+            else:
                 handover = Handover()
                 handover = ProgranHelpers.update_fields(handover, handover_dict)
-                log.info("handover is new, creating it", handover=handover_dict)
+                log.debug("handover is new, creating it", handover=handover_dict)
+                handover.created_by = "Progran"
 
+            handover = ProgranHelpers.update_fields(handover, handover_dict)
             handover.save()
 
-            # checking for profiles
-            try:
-                si = ProgranServiceInstance.objects.get(name=p['Name'])
-                log.info("Profile %s already exists, updating it" % p['Name'])
-            except IndexError:
-                si = ProgranServiceInstance()
-
-                si.no_sync = True
-
-                log.info("Profile %s is new, creating it" % p['Name'])
-
-            si = ProgranHelpers.update_fields(si, p, field_mapping, field_transformations)
+            # Assigning handover to profile
             si.handover = handover
 
+            si.backend_status = "OK"
+            si.backend_code = 1
+
             si.save()
 
             updated_profiles.append(si.name)
@@ -119,7 +130,10 @@
         deleted_profiles = ProgranHelpers.list_diff(existing_profiles, updated_profiles)
 
         if len(deleted_profiles) > 0:
-            log.info("Profiles %s have been removed in progran, removing them from XOS" % str(deleted_profiles))
+            log.debug("Profiles %s have been removed in progran, removing them from XOS" % str(deleted_profiles))
             for p in deleted_profiles:
                 si = ProgranServiceInstance.objects.get(name=p)
+                if si.created_by == 'XOS' and si.previously_sync == False:
+                    # don't delete if the profile has been created by XOS and it hasn't been sync'ed yet
+                    continue
                 si.delete()