VOL-1323: Log message cleanup of OpenOMCI code
Change-Id: I4826b5ef80992fb41021ab0092404355f05361a7
diff --git a/voltha/extensions/omci/state_machines/alarm_sync.py b/voltha/extensions/omci/state_machines/alarm_sync.py
index dee6d83..4f4de31 100644
--- a/voltha/extensions/omci/state_machines/alarm_sync.py
+++ b/voltha/extensions/omci/state_machines/alarm_sync.py
@@ -305,7 +305,7 @@
self._task_deferred.addCallbacks(success, failure)
def reconcile_alarm_table(self, results):
- self.log.info('alarm-reconcile', state=self.state, results=results)
+ self.log.debug('alarm-reconcile', state=self.state, results=results)
onu_only = results['onu-only']
olt_only = results['olt-only']
@@ -390,7 +390,7 @@
:param _topic: (str) OMCI-RX topic
:param msg: (dict) Dictionary with 'rx-response' and 'tx-request' (if any)
"""
- self.log.info('on-alarm-update-response', state=self.state, msg=msg)
+ self.log.debug('on-alarm-update-response', state=self.state, msg=msg)
if self._omci_cc_subscriptions[RxEvent.Get_ALARM_Get]:
if self.state == 'disabled':
@@ -404,7 +404,7 @@
isinstance(response.fields.get('omci_message'), OmciGetAllAlarmsResponse):
# ONU will reset its last alarm sequence number to 0 on receipt of the
# Get All Alarms request
- self.log.info('received alarm response')
+ self.log.debug('received-alarm-response')
self.reset_alarm_sequence()
except Exception as e:
@@ -419,7 +419,7 @@
TX_REQUEST_KEY -> None (this is an autonomous msg)
RX_RESPONSE_KEY -> OmciMessage (Alarm notification frame)
"""
- self.log.info('on-alarm-update-response', state=self.state, msg=msg)
+ self.log.debug('on-alarm-update-response', state=self.state, msg=msg)
alarm_msg = msg.get(RX_RESPONSE_KEY)
if alarm_msg is not None:
diff --git a/voltha/extensions/omci/state_machines/mib_sync.py b/voltha/extensions/omci/state_machines/mib_sync.py
index b63e36b..16f29b2 100644
--- a/voltha/extensions/omci/state_machines/mib_sync.py
+++ b/voltha/extensions/omci/state_machines/mib_sync.py
@@ -170,6 +170,11 @@
queued=True,
name='{}-{}'.format(self.__class__.__name__,
device_id))
+ try:
+ import logging
+ logging.getLogger('transitions').setLevel(logging.WARNING)
+ except Exception as e:
+ self.log.exception('log-level-failed', e=e)
def _cancel_deferred(self):
d1, self._deferred = self._deferred, None
@@ -843,7 +848,7 @@
if modified:
self.increment_mib_data_sync()
- except KeyError as e:
+ except KeyError as _e:
pass # NOP
except Exception as e:
self.log.exception('set', e=e)
diff --git a/voltha/extensions/omci/state_machines/performance_intervals.py b/voltha/extensions/omci/state_machines/performance_intervals.py
index 8144a56..0b8d9c4 100644
--- a/voltha/extensions/omci/state_machines/performance_intervals.py
+++ b/voltha/extensions/omci/state_machines/performance_intervals.py
@@ -182,6 +182,12 @@
ignore_invalid_triggers=True,
name='{}-{}'.format(self.__class__.__name__,
device_id))
+ try:
+ import logging
+ logging.getLogger('transitions').setLevel(logging.WARNING)
+ except Exception as e:
+ self.log.exception('log-level-failed', e=e)
+
def _cancel_deferred(self):
d1, self._deferred = self._deferred, None
@@ -411,7 +417,7 @@
instances[entity_id] = (cid, eid)
except Exception as e:
- self.log.exception('pm-me-setup', e=e)
+ self.log.exception('pm-me-setup', class_id=class_id, e=e)
# Got to synchronize_time state
self._deferred = reactor.callLater(0, self.tick)
@@ -562,7 +568,7 @@
"""
if self._next_interval is not None and self._next_interval > datetime.utcnow():
- self.log.info('wait-next-interval')
+ self.log.debug('wait-next-interval')
# Not ready for next interval, transition back to idle and we should get
# called again after a short delay
reactor.callLater(0, self.success)
@@ -578,14 +584,14 @@
class_id = key[0]
entity_id = key[1]
- self.log.info("in-enter-collect-data", key=key, retries=self._pm_me_collect_retries[key])
+ self.log.debug("in-enter-collect-data", key=key, retries=self._pm_me_collect_retries[key])
# Collect the data ?
if self._pm_me_collect_retries[key] > 0:
def success(results):
- self.log.info('collect-success', results=results,
- class_id=results.get('class_id'),
- entity_id=results.get('entity_id'))
+ self.log.debug('collect-success', results=results,
+ class_id=results.get('class_id'),
+ entity_id=results.get('entity_id'))
self._current_task = None
self._pm_me_collect_retries[key] = 0
self._deferred = reactor.callLater(0, self.success)
@@ -599,8 +605,6 @@
return reason # Halt callback processing
# start the task
- self.log.info('collect-task-start')
-
if key in self._pm_me_extended_info:
self.log.debug('collect-extended-info-found', key=key, extended_info=self._pm_me_extended_info[key])
parent_class_id = self._pm_me_extended_info[key][0]
@@ -624,7 +628,7 @@
# Here if all intervals have been collected (we are up to date)
self._next_interval = self.get_next_interval
- self.log.info('collect-calculate-next', next=self._next_interval)
+ self.log.debug('collect-calculate-next', next=self._next_interval)
self._pm_me_collect_retries = dict.fromkeys(self._pm_me_collect_retries, self._collect_attempts)
reactor.callLater(0, self.success)
diff --git a/voltha/extensions/omci/tasks/alarm_resync_task.py b/voltha/extensions/omci/tasks/alarm_resync_task.py
index 1007724..a16f3a2 100644
--- a/voltha/extensions/omci/tasks/alarm_resync_task.py
+++ b/voltha/extensions/omci/tasks/alarm_resync_task.py
@@ -116,7 +116,7 @@
During the alarm upload process, the maximum time between alarm upload next
requests is 1 minute.
"""
- self.log.info('perform-alarm-resync')
+ self.log.debug('perform-alarm-resync')
try:
self.strobe_watchdog()
diff --git a/voltha/extensions/omci/tasks/get_mds_task.py b/voltha/extensions/omci/tasks/get_mds_task.py
index 325fa1a..1560c83 100644
--- a/voltha/extensions/omci/tasks/get_mds_task.py
+++ b/voltha/extensions/omci/tasks/get_mds_task.py
@@ -75,7 +75,7 @@
"""
Get the 'mib_data_sync' attribute of the ONU
"""
- self.log.info('perform-get-mds')
+ self.log.debug('perform-get-mds')
try:
device = self.omci_agent.get_device(self.device_id)
diff --git a/voltha/extensions/omci/tasks/interval_data_task.py b/voltha/extensions/omci/tasks/interval_data_task.py
index 369f817..d41c1d0 100644
--- a/voltha/extensions/omci/tasks/interval_data_task.py
+++ b/voltha/extensions/omci/tasks/interval_data_task.py
@@ -186,7 +186,8 @@
final_results[attribute] = omci_msg['data'].get(attribute)
except TimeoutError as e:
- self.log.warn('interval-get-timeout', e=e, class_id=self._class_id)
+ self.log.warn('interval-get-timeout', e=e, class_id=self._class_id,
+ entity_id=self._entity_id, attributes=attributes)
self.deferred.errback(failure.Failure(e))
except Exception as e:
diff --git a/voltha/extensions/omci/tasks/mib_resync_task.py b/voltha/extensions/omci/tasks/mib_resync_task.py
index 52cf0b0..ef9c531 100644
--- a/voltha/extensions/omci/tasks/mib_resync_task.py
+++ b/voltha/extensions/omci/tasks/mib_resync_task.py
@@ -122,7 +122,7 @@
During the mib upload process, the maximum time between mib upload next
requests is 1 minute.
"""
- self.log.info('perform-mib-resync')
+ self.log.debug('perform-mib-resync')
try:
results = yield self.snapshot_mib()
diff --git a/voltha/extensions/omci/tasks/mib_upload.py b/voltha/extensions/omci/tasks/mib_upload.py
index 639f8fd..4afd234 100644
--- a/voltha/extensions/omci/tasks/mib_upload.py
+++ b/voltha/extensions/omci/tasks/mib_upload.py
@@ -85,7 +85,7 @@
"""
Perform the MIB Upload sequence
"""
- self.log.info('perform-mib-upload')
+ self.log.debug('perform-mib-upload')
seq_no = 0
number_of_commands = 0
diff --git a/voltha/extensions/omci/tasks/omci_delete_pm_task.py b/voltha/extensions/omci/tasks/omci_delete_pm_task.py
index 7906a83..adf1ce2 100644
--- a/voltha/extensions/omci/tasks/omci_delete_pm_task.py
+++ b/voltha/extensions/omci/tasks/omci_delete_pm_task.py
@@ -71,7 +71,7 @@
@inlineCallbacks
def perform_delete(self):
""" Perform the delete requests """
- self.log.info('perform-delete')
+ self.log.debug('perform-delete')
try:
for me in self._me_tuples:
@@ -90,7 +90,7 @@
results = yield self._device.omci_cc.send(frame)
status = results.fields['omci_message'].fields['success_code']
- self.log.info('perform-delete-status', status=status)
+ self.log.debug('perform-delete-status', status=status)
# Did it fail, it instance does not exist, not an error
if status != RC.Success.value and status != RC.UnknownInstance.value:
diff --git a/voltha/extensions/omci/tasks/omci_get_request.py b/voltha/extensions/omci/tasks/omci_get_request.py
index 0a5b1ec..45c1db4 100644
--- a/voltha/extensions/omci/tasks/omci_get_request.py
+++ b/voltha/extensions/omci/tasks/omci_get_request.py
@@ -148,7 +148,7 @@
"""
Perform the initial get request
"""
- self.log.info('perform-get')
+ self.log.debug('perform-get')
try:
frame = MEFrame(self._entity_class, self._entity_id, self._attributes).get()
@@ -156,7 +156,7 @@
results = yield self._device.omci_cc.send(frame)
status = results.fields['omci_message'].fields['success_code']
- self.log.info('perform-get-status', status=status)
+ self.log.debug('perform-get-status', status=status)
# Success?
if status == RC.Success.value:
@@ -192,7 +192,7 @@
else:
raise GetException('Get failed with status code: {}'.format(status))
- self.log.info('get-completed')
+ self.log.debug('get-completed')
self.deferred.callback(self)
except TimeoutError as e:
@@ -215,7 +215,7 @@
:param missing_attr: (set) Missing attributes
"""
- self.log.info('perform-get-missing', attrs=missing_attr)
+ self.log.debug('perform-get-missing', attrs=missing_attr)
results_omci = self._results.fields['omci_message'].fields
@@ -265,7 +265,7 @@
:param attributes:
:return:
"""
- self.log.info('perform-get-failed', attrs=attributes)
+ self.log.debug('perform-get-failed', attrs=attributes)
for attr in attributes:
try:
@@ -277,7 +277,7 @@
status = results.fields['omci_message'].fields['success_code']
if status == RC.AttributeFailure.value:
- self.log.info('unknown-or-invalid-attribute', attr=attr, status=status)
+ self.log.debug('unknown-or-invalid-attribute', attr=attr, status=status)
self._failed_or_unknown_attributes.add(attr)
elif status != RC.Success.value:
diff --git a/voltha/extensions/omci/tasks/omci_modify_request.py b/voltha/extensions/omci/tasks/omci_modify_request.py
index 27dfb3d..da7bff5 100644
--- a/voltha/extensions/omci/tasks/omci_modify_request.py
+++ b/voltha/extensions/omci/tasks/omci_modify_request.py
@@ -151,14 +151,14 @@
"""
Perform the request
"""
- self.log.info('perform-request')
+ self.log.debug('perform-request')
try:
self.strobe_watchdog()
self._results = yield self._device.omci_cc.send(self._frame)
status = self._results.fields['omci_message'].fields['success_code']
- self.log.info('response-status', status=status)
+ self.log.debug('response-status', status=status)
# Success?
if status in (RC.Success.value, RC.InstanceExists):
diff --git a/voltha/extensions/omci/tasks/onu_capabilities_task.py b/voltha/extensions/omci/tasks/onu_capabilities_task.py
index e93d0ed..048382c 100644
--- a/voltha/extensions/omci/tasks/onu_capabilities_task.py
+++ b/voltha/extensions/omci/tasks/onu_capabilities_task.py
@@ -134,7 +134,7 @@
Then a loop is entered and get-next commands are sent for each sequence
requested.
"""
- self.log.info('perform-get')
+ self.log.debug('perform-get')
try:
self.strobe_watchdog()
diff --git a/voltha/extensions/omci/tasks/sync_time_task.py b/voltha/extensions/omci/tasks/sync_time_task.py
index 7686cb4..b5b1dc9 100644
--- a/voltha/extensions/omci/tasks/sync_time_task.py
+++ b/voltha/extensions/omci/tasks/sync_time_task.py
@@ -75,7 +75,7 @@
"""
Sync the time
"""
- self.log.info('perform-sync-time')
+ self.log.debug('perform-sync-time')
try:
device = self.omci_agent.get_device(self.device_id)