promise: add check zope longrequest log promise

slapos/promise/plugin/check_error_on_zope_longrequest_log.py

+from zope import interface as zope_interface
+from slapos.grid.promise import interface
+from slapos.grid.promise.generic import GenericPromise
+import time
+
+import os
+import sys
+import re
+
+r = re.compile("^([0-9]+\-[0-9]+\-[0-9]+ [0-9]+\:[0-9]+\:[0-9]+)(\,[0-9]+) - ([A-z]+) (.*)$")
+
+class RunPromise(GenericPromise):
+
+  zope_interface.implements(interface.IPromise)
+
+  def __init__(self, config):
+    GenericPromise.__init__(self, config)
+    self.setPeriodicity(minute=10)
+
+  def sense(self):
+    log_file = self.getConfig('log-file')
+    error_threshold = self.getConfig('error-threshold')
+    maximum_delay = self.getConfig('maximum-delay')
+    error_amount = 0
+    if not os.path.exists(log_file):
+      # file don't exist, nothing to check
+      self.logger.info("log file does not exist: log check skipped")
+      return 0
+    
+    with open(log_file) as f:
+      f.seek(0, 2)
+      block_end_byte = f.tell()
+      f.seek(-min(block_end_byte, 4096*10), 1)
+      data = f.read()
+      for line in reversed(data.splitlines()):
+        m = r.match(line)
+        if m is None:
+          continue
+        dt, _, level, msg = m.groups()
+        try:
+          t = time.strptime(dt, "%Y-%m-%d %H:%M:%S")
+        except ValueError:
+          continue
+        if maximum_delay and (time.time()-time.mktime(t)) > maximum_delay:
+          # no result in the latest hour
+          break
+        error_amount += 1
+    if error_amount > error_threshold:
+      self.logger.error('ERROR=%s' % error_amount)
+    else:
+      self.logger.info('INFO=%s' % error_amount)
+
+  def test(self):
+    return self._test(result_count=1, failure_amount=1)
+
+  def anomaly(self):
+    return self._test(result_count=3, failure_amount=3)

slapos/test/promise/plugin/test_check_error_on_zope_longrequest_log.py

+##############################################################################
+#
+# Copyright (c) 2018 Vifib SARL and Contributors. All Rights Reserved.
+#
+# WARNING: This program as such is intended to be used by professional
+# programmers who take the whole responsibility of assessing all potential
+# consequences resulting from its eventual inadequacies and bugs
+# End users who are looking for a ready-to-use solution with commercial
+# guarantees and support are strongly adviced to contract a Free Software
+# Service Company
+#
+# 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 3
+# 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., 59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.
+#
+##############################################################################
+
+from slapos.test.promise.plugin import TestPromisePluginMixin
+import os
+from slapos.test.promise import data
+import time
+from slapos.grid.promise import PromiseError
+
+
+class TestCheckErrorOnZopeLongrequestLog(TestPromisePluginMixin):
+
+  def setUp(self):
+    TestPromisePluginMixin.setUp(self)
+    self.promise_name = "check-error-on-zope_longrequest-log.py"
+    self.base_path = "/".join(data.__file__.split("/")[:-1])
+    self.log_file = self.base_path + "/longrequest_logger_zope.log"
+    self.test_log_file = self.base_path + "/SOFTINST-0_longrequest_logger_zope.log"
+    self._update_logs()
+
+  def get_time(self, sec):
+    return time.strftime("%Y-%m-%d %H:%M:%S", time.localtime(time.time()-sec))
+
+  def _update_logs(self):
+    i = 600
+    new = ""
+    old = ""
+    with open(self.log_file) as f:
+      for line in f:
+        new += line.replace("DATETIME", self.get_time(i))
+        old += line.replace("DATETIME", self.get_time(i + 3600))
+        i -= 1
+      with open(self.test_log_file, "w") as f:
+        f.write(old)
+        f.write(new) 
+
+  def test_01_no_delay_no_error_threshold(self):
+    content = """from slapos.promise.plugin.check_error_on_zope_longrequest_log import RunPromise
+
+extra_config_dict = {
+  'log-file': '%(log_file)s',
+  'error-threshold': 0,
+  'maximum-delay': 0
+}
+""" % {'log_file': self.test_log_file}
+    self.writePromise(self.promise_name, content)
+
+    self.configureLauncher()
+    with self.assertRaises(PromiseError):
+      self.launcher.run()
+    result = self.getPromiseResult(self.promise_name)
+    self.assertEquals(result['result']['message'], "ERROR=6")
+
+  def test_02_no_delay_error_threshold(self):
+    content = """from slapos.promise.plugin.check_error_on_zope_longrequest_log import RunPromise
+
+extra_config_dict = {
+  'log-file': '%(log_file)s',
+  'error-threshold': 7,
+  'maximum-delay': 0
+}
+""" % {'log_file': self.test_log_file}
+    self.writePromise(self.promise_name, content)
+
+    self.configureLauncher()
+    self.launcher.run()
+    result = self.getPromiseResult(self.promise_name)
+    self.assertEquals(result['result']['message'], "INFO=6")
+
+  def test_03_delay_no_error_threshold(self):
+    content = """from slapos.promise.plugin.check_error_on_zope_longrequest_log import RunPromise
+
+extra_config_dict = {
+  'log-file': '%(log_file)s',
+  'error-threshold': 2,
+  'maximum-delay': 3600
+}
+""" % {'log_file': self.test_log_file}
+    self.writePromise(self.promise_name, content)
+    self.configureLauncher()
+    with self.assertRaises(PromiseError):
+      self.launcher.run()
+    result = self.getPromiseResult(self.promise_name)
+    self.assertEquals(result['result']['message'], "ERROR=3")
+
+
+if __name__ == '__main__':
+  unittest.main()