VOL-2311: Better logging and remove old code

- tasks have better detail
- 1.x functions removed
- extraineous logging removed
- build info injected into environment, viewable
  in log and voltctl similar to openolt

Change-Id: I9b22334c3049efa857b485cca28a343b36514ab6
diff --git a/python/adapters/brcm_openomci_onu/omci/brcm_capabilities_task.py b/python/adapters/brcm_openomci_onu/omci/brcm_capabilities_task.py
index b6ca406..80e6463 100644
--- a/python/adapters/brcm_openomci_onu/omci/brcm_capabilities_task.py
+++ b/python/adapters/brcm_openomci_onu/omci/brcm_capabilities_task.py
@@ -14,7 +14,6 @@
 # limitations under the License.
 
 from __future__ import absolute_import
-import structlog
 from pyvoltha.adapters.extensions.omci.tasks.onu_capabilities_task import OnuCapabilitiesTask
 from twisted.internet.defer import failure
 
@@ -44,9 +43,6 @@
         :param omci_agent: (OmciAdapterAgent) OMCI Adapter agent
         :param device_id: (str) ONU Device ID
         """
-        self.log = structlog.get_logger(device_id=device_id)
-        self.log.debug('function-entry')
-
         super(BrcmCapabilitiesTask, self).__init__(omci_agent, device_id)
         self._omci_managed = False      # TODO: Look up capabilities/model number
 
@@ -59,7 +55,6 @@
 
         :return: (set of ints)
         """
-        self.log.debug('function-entry')
 
         if self._omci_managed:
             return super(BrcmCapabilitiesTask, self).supported_managed_entities
@@ -83,7 +78,6 @@
 
         :return: (set of EntityOperations)
         """
-        self.log.debug('function-entry')
 
         if self._omci_managed:
             return super(BrcmCapabilitiesTask, self).supported_message_types
@@ -127,7 +121,6 @@
         Then a loop is entered and get-next commands are sent for each sequence
         requested.
         """
-        self.log.debug('function-entry')
 
         self.log.info('perform-get')
 
diff --git a/python/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py b/python/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py
index eaa8ff5..b0fe3d8 100644
--- a/python/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py
+++ b/python/adapters/brcm_openomci_onu/omci/brcm_mib_download_task.py
@@ -13,7 +13,6 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
-import structlog
 from twisted.internet import reactor
 from twisted.internet.defer import inlineCallbacks, returnValue, TimeoutError, failure
 from pyvoltha.adapters.extensions.omci.omci_me import PptpEthernetUniFrame, GalEthernetProfileFrame, \
@@ -65,10 +64,6 @@
         :param omci_agent: (OmciAdapterAgent) OMCI Adapter agent
         :param device_id: (str) ONU Device ID
         """
-
-        self.log = structlog.get_logger(device_id=handler.device_id)
-        self.log.debug('function-entry')
-
         super(BrcmMibDownloadTask, self).__init__(BrcmMibDownloadTask.name,
                                                   omci_agent,
                                                   handler.device_id,
@@ -102,7 +97,6 @@
         self._free_dl_prior_q_entity_ids = set()
 
     def cancel_deferred(self):
-        self.log.debug('function-entry')
         super(BrcmMibDownloadTask, self).cancel_deferred()
 
         d, self._local_deferred = self._local_deferred, None
@@ -116,7 +110,6 @@
         """
         Start the MIB Download
         """
-        self.log.debug('function-entry')
         super(BrcmMibDownloadTask, self).start()
         self._local_deferred = reactor.callLater(0, self.perform_mib_download)
 
@@ -124,9 +117,6 @@
         """
         Shutdown MIB Synchronization tasks
         """
-        self.log.debug('function-entry')
-        self.log.debug('stopping')
-
         self.cancel_deferred()
         super(BrcmMibDownloadTask, self).stop()
 
@@ -139,7 +129,6 @@
         :param operation: (str) what operation was being performed
         :return: True if successful, False if the entity existed (already created)
         """
-        self.log.debug('function-entry')
 
         omci_msg = results.fields['omci_message'].fields
         status = omci_msg['success_code']
