VOL-1415 VOL-1345 On onu reboot ensure the same gem and tcont id are used

Check if a tcont already has an alloc id assigned and if so use it,
otherwise check for a free one

Also the dict where gem ports are checked if they exist have an additional key,
use that to determine if exists

Also some logging fixes so certain objects are string represented properly

Change-Id: I24d3a69a1bda5b8f64dde472cb9e1260e19b1508
diff --git a/voltha/adapters/brcm_openomci_onu/brcm_openomci_onu_handler.py b/voltha/adapters/brcm_openomci_onu/brcm_openomci_onu_handler.py
index 9fed3f9..42dd0a9 100644
--- a/voltha/adapters/brcm_openomci_onu/brcm_openomci_onu_handler.py
+++ b/voltha/adapters/brcm_openomci_onu/brcm_openomci_onu_handler.py
@@ -375,7 +375,7 @@
             gemdict['weight'] = gem_port['weight']
             gemdict['uni_id'] = uni_id
 
-            gem_port = OnuGemPort.create(self, gem_port=gemdict, entity_id=self._pon.next_gem_entity_id)
+            gem_port = OnuGemPort.create(self, gem_port=gemdict)
 
             self._pon.add_gem_port(gem_port)
 
@@ -615,12 +615,12 @@
         assert uni_port is not None
 
         def success(_results):
-            self.log.info('vlan-tagging-success', _results=_results)
+            self.log.info('vlan-tagging-success', uni_port=uni_port, vlan=_set_vlan_vid)
             device.reason = 'omci-flows-pushed'
             self._vlan_filter_task = None
 
         def failure(_reason):
-            self.log.warn('vlan-tagging-failure', _reason=_reason)
+            self.log.warn('vlan-tagging-failure', uni_port=uni_port, vlan=_set_vlan_vid)
             device.reason = 'omci-flows-failed-retrying'
             self._vlan_filter_task = reactor.callLater(_STARTUP_RETRY_WAIT,
                                                        self._add_vlan_filter_task, device, uni_port, _set_vlan_vid)
diff --git a/voltha/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py b/voltha/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py
index 48f712d..3341219 100644
--- a/voltha/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py
+++ b/voltha/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py
@@ -83,8 +83,7 @@
 
         self._pon = handler.pon_port
 
-        # Port numbers
-        self._pon_port_num = self._pon.pon_port_num
+        # Defaults
         self._input_tpid = DEFAULT_TPID
         self._output_tpid = DEFAULT_TPID
 
diff --git a/voltha/adapters/brcm_openomci_onu/omci/brcm_tp_service_specific_task.py b/voltha/adapters/brcm_openomci_onu/omci/brcm_tp_service_specific_task.py
index 0df8d80..ff0bd30 100644
--- a/voltha/adapters/brcm_openomci_onu/omci/brcm_tp_service_specific_task.py
+++ b/voltha/adapters/brcm_openomci_onu/omci/brcm_tp_service_specific_task.py
@@ -102,12 +102,12 @@
         self._tconts = []
         for tcont in handler.pon_port.tconts.itervalues():
             if tcont.uni_id is not None and tcont.uni_id != self._uni_port.uni_id: continue
-            self._tconts.append(tcont);
+            self._tconts.append(tcont)
 
         self._gem_ports = []
         for gem_port in handler.pon_port.gem_ports.itervalues():
             if gem_port.uni_id is not None and gem_port.uni_id != self._uni_port.uni_id: continue
-            self._gem_ports.append(gem_port);
+            self._gem_ports.append(gem_port)
 
         self.tcont_me_to_queue_map = dict()
         self.uni_port_to_queue_map = dict()
@@ -191,25 +191,30 @@
             self.log.debug('tcont-idents', tcont_idents=tcont_idents)
 
             for tcont in self._tconts:
-                free_entity_id = None
-                for k, v in tcont_idents.items():
-                    alloc_check = v.get('attributes', {}).get('alloc_id', 0)
-                    # Some onu report both to indicate an available tcont
-                    if alloc_check == 0xFF or alloc_check == 0xFFFF:
-                        free_entity_id = k
+                self.log.debug('tcont-loop', tcont=tcont)
+
+                if tcont.entity_id is None:
+                    free_entity_id = None
+                    for k, v in tcont_idents.items():
+                        alloc_check = v.get('attributes', {}).get('alloc_id', 0)
+                        # Some onu report both to indicate an available tcont
+                        if alloc_check == 0xFF or alloc_check == 0xFFFF:
+                            free_entity_id = k
+                            break
+
+                    self.log.debug('tcont-loop-free', free_entity_id=free_entity_id, alloc_id=tcont.alloc_id)
+
+                    if free_entity_id is None:
+                        self.log.error('no-available-tconts')
                         break
