From 2d197a3bd822815ca7ffe0dc5183014f542cfcdf Mon Sep 17 00:00:00 2001 From: Joshua Harlow Date: Thu, 13 Mar 2014 23:36:40 -0700 Subject: [PATCH] Adjust logging levels and usage to follow standards A few of our logging levels and messages should be updated to better reflect the oslo logging standards created at https://wiki.openstack.org/LoggingStandards so update some of them to not report error when its really warning level and not report warning when debug is better. Change-Id: I8abdb1bcfa2893c6b97eda7e85ac779e456966b8 --- taskflow/jobs/backends/impl_zookeeper.py | 19 ++++++++++--------- taskflow/listeners/base.py | 4 ++-- taskflow/listeners/timing.py | 4 ++-- .../persistence/backends/impl_sqlalchemy.py | 4 ++-- taskflow/task.py | 11 ++++++----- taskflow/tests/unit/test_task.py | 16 ++++++++-------- taskflow/utils/lock_utils.py | 2 +- taskflow/utils/misc.py | 4 ++-- 8 files changed, 33 insertions(+), 31 deletions(-) diff --git a/taskflow/jobs/backends/impl_zookeeper.py b/taskflow/jobs/backends/impl_zookeeper.py index 75e4dc52..8095bb6d 100644 --- a/taskflow/jobs/backends/impl_zookeeper.py +++ b/taskflow/jobs/backends/impl_zookeeper.py @@ -224,19 +224,20 @@ class ZookeeperJobBoard(jobboard.JobBoard): details=job_data.get("details", {})) self._known_jobs[path] = (job, _READY) except (ValueError, TypeError, KeyError): - LOG.exception("Incorrectly formatted job data found" - " at path: %s", path) + LOG.warn("Incorrectly formatted job data found at path: %s", + path, exc_info=True) except self._client.handler.timeout_exception: - LOG.warn("Connection timed out fetching job data" - " from path: %s", path) + LOG.warn("Connection timed out fetching job data from path: %s", + path, exc_info=True) except k_exceptions.SessionExpiredError: - LOG.warn("Session expired fetching job data from path: %s", path) + LOG.warn("Session expired fetching job data from path: %s", path, + exc_info=True) except k_exceptions.NoNodeError: - LOG.warn("No job node found at path: %s, it must have" - " disappeared or was removed", path) + LOG.debug("No job node found at path: %s, it must have" + " disappeared or was removed", path) except k_exceptions.KazooException: - LOG.exception("Internal error fetching job data from" - " path: %s", path) + LOG.warn("Internal error fetching job data from path: %s", + path, exc_info=True) def _on_job_posting(self, children): LOG.debug("Got children %s under path %s", children, self.path) diff --git a/taskflow/listeners/base.py b/taskflow/listeners/base.py index bbf62c76..1e767def 100644 --- a/taskflow/listeners/base.py +++ b/taskflow/listeners/base.py @@ -106,8 +106,8 @@ class ListenerBase(object): self.deregister() except Exception: # Don't let deregistering throw exceptions - LOG.exception("Failed deregistering listeners from engine %s", - self._engine) + LOG.warn("Failed deregistering listeners from engine %s", + self._engine, exc_info=True) @six.add_metaclass(abc.ABCMeta) diff --git a/taskflow/listeners/timing.py b/taskflow/listeners/timing.py index d271b8fb..449488c5 100644 --- a/taskflow/listeners/timing.py +++ b/taskflow/listeners/timing.py @@ -50,8 +50,8 @@ class TimingListener(base.ListenerBase): # Don't let storage failures throw exceptions in a listener method. self._engine.storage.update_task_metadata(task_name, meta_update) except excp.StorageError: - LOG.exception("Failure to store duration update %s for task %s", - meta_update, task_name) + LOG.warn("Failure to store duration update %s for task %s", + meta_update, task_name, exc_info=True) def _task_receiver(self, state, details): task_name = details['task_name'] diff --git a/taskflow/persistence/backends/impl_sqlalchemy.py b/taskflow/persistence/backends/impl_sqlalchemy.py index 23b34a99..48122ec2 100644 --- a/taskflow/persistence/backends/impl_sqlalchemy.py +++ b/taskflow/persistence/backends/impl_sqlalchemy.py @@ -142,10 +142,10 @@ def _ping_listener(dbapi_conn, connection_rec, connection_proxy): dbapi_conn.cursor().execute('select 1') except dbapi_conn.OperationalError as ex: if _in_any(six.text_type(ex.args[0]), MY_SQL_GONE_WAY_AWAY_ERRORS): - LOG.warn('Got mysql server has gone away: %s', ex) + LOG.warn('Got mysql server has gone away', exc_info=True) raise sa_exc.DisconnectionError("Database server went away") elif _in_any(six.text_type(ex.args[0]), POSTGRES_GONE_WAY_AWAY_ERRORS): - LOG.warn('Got postgres server has gone away: %s', ex) + LOG.warn('Got postgres server has gone away', exc_info=True) raise sa_exc.DisconnectionError("Database server went away") else: raise diff --git a/taskflow/task.py b/taskflow/task.py index 53915554..9f68710d 100644 --- a/taskflow/task.py +++ b/taskflow/task.py @@ -95,8 +95,9 @@ class BaseTask(atom.Atom): try: handler(self, event_data, *args, **kwargs) except Exception: - LOG.exception("Failed calling `%s` on event '%s'", - reflection.get_callable_name(handler), event) + LOG.warn("Failed calling `%s` on event '%s'", + reflection.get_callable_name(handler), event, + exc_info=True) @contextlib.contextmanager def autobind(self, event_name, handler_func, **kwargs): @@ -109,9 +110,9 @@ class BaseTask(atom.Atom): self.bind(event_name, handler_func, **kwargs) bound = True except ValueError: - LOG.exception("Failed binding functor `%s` as a receiver of" - " event '%s' notifications emitted from task %s", - handler_func, event_name, self) + LOG.warn("Failed binding functor `%s` as a receiver of" + " event '%s' notifications emitted from task %s", + handler_func, event_name, self, exc_info=True) try: yield self finally: diff --git a/taskflow/tests/unit/test_task.py b/taskflow/tests/unit/test_task.py index 92c86cb9..cef9145e 100644 --- a/taskflow/tests/unit/test_task.py +++ b/taskflow/tests/unit/test_task.py @@ -225,27 +225,27 @@ class TaskTest(test.TestCase): self.assertEqual(result, [1.0, 1.0, 1.0]) self.assertEqual(mocked_warn.call_count, 2) - @mock.patch.object(task.LOG, 'exception') - def test_update_progress_handler_failure(self, mocked_exception): + @mock.patch.object(task.LOG, 'warn') + def test_update_progress_handler_failure(self, mocked_warn): def progress_callback(*args, **kwargs): raise Exception('Woot!') task = ProgressTask() with task.autobind('update_progress', progress_callback): task.execute([0.5]) - mocked_exception.assert_called_once_with( + mocked_warn.assert_called_once_with( mock.ANY, reflection.get_callable_name(progress_callback), - 'update_progress') + 'update_progress', exc_info=mock.ANY) - @mock.patch.object(task.LOG, 'exception') - def test_autobind_non_existent_event(self, mocked_exception): + @mock.patch.object(task.LOG, 'warn') + def test_autobind_non_existent_event(self, mocked_warn): event = 'test-event' handler = lambda: None task = MyTask() with task.autobind(event, handler): self.assertEqual(len(task._events_listeners), 0) - mocked_exception.assert_called_once_with( - mock.ANY, handler, event, task) + mocked_warn.assert_called_once_with( + mock.ANY, handler, event, task, exc_info=mock.ANY) def test_autobind_handler_is_none(self): task = MyTask() diff --git a/taskflow/utils/lock_utils.py b/taskflow/utils/lock_utils.py index b41ba912..90cd2cce 100644 --- a/taskflow/utils/lock_utils.py +++ b/taskflow/utils/lock_utils.py @@ -331,7 +331,7 @@ class _InterProcessLock(object): if not os.path.exists(basedir): misc.ensure_tree(basedir) - LOG.info('Created lock path: %s', basedir) + LOG.debug('Created lock path: %s', basedir) self.lockfile = open(self.fname, 'w') diff --git a/taskflow/utils/misc.py b/taskflow/utils/misc.py index 7d6a5f66..0bc0a054 100644 --- a/taskflow/utils/misc.py +++ b/taskflow/utils/misc.py @@ -395,8 +395,8 @@ class TransitionNotifier(object): try: callback(state, *args, **kwargs) except Exception: - LOG.exception(("Failure calling callback %s to notify about" - " state transition %s"), callback, state) + LOG.warn("Failure calling callback %s to notify about state" + " transition %s", callback, state, exc_info=True) def register(self, state, callback, args=None, kwargs=None): assert six.callable(callback), "Callback must be callable"