promise.check_error_on_apache_log: New Promise

  Added new promise to inspect an apache error log to detect failures if failures occurred.

.gitignore

@@ -10,3 +10,4 @@
 /slapos.toolbox.egg-info/
 .eggs/
 config.json
+slapos/test/promise/data/SOFTINST-0_*

setup.py

@@ -68,6 +68,7 @@ setup(name=name,
           'agent = slapos.agent.agent:main',
           'check-web-page-http-cache-hit = slapos.promise.check_web_page_http_cache_hit:main',
           'check-feed-as-promise = slapos.checkfeedaspromise:main',
+          'check-error-on-apache-log = slapos.promise.check_error_on_apache_log:main', 
           'clouddestroy = slapos.cloudmgr.destroy:main',
           'cloudgetprivatekey = slapos.cloudmgr.getprivatekey:main',
           'cloudgetpubliciplist = slapos.cloudmgr.getpubliciplist:main',

slapos/promise/check_error_on_apache_log/__init__.py

+import re
+import time
+import sys
+import gzip
+import argparse
+
+r = re.compile("^(\[[^\]]+\]) (\[[^\]]+\]) (.*)$")
+
+def test(log_file, maximum_delay):
+  error_amount = 0
+  no_route_error = 0
+  network_is_unreacheable = 0
+  timeout = 0
+  with open(log_file) as f:
+
+    f.seek(0, 2)
+    block_end_byte = f.tell()
+    f.seek(-min(block_end_byte, 4096), 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[1:-1], "%a %b %d %H:%M:%S %Y")
+      except ValueError:
+        # Fail to parser for the first time, try a different output.
+        t = time.strptime(dt[1:-1], "%a %b %d %H:%M:%S.%f %Y")
+      if maximum_delay and (time.time()-time.mktime(t)) > maximum_delay:
+        # no result in the latest hour
+        break
+
+      if level != "[error]":
+        continue
+
+      # Classify the types of errors
+      if "(113)No route to host" in msg:
+        no_route_error += 1
+      elif "(101)Network is unreachable" in msg:
+        network_is_unreacheable += 1
+      elif "(110)Connection timed out" in msg:
+        timeout += 1
+      
+      error_amount += 1
+
+  if error_amount:
+    return "ERROR=%s (NOTROUTE=%s, UNREACHEABLENET=%s, TIMEOUT=%s)" % (error_amount, no_route_error, network_is_unreacheable, timeout)
+  
+  return "OK"
+
+
+def main():
+  parser = argparse.ArgumentParser()
+  parser.add_argument("-l", "--log-file", required=True)
+  parser.add_argument("-d", "--maximum-delay", default=0)
+  args = parser.parse_args()
+
+  log_file = args.log_file
+
+  result = test(args.log_file, args.maximum_delay)
+
+  print result
+  if result != "OK":
+    sys.exit(1)
+

slapos/test/promise/data/apache_error_log

+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 9 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 1 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 27 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 25 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 3 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 3 (server couscous.erp5.cn:443)
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 22 (server couscous.erp5.cn:443)
+[DATETIME] [error] (113)No route to host: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 5 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 6 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)

slapos/test/promise/data/infoonly_error_log

+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 29 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 9 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 3 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 8 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 41 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 36 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 45 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 15 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 2 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 43 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 59 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol

slapos/test/promise/data/timeout_error_log

+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 1 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [error] (110)Connection timed out: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (110)Connection timed out: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 1 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 43 (server couscous.erp5.cn:443)
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 65 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Seeding PRNG with 288 bytes of entropy
+[DATETIME] [info] Initial (No.1) HTTPS request received for child 1 (server couscous.erp5.cn:443)
+[DATETIME] [info] [client 123:456:abc::1] Connection to child 0 established (server couscous.erp5.cn:443)

slapos/test/promise/data/unreachable_error_log

+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [error] (101)Network is unreachable: proxy: HTTPS: attempt to connect to [123:456:abc::1]:2153 (*) failed
+[DATETIME] [info] Loading certificate & private key of SSL-aware server
+[DATETIME] [info] Configuring server for SSL protocol

slapos/test/promise/test_check_error_on_apache_log.py

+##############################################################################
+#
+# Copyright (c) 2017 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.
+#
+##############################################################################
+
+import unittest
+import os.path
+import socket
+import time
+from slapos.promise.check_error_on_apache_log import test
+
+from slapos.test.promise import data
+
+class TestCheckErrorOnApacheLog(unittest.TestCase):
+
+  def get_time(self, sec):
+    return time.strftime("%a %b %d %H:%M:%S %Y", time.gmtime(time.time()-sec))
+
+  def _update_logs(self):
+    log_file_list = [
+       "apache_error_log",
+       "infoonly_error_log",
+       "timeout_error_log",
+       "unreachable_error_log"]
+    i = 600
+    for log_file in log_file_list:
+      new = ""
+      old = ""
+      with open(self.base_path + "/" + 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.base_path + "/SOFTINST-0_" + log_file, "w") as f:
+        f.write(old)
+        f.write(new)
+
+  def setUp(self):
+    self.base_path = "/".join(data.__file__.split("/")[:-1])
+    self._update_logs()
+
+  def test_no_error(self):
+    self.assertEquals("OK",
+      test(self.base_path + "/SOFTINST-0_infoonly_error_log", 0))
+
+    self.assertEquals("OK",
+      test(self.base_path + "/SOFTINST-0_infoonly_error_log", 3600))
+
+  def test_error(self):
+    self.assertEquals("ERROR=2 (NOTROUTE=2, UNREACHEABLENET=0, TIMEOUT=0)",
+      test(self.base_path + "/SOFTINST-0_apache_error_log", 0))
+
+    self.assertEquals("ERROR=1 (NOTROUTE=1, UNREACHEABLENET=0, TIMEOUT=0)",
+      test(self.base_path + "/SOFTINST-0_apache_error_log", 3600))
+
+  def test_error_timeout(self):
+    self.assertEquals("ERROR=4 (NOTROUTE=0, UNREACHEABLENET=0, TIMEOUT=4)",
+      test(self.base_path + "/SOFTINST-0_timeout_error_log", 0))
+
+    self.assertEquals("ERROR=2 (NOTROUTE=0, UNREACHEABLENET=0, TIMEOUT=2)",
+      test(self.base_path + "/SOFTINST-0_timeout_error_log", 3600))
+
+  def test_error_unreacheabler(self):
+    self.assertEquals("ERROR=11 (NOTROUTE=0, UNREACHEABLENET=11, TIMEOUT=0)",
+      test(self.base_path + "/SOFTINST-0_unreachable_error_log", 0))
+
+    self.assertEquals("ERROR=11 (NOTROUTE=0, UNREACHEABLENET=11, TIMEOUT=0)",
+      test(self.base_path + "/SOFTINST-0_unreachable_error_log", 3600))   
+  
+if __name__ == '__main__':
+  unittest.main()
+