-                    else:
-                        free_entity_id = None
 
-                self.log.debug('tcont-loop', free_entity_id=free_entity_id, alloc_id=tcont.alloc_id)
-
-                if free_entity_id is None:
-                    self.log.error('no-available-tconts')
-                    break
-
-                # TODO: Need to restore on failure.  Need to check status/results
-                results = yield tcont.add_to_hardware(omci_cc, free_entity_id)
-                self.check_status_and_state(results, 'create-tcont')
+                    # Also assign entity id within tcont object
+                    results = yield tcont.add_to_hardware(omci_cc, free_entity_id)
+                    self.check_status_and_state(results, 'new-tcont-added')
+                else:
+                    # likely already added given entity_id is set, but no harm in doing it again
+                    results = yield tcont.add_to_hardware(omci_cc, tcont.entity_id)
+                    self.check_status_and_state(results, 'existing-tcont-added')
 
             ################################################################################
             # GEMS  (GemPortNetworkCtp and GemInterworkingTp)
@@ -321,15 +326,16 @@
 
                     # TODO: Need to restore on failure.  Need to check status/results
                     results = yield gem_port.add_to_hardware(omci_cc,
-                                                   tcont.entity_id,
-                                                   self._ieee_mapper_service_profile_entity_id +
-                                                             self._uni_port.mac_bridge_port_num,
-                                                   self._gal_enet_profile_entity_id,
-                                                   ul_prior_q_entity_id, dl_prior_q_entity_id)
-                    self.check_status_and_state(results, 'create-gem-port')
+                                             tcont.entity_id,
+                                             self._ieee_mapper_service_profile_entity_id +
+                                                      self._uni_port.mac_bridge_port_num,
+                                             self._gal_enet_profile_entity_id,
+                                             ul_prior_q_entity_id, dl_prior_q_entity_id)
+                    self.check_status_and_state(results, 'assign-gem-port')
                 elif gem_port.direction == "downstream":
                     # Downstream is inverse of upstream
                     # TODO: could also be a case of multicast. Not supported for now
+                    self.log.debug("skipping-downstream-gem", gem_port=gem_port)
                     pass
 
             ################################################################################
diff --git a/voltha/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py b/voltha/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py
index 9f605d2..c304a27 100644
--- a/voltha/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py
+++ b/voltha/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py
@@ -86,7 +86,7 @@
             # lock the whole ont and all the pptp.  some onu dont causing odd behavior.
             msg = OntGFrame(attributes={'administrative_state': state})
             frame = msg.set()
-            self.log.debug('openomci-msg', msg=msg)
+            self.log.debug('openomci-msg', omci_msg=msg)
             results = yield self._device.omci_cc.send(frame)
             self.strobe_watchdog()
 
@@ -124,7 +124,7 @@
     @inlineCallbacks
     def _send_uni_lock_msg(self, entity_id, value, me_message):
         frame = me_message.set()
-        self.log.debug('openomci-msg', msg=me_message)
+        self.log.debug('openomci-msg', omci_msg=me_message)
         results = yield self._device.omci_cc.send(frame)
         self.strobe_watchdog()
 
diff --git a/voltha/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py b/voltha/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py
index a46db8c..6c665c7 100644
--- a/voltha/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py
+++ b/voltha/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py
@@ -90,7 +90,7 @@
             # Delete bridge ani side vlan filter
             msg = VlanTaggingFilterDataFrame(_mac_bridge_port_ani_entity_id + self._uni_port.mac_bridge_port_num)
             frame = msg.delete()
-            self.log.debug('openomci-msg', msg=msg)
+            self.log.debug('openomci-msg', omci_msg=msg)
             self.strobe_watchdog()
             results = yield self._device.omci_cc.send(frame)
             self.check_status_and_state(results, 'flow-delete-vlan-tagging-filter-data')