@@ -170,7 +159,6 @@
         and other characteristics are done as needed.
         """
         try:
-            self.log.debug('function-entry')
             self.log.info('perform-download')
 
             if self._handler.enabled and len(self._handler.uni_ports) > 0:
@@ -207,7 +195,6 @@
 
     @inlineCallbacks
     def perform_initial_bridge_setup(self):
-        self.log.debug('function-entry')
 
         omci_cc = self._onu_device.omci_cc
         try:
@@ -240,7 +227,6 @@
 
     @inlineCallbacks
     def perform_uni_initial_bridge_setup(self, uni_port):
-        self.log.debug('function-entry')
         omci_cc = self._onu_device.omci_cc
         frame = None
         try:
diff --git a/python/adapters/brcm_openomci_onu/omci/brcm_tp_delete_task.py b/python/adapters/brcm_openomci_onu/omci/brcm_tp_delete_task.py
index b75d791..3fa3ddc 100644
--- a/python/adapters/brcm_openomci_onu/omci/brcm_tp_delete_task.py
+++ b/python/adapters/brcm_openomci_onu/omci/brcm_tp_delete_task.py
@@ -60,16 +60,17 @@
         :param uni_id: (int) numeric id of the uni port on the onu device, starts at 0
         :param tp_table_id: (int) Technology Profile Table-ID
         """
-        log = structlog.get_logger(device_id=handler.device_id, uni_id=uni_id)
-        log.debug('function-entry')
-
         super(BrcmTpDeleteTask, self).__init__(BrcmTpDeleteTask.name,
                                                omci_agent,
                                                handler.device_id,
                                                priority=DELETE_TP_TASK_PRIORITY,
                                                exclusive=True)
 
-        self.log = log
+        self.log = structlog.get_logger(device_id=handler.device_id,
+                                        name=BrcmTpDeleteTask.name,
+                                        task_id=self._task_id,
+                                        uni_id=uni_id,
+                                        tp_table_id=tp_table_id)
 
         self._onu_device = omci_agent.get_device(handler.device_id)
         self._local_deferred = None
@@ -96,7 +97,6 @@
             handler.pon_port.mac_bridge_port_ani_entity_id
 
     def cancel_deferred(self):
-        self.log.debug('function-entry')
         super(BrcmTpDeleteTask, self).cancel_deferred()
 
         d, self._local_deferred = self._local_deferred, None
@@ -110,7 +110,6 @@
         """
         Start the Tech-Profile Delete
         """
-        self.log.debug('function-entry')
         super(BrcmTpDeleteTask, self).start()
         if self._tcont is not None:
             self._local_deferred = reactor.callLater(0, self.delete_tcont_and_associated_me)
@@ -123,9 +122,6 @@
         """
         Shutdown Tech-Profile delete tasks
         """
-        self.log.debug('function-entry')
-        self.log.debug('stopping')
-
         self.cancel_deferred()
         super(BrcmTpDeleteTask, self).stop()
 
@@ -138,7 +134,6 @@
         :param operation: (str) what operation was being performed
         :return: True if successful, False if the entity existed (already created)
         """
-        self.log.debug('function-entry')
 
         omci_msg = results.fields['omci_message'].fields
         status = omci_msg['success_code']
@@ -162,7 +157,7 @@
 
     @inlineCallbacks
     def delete_tcont_and_associated_me(self):
-        self.log.debug('function-entry')
+        self.log.info('deleting-tcont')
 
         omci_cc = self._onu_device.omci_cc
 
@@ -213,6 +208,8 @@
 
     @inlineCallbacks
     def delete_gem_port_nw_ctp_and_associated_me(self):
+        self.log.info('deleting-gem-port-iw')
+
         omci_cc = self._onu_device.omci_cc
         try:
             ################################################################################
diff --git a/python/adapters/brcm_openomci_onu/omci/brcm_tp_setup_task.py b/python/adapters/brcm_openomci_onu/omci/brcm_tp_setup_task.py
index cca0b06..d93224a 100644
--- a/python/adapters/brcm_openomci_onu/omci/brcm_tp_setup_task.py
+++ b/python/adapters/brcm_openomci_onu/omci/brcm_tp_setup_task.py
@@ -59,16 +59,19 @@
         :param uni_id: (int) numeric id of the uni port on the onu device, starts at 0
         :param tp_table_id: (int) Technology Profile Table-ID
         """
-        log = structlog.get_logger(device_id=handler.device_id, uni_id=uni_id)
-        log.debug('function-entry')
-
         super(BrcmTpSetupTask, self).__init__(BrcmTpSetupTask.name,
                                               omci_agent,
                                               handler.device_id,
                                               priority=SETUP_TP_TASK_PRIORITY,
                                               exclusive=True)
 
-        self.log = log
+        self.log = structlog.get_logger(device_id=handler.device_id,
+                                        name=BrcmTpSetupTask.name,
+                                        task_id=self._task_id,
+                                        tconts=tconts,
+                                        gem_ports=gem_ports,
+                                        uni_id=uni_id,
+                                        tp_table_id=tp_table_id)
 
         self._onu_device = omci_agent.get_device(handler.device_id)
         self._local_deferred = None
@@ -103,7 +106,6 @@
         self.uni_port_to_queue_map = dict()
 
     def cancel_deferred(self):
-        self.log.debug('function-entry')
         super(BrcmTpSetupTask, self).cancel_deferred()
 
         d, self._local_deferred = self._local_deferred, None
@@ -117,7 +119,6 @@
         """
         Start the Tech-Profile Download
         """
-        self.log.debug('function-entry')
         super(BrcmTpSetupTask, self).start()
         self._local_deferred = reactor.callLater(0, self.perform_service_specific_steps)
 
@@ -125,9 +126,6 @@
         """
         Shutdown Tech-Profile download tasks
         """
-        self.log.debug('function-entry')
-        self.log.debug('stopping')
-
         self.cancel_deferred()
         super(BrcmTpSetupTask, self).stop()
 
@@ -140,7 +138,6 @@
         :param operation: (str) what operation was being performed
         :return: True if successful, False if the entity existed (already created)
         """
-        self.log.debug('function-entry')
 
         omci_msg = results.fields['omci_message'].fields
         status = omci_msg['success_code']
@@ -164,7 +161,7 @@
 
     @inlineCallbacks
     def perform_service_specific_steps(self):
-        self.log.debug('function-entry')
+        self.log.info('creating-tcont-mapper-gemport-iw')
 
         omci_cc = self._onu_device.omci_cc
         gem_pq_associativity = dict()
diff --git a/python/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py b/python/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py
index 2edd43c..3884620 100644
--- a/python/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py
+++ b/python/adapters/brcm_openomci_onu/omci/brcm_uni_lock_task.py
@@ -15,6 +15,7 @@
 #
 
 from __future__ import absolute_import
+import structlog
 from pyvoltha.adapters.extensions.omci.tasks.task import Task
 from twisted.internet import reactor
 from twisted.internet.defer import inlineCallbacks, failure, returnValue
@@ -51,6 +52,12 @@
                                               device_id,
                                               priority=priority,
                                               exclusive=True)
+
+        self.log = structlog.get_logger(device_id=device_id,
+                                        name=BrcmUniLockTask.name,
+                                        task_id=self._task_id,
+                                        setting_lock=lock)
+
         self._device = omci_agent.get_device(device_id)
         self._lock = lock
         self._results = None
diff --git a/python/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py b/python/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py
index deee947..6f704fd 100644
--- a/python/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py
+++ b/python/adapters/brcm_openomci_onu/omci/brcm_vlan_filter_task.py
@@ -52,14 +52,20 @@
         :param tp_id: (int) TP ID for the flow
         :param priority: (int) OpenOMCI Task priority (0..255) 255 is the highest
         """
-
-        self.log = structlog.get_logger(device_id=handler.device_id, uni_port=uni_port.port_number)
-
         super(BrcmVlanFilterTask, self).__init__(BrcmVlanFilterTask.name,
                                                  omci_agent,
                                                  handler.device_id,
                                                  priority=priority,
                                                  exclusive=True)
+
+        self.log = structlog.get_logger(device_id=handler.device_id,
+                                        name=BrcmVlanFilterTask.name,
+                                        task_id=self._task_id,
+                                        entity_id=uni_port.entity_id,
+                                        uni_id=uni_port.uni_id,
+                                        uni_port=uni_port.port_number,
+                                        set_vlan_id=set_vlan_id)
+
         self._device = omci_agent.get_device(handler.device_id)
         self._uni_port = uni_port
         self._set_vlan_id = set_vlan_id