Milan Zamazal has uploaded a new change for review.

Change subject: logging: throttledlog introduced
......................................................................

logging: throttledlog introduced

In some situations, we want to log interesting information.  A natural
place to retrieve and log the information is where it is created.
However the corresponding code may be called quite often and we don't
need logging the information that often and fill logs with it
excessively.  It's sufficient to log it just from time to time.

This patch provides means for occasional logging.  The provided
functions actually log only every given number of invocations or every
given time span.  We're going to use the functionality in followup
patches.

Change-Id: Ief96f74eb84880827ccf24c3e7ae854403090b8a
Signed-off-by: Milan Zamazal <mzama...@redhat.com>
---
M lib/vdsm/Makefile.am
A lib/vdsm/throttledlog.py
M tests/Makefile.am
A tests/throttledlog_test.py
M vdsm.spec.in
5 files changed, 203 insertions(+), 0 deletions(-)


  git pull ssh://gerrit.ovirt.org:29418/vdsm refs/changes/61/59461/1

diff --git a/lib/vdsm/Makefile.am b/lib/vdsm/Makefile.am
index fbeea7e..c12ef3e 100644
--- a/lib/vdsm/Makefile.am
+++ b/lib/vdsm/Makefile.am
@@ -60,6 +60,7 @@
        supervdsm.py \
        sysctl.py \
        taskset.py \
+       throttledlog.py \
        udevadm.py \
        utils.py \
        v2v.py \
diff --git a/lib/vdsm/throttledlog.py b/lib/vdsm/throttledlog.py
new file mode 100644
index 0000000..1039154
--- /dev/null
+++ b/lib/vdsm/throttledlog.py
@@ -0,0 +1,114 @@
+#
+# Copyright 2016 Red Hat, Inc.
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program; if not, write to the Free Software
+# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
+#
+# Refer to the README and COPYING files for full details of the license
+#
+from __future__ import absolute_import
+
+import functools
+import logging
+
+from vdsm.utils import monotonic_time
+
+
+_DEFAULT_TIMEOUT_SEC = 3600
+_DEFAULT_LOGGING_LEVEL = logging.DEBUG
+
+_logger = logging.getLogger('throttled')
+
+_periodic = {}
+
+
+class _Periodic(object):
+
+    def __init__(self, interval, timeout):
+        self._interval = interval
+        self._timeout = timeout
+        self._counter = 0
+        self._last_time = 0
+
+    def tick(self):
+        now = monotonic_time()
+        result = self._result(now)
+        self._counter = (self._counter + 1) % self._interval
+        if result:
+            self._last_time = now
+        return result
+
+    def _result(self, now):
+        return (self._counter == 0 or
+                (now - self._last_time) >= self._timeout)
+
+
+def throttle(name, interval, timeout=_DEFAULT_TIMEOUT_SEC):
+    """
+    Throttle log messages for `name`, logging at most one message per
+    `interval` calls or always after `timeout` seconds of silence.  Throttling
+    applies only to logging performed via `log()` function of this module.  The
+    first call of `log()` never throttles the log, following calls are
+    throttled according to the given parameters.
+
+    If this function has already been called for `name`, replace the throttling
+    parameters for `name` with the new ones given here and start throttling
+    from beginning.
+
+    :param name: Arbitrary identifier to be matched in `log()` calls.
+    :type name: basestring
+    :param interval: The number of `log()` calls that should log at least once.
+    :type interval: int
+    :param timeout: The number of seconds without log emitted after which
+      `log()` should always unthrottle the next message.
+    :type timeout: int
+    """
+    _periodic[name] = _Periodic(interval, timeout)
+
+
+def log(name, level, message, *args):
+    """
+    Log `message` and `args` if throttling settings for `name` allow it.
+    See `throttle()` for information about throttling and `name`.
+    `level`, `message` and `args` are passed to `logging.Logger.log()`
+    unchanged.
+
+    :param name: Arbitrary identifier to be matched by `throttle()` settings.
+    :type name: basestring
+
+    .. note::
+
+      Depending on throttling settings and the current logging level `message`
+      and `args` may not be logged at all.  So don't perform expensive
+      preprocessing of `args` before calling this function.  If you need to
+      modify it before logging it, you may want to use something like
+      `vdsm.logUtils.Suppressed` or its subclasses.
+    """
+    try:
+        periodic = _periodic[name]
+    except KeyError:
+        pass  # unthrottled
+    else:
+        if not periodic.tick():
+            return
+
+    _logger.log(level, message, *args)
+
+
+def debug(name, message, *args):
+    log(name, logging.DEBUG, message, *args)
+
+
+def info(name, message, *args):
+    log(name, logging.INFO, message, *args)
diff --git a/tests/Makefile.am b/tests/Makefile.am
index d664a21..cf06573 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -129,6 +129,7 @@
        toolTests.py \
        toolBondingTests.py \
        transportWrapperTests.py \
+       throttledlog_test.py \
        unicode_test.py \
        utilsTests.py \
        vdscliTests.py \
@@ -235,6 +236,7 @@
        storagetestlibTests.py \
        tasksetTests.py \
        testlibTests.py \
+       throttledlog_test.py \
        toolBondingTests.py \
        toolTests.py \
        transportWrapperTests.py \
diff --git a/tests/throttledlog_test.py b/tests/throttledlog_test.py
new file mode 100644
index 0000000..9085d07
--- /dev/null
+++ b/tests/throttledlog_test.py
@@ -0,0 +1,85 @@
+#
+# Copyright 2016 Red Hat, Inc.
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program; if not, write to the Free Software
+# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301 USA
+#
+# Refer to the README and COPYING files for full details of the license
+#
+import logging
+
+from vdsm import throttledlog
+
+from monkeypatch import MonkeyPatch
+from testlib import VdsmTestCase
+
+
+class FakeLogger(object):
+
+    def __init__(self, level):
+        self.level = level
+        self.messages = []
+
+    def isEnabledFor(self, level):
+        return level >= self.level
+
+    def log(self, level, message, *args):
+        if not self.isEnabledFor(level):
+            return
+        self.messages.append(message % args)
+
+
+class FakeTime(object):
+
+    def __init__(self):
+        self.time = 0.0
+
+    def __call__(self):
+        return self.time
+
+
+class TestThrottledLogging(VdsmTestCase):
+
+    @MonkeyPatch(throttledlog, "_logger", FakeLogger(logging.DEBUG))
+    def test_throttled_logging(self):
+        throttledlog.throttle('test', 3)
+        for i in range(5):
+            throttledlog.debug('test', "Cycle: %s", i)
+        self.assertEqual(throttledlog._logger.messages,
+                         ['Cycle: 0', 'Cycle: 3'])
+
+    @MonkeyPatch(throttledlog, "_logger", FakeLogger(logging.INFO))
+    def test_no_logging(self):
+        throttledlog.throttle('test', 3)
+        for i in range(5):
+            throttledlog.debug('test', "Cycle: %s", i)
+        self.assertEqual(throttledlog._logger.messages, [])
+
+    @MonkeyPatch(throttledlog, "_logger", FakeLogger(logging.DEBUG))
+    def test_default(self):
+        throttledlog.throttle('test', 3)
+        for i in range(5):
+            throttledlog.debug('other', "Cycle: %s", i)
+        self.assertEqual(throttledlog._logger.messages,
+                         ['Cycle: %s' % (i,) for i in range(5)])
+
+    @MonkeyPatch(throttledlog, "_logger", FakeLogger(logging.DEBUG))
+    @MonkeyPatch(throttledlog, "monotonic_time", FakeTime())
+    def test_timeout(self):
+        throttledlog.throttle('test', 10, timeout=7)
+        for i in range(12):
+            throttledlog.debug('test', "Cycle: %s", i)
+            throttledlog.monotonic_time.time += 1.0
+        self.assertEqual(throttledlog._logger.messages,
+                         ['Cycle: %s' % (i,) for i in (0, 7, 10,)])
diff --git a/vdsm.spec.in b/vdsm.spec.in
index bbaa9ec..b1826bd 100644
--- a/vdsm.spec.in
+++ b/vdsm.spec.in
@@ -1261,6 +1261,7 @@
 %{python_sitelib}/%{vdsm_name}/supervdsm.py*
 %{python_sitelib}/%{vdsm_name}/sysctl.py*
 %{python_sitelib}/%{vdsm_name}/taskset.py*
+%{python_sitelib}/%{vdsm_name}/throttledlog.py*
 %{python_sitelib}/%{vdsm_name}/udevadm.py*
 %{python_sitelib}/%{vdsm_name}/utils.py*
 %{python_sitelib}/%{vdsm_name}/v2v.py*


-- 
To view, visit https://gerrit.ovirt.org/59461
To unsubscribe, visit https://gerrit.ovirt.org/settings

Gerrit-MessageType: newchange
Gerrit-Change-Id: Ief96f74eb84880827ccf24c3e7ae854403090b8a
Gerrit-PatchSet: 1
Gerrit-Project: vdsm
Gerrit-Branch: master
Gerrit-Owner: Milan Zamazal <mzama...@redhat.com>
_______________________________________________
vdsm-patches mailing list
vdsm-patches@lists.fedorahosted.org
https://lists.fedorahosted.org/admin/lists/vdsm-patches@lists.fedorahosted.org

Reply via email to