@@ -102,7 +102,7 @@
                 forward_operation=0x10
             )
             frame = msg.create()
-            self.log.debug('openomci-msg', msg=msg)
+            self.log.debug('openomci-msg', omci_msg=msg)
             self.strobe_watchdog()
             results = yield self._device.omci_cc.send(frame)
             self.check_status_and_state(results, 'flow-create-vlan-tagging-filter-data')
@@ -140,7 +140,7 @@
                 attributes=attributes  # See above
             )
             frame = msg.set()
-            self.log.debug('openomci-msg', msg=msg)
+            self.log.debug('openomci-msg', omci_msg=msg)
             self.strobe_watchdog()
             results = yield self._device.omci_cc.send(frame)
             self.check_status_and_state(results,
@@ -176,7 +176,7 @@
                 attributes=attributes  # See above
             )
             frame = msg.set()
-            self.log.debug('openomci-msg', msg=msg)
+            self.log.debug('openomci-msg', omci_msg=msg)
             self.strobe_watchdog()
             results = yield self._device.omci_cc.send(frame)
             self.check_status_and_state(results,
diff --git a/voltha/adapters/brcm_openomci_onu/onu_gem_port.py b/voltha/adapters/brcm_openomci_onu/onu_gem_port.py
index 42457ee..b388030 100644
--- a/voltha/adapters/brcm_openomci_onu/onu_gem_port.py
+++ b/voltha/adapters/brcm_openomci_onu/onu_gem_port.py
@@ -26,7 +26,8 @@
     Broadcom ONU specific implementation
     """
 
-    def __init__(self, gem_id, uni_id, alloc_id, entity_id,
+    def __init__(self, gem_id, uni_id, alloc_id,
+                 entity_id=None,
                  direction="BIDIRECTIONAL",
                  encryption=False,
                  discard_config=None,
@@ -88,7 +89,10 @@
         self.tx_bytes = 0
 
     def __str__(self):
-        return "alloc-id: {}, gem-id: {}".format(self.alloc_id, self.gem_id)
+        return "OnuGemPort - entity_id {}, alloc-id: {}, gem-id: {}, ".format(self.entity_id, self.alloc_id, self.gem_id)
+
+    def __repr__(self):
+        return str(self)
 
     @property
     def pon_id(self):
@@ -163,6 +167,11 @@
         self.log.debug('function-entry')
         return self._entity_id
 
+    @entity_id.setter
+    def entity_id(self, value):
+        self.log.debug('function-entry')
+        self._entity_id = value
+
     @property
     def encryption(self):
         self.log.debug('function-entry')
@@ -252,13 +261,12 @@
         self._scheduling_policy = scheduling_policy
 
     @staticmethod
-    def create(handler, gem_port, entity_id):
-        log.debug('function-entry', gem_port=gem_port, entity_id=entity_id)
+    def create(handler, gem_port):
+        log.debug('function-entry', gem_port=gem_port)
 
         return OnuGemPort(gem_id=gem_port['gemport_id'],
                           uni_id=gem_port['uni_id'],
                           alloc_id=gem_port['alloc_id_ref'],
-                          entity_id=entity_id,
                           direction=gem_port['direction'],
                           encryption=gem_port['encryption'],  # aes_indicator,
                           discard_config=gem_port['discard_config'],
@@ -278,7 +286,6 @@
                         gal_enet_profile_entity_id,
                         ul_prior_q_entity_id,
                         dl_prior_q_entity_id):
-        self.log.debug('function-entry')
 
         self.log.debug('add-to-hardware', entity_id=self.entity_id, gem_id=self.gem_id,
                        tcont_entity_id=tcont_entity_id,
@@ -291,7 +298,6 @@
             direction = "downstream" if self.multicast else "bi-directional"
             assert not self.multicast, 'MCAST is not supported yet'
 
-            # TODO: magic numbers here
             attributes = dict()
             attributes['priority_queue_pointer_downstream'] = dl_prior_q_entity_id
             msg = GemPortNetworkCtpFrame(
diff --git a/voltha/adapters/brcm_openomci_onu/onu_tcont.py b/voltha/adapters/brcm_openomci_onu/onu_tcont.py
index 1e22bdb..c5414ee 100644
--- a/voltha/adapters/brcm_openomci_onu/onu_tcont.py
+++ b/voltha/adapters/brcm_openomci_onu/onu_tcont.py
@@ -40,6 +40,13 @@
         self._handler = handler
         self._entity_id = None
 
+    def __str__(self):
+        return "OnuTCont - uni_id: {}, entity_id {}, alloc-id: {}, q_sched_policy: {}, traffic_descriptor: {}".format(
+            self.uni_id, self._entity_id, self.alloc_id, self.q_sched_policy, self.traffic_descriptor)
+
+    def __repr__(self):
+        return str(self)
+
     @property
     def entity_id(self):
         self.log.debug('function-entry')
@@ -73,7 +80,6 @@
 
     @inlineCallbacks
     def add_to_hardware(self, omci, tcont_entity_id):
-        self.log.debug('function-entry', omci=omci, tcont_entity_id=tcont_entity_id)
         self.log.debug('add-to-hardware', tcont_entity_id=tcont_entity_id)
 
         self._entity_id = tcont_entity_id
diff --git a/voltha/adapters/brcm_openomci_onu/pon_port.py b/voltha/adapters/brcm_openomci_onu/pon_port.py
index fbde551..db1daa8 100644
--- a/voltha/adapters/brcm_openomci_onu/pon_port.py
+++ b/voltha/adapters/brcm_openomci_onu/pon_port.py
@@ -49,13 +49,15 @@
         self._gem_ports = {}                           # gem-id -> GemPort
         self._tconts = {}                              # alloc-id -> TCont
 
-        self.pon_port_num = 3  # TODO why 3.  maybe this is the ani port number.  look at anis list
-
         self.ieee_mapper_service_profile_entity_id = 0x8001
         self.mac_bridge_port_ani_entity_id = 0x2102  # TODO: can we just use the entity id from the anis list?
 
     def __str__(self):
-        return "PonPort"      # TODO: Encode current state
+        return "PonPort - port_number: {}, next_entity_id: {}, num_gem_ports: {}, num_tconts: {}".format(
+            self._port_number, self._next_entity_id, len(self._gem_ports), len(self._tconts))
+
+    def __repr__(self):
+        return str(self)
 
     @staticmethod
     def create(handler, port_no):
@@ -256,10 +258,12 @@
         if not self._valid:
             return  # Deleting
 
-        if not reflow and gem_port.gem_id in self._gem_ports:
+        if not reflow and (gem_port.gem_id, gem_port.direction) in self._gem_ports:
             return  # nop
 
-        self.log.info('add-gem-port', gem_port=gem_port.gem_id, reflow=reflow)
+        # if this is actually a new gem port then issue the next entity_id
+        gem_port.entity_id = self.next_gem_entity_id
+        self.log.info('add-gem-port', gem_port=gem_port, reflow=reflow)
         self._gem_ports[(gem_port.gem_id, gem_port.direction)] = gem_port
 
     @inlineCallbacks
diff --git a/voltha/adapters/brcm_openomci_onu/uni_port.py b/voltha/adapters/brcm_openomci_onu/uni_port.py
index c8aca6b..2ee307b 100644
--- a/voltha/adapters/brcm_openomci_onu/uni_port.py
+++ b/voltha/adapters/brcm_openomci_onu/uni_port.py
@@ -55,7 +55,11 @@
         self._oper_status = OperStatus.ACTIVE
 
     def __str__(self):
-        return "UniPort: {}:{}".format(self.name, self.port_number)
+        return "UniPort - name: {}, port_number: {}, entity_id: {}, mac_bridge_port_num: {}, type: {}, ofp_port: {}"\
+            .format(self.name, self.port_number, self.entity_id, self._mac_bridge_port_num, self.type, self._ofp_port_no)
+
+    def __repr__(self):
+        return str(self)
 
     @staticmethod
     def create(handler, name, uni_id, port_no, ofp_port_no, type):
diff --git a/voltha/extensions/omci/me_frame.py b/voltha/extensions/omci/me_frame.py
index cf1cf3e..1724100 100644
--- a/voltha/extensions/omci/me_frame.py
+++ b/voltha/extensions/omci/me_frame.py
@@ -42,6 +42,9 @@
         return '{}: Entity_ID: {}, Data: {}'.\
             format(self.entity_class_name, self._entity_id, self.data)
 
+    def __repr__(self):
+        return str(self)
+
     @property
     def entity_class(self):
         """