Add log level and test for functions

README.md

@@ -57,11 +57,17 @@ The environment variables will setup the HAProxy.
 | EASYHAPROXY_LETSENCRYPT_EMAIL | (Optional) The email will be used to request the certificate to Letsencrypt                                   |
 | EASYHAPROXY_SSL_MODE          | (Optional) `STRICT` supports only the most recent TLS version; `DEFAULT` good SSL integration with recent browsers; `LOOSE` supports all old SSL protocols for old browsers (not recommended).  |    
 | EASYHAPROXY_REFRESH_CONF      | (Optional) Check configuration every N seconds. Default: 10                                                   |  
+| EASYHAPROXY_LOG_LEVEL         | (Optional) The log level for EasyHAproxy messages. Available: TRACE,DEBUG,INFO,WARN,ERROR,FATAL Default: TRACE |  
+| CERTBOT_LOG_LEVEL             | (Optional) The log level for Certbot messages. Available: TRACE,DEBUG,INFO,WARN,ERROR,FATAL Default: TRACE |  
+| HAPROXY_LOG_LEVEL             | (Optional) The log level for HAProxy messages. Available: TRACE,DEBUG,INFO,WARN,ERROR,FATAL Default: TRACE |  
 | HAPROXY_USERNAME              | (Optional) The HAProxy username to the statistics. Default: `admin`                                           |
 | HAPROXY_PASSWORD              | (Optional) The HAProxy password to the statistics. If not set, statistics will be available with no password  |
 | HAPROXY_STATS_PORT            | (Optional) The HAProxy port to the statistics. Default: `1936`. If set to `false`, disable statistics         |
 | HAPROXY_CUSTOMERRORS          | (Optional) If HAProxy will use custom HTML errors. true/false. Default: `false`                               |
 
+
+
+
 The environment variable `EASYHAPROXY_DISCOVER` will define where is located your containers (see below for more details):
 
 - docker

src/functions/__init__.py

@@ -6,6 +6,35 @@ import time
 import os
 
 class Functions:
+    HAPROXY_LOG="HAPROXY"
+    EASYHAPROXY_LOG="EASYHAPROXY"
+    CERTBOT_LOG="CERTBOT"
+    INIT_LOG="INIT"
+
+    TRACE = "TRACE"
+    DEBUG = "DEBUG"
+    INFO = "INFO"
+    WARN = "WARN"
+    ERROR = "ERROR"
+    FATAL = "FATAL"
+
+    debug_log = None
+
+    @staticmethod
+    def skip_log(source, log_level_str):
+        level = os.getenv("%s_LOG_LEVEL" % (source.upper()), "").upper()
+        level_importance = {
+            Functions.TRACE: 0,
+            Functions.DEBUG: 1,
+            Functions.INFO: 2, 
+            Functions.WARN: 3,
+            Functions.ERROR: 4,
+            Functions.FATAL: 5
+        }
+        level_required = 0 if level not in level_importance else level_importance[level]
+        level_asked = 0 if log_level_str.upper() not in level_importance else level_importance[log_level_str.upper()]
+        return level_asked < level_required
+
     @staticmethod
     def load(filename):
         with open(filename, 'r') as content_file:
@@ -21,11 +50,17 @@ class Functions:
         if message is None or message == "":
             return
 
+        if Functions.skip_log(source, level):
+            return
+
         if not isinstance(message, (list, tuple)):
             message = [message]
         
         for line in message:
-            print("[%s] %s [%s]: %s" % (source, datetime.now().strftime("%x %X"), level, line.rstrip()))
+            log = "[%s] %s [%s]: %s" % (source, datetime.now().strftime("%x %X"), level, line.rstrip())
+            print(log)
+            if Functions.debug_log is not None:
+                Functions.debug_log.append(log)
 
     @staticmethod
     def run_bash(source, command, log_output=True, return_result=True):
@@ -43,21 +78,21 @@ class Functions:
             while True:
                 line = process.stdout.readline().rstrip()
                 output.append(line) if return_result else None
-                Functions.log(source, "info", line) if log_output else None
+                Functions.log(source, Functions.INFO, line) if log_output else None
-                Functions.log(source, "warning", process.stderr.readline())
+                Functions.log(source, Functions.WARN, process.stderr.readline())
                 return_code = process.poll()
                 if return_code is not None:
                     lines = []
                     for line in process.stdout.readlines():
                         output.append(line.rstrip()) if return_result else None
                         lines.append(line.rstrip())
-                    Functions.log(source, "info", lines) if log_output else None
+                    Functions.log(source, Functions.INFO, lines) if log_output else None
-                    Functions.log(source, "warning", process.stderr.readlines())
+                    Functions.log(source, Functions.WARN, process.stderr.readlines())
                     break
 
             return output
         except Exception as e:
-            Functions.log(source, 'error', "%s" % (e))
+            Functions.log(source, Functions.ERROR, "%s" % (e))
 
 
 class DaemonizeHAProxy:
@@ -69,7 +104,7 @@ class DaemonizeHAProxy:
         if action == "start":
             self.__prepare("/usr/sbin/haproxy -W -f /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -S /var/run/haproxy.sock")
         else:
-            pid = "".join(Functions().run_bash("HAPROXY", "cat /run/haproxy.pid", log_output=False))
+            pid = "".join(Functions().run_bash(Functions.HAPROXY_LOG, "cat /run/haproxy.pid", log_output=False))
             self.__prepare("/usr/sbin/haproxy -W -f /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -x /var/run/haproxy.sock -sf %s" % (pid))
 
         if self.process is None:
@@ -79,7 +114,7 @@ class DaemonizeHAProxy:
         self.thread.start()
 
     def __prepare(self, command):
-        source = "HAPROXY"
+        source = Functions.HAPROXY_LOG
         if not isinstance(command, (list, tuple)):
             command = shlex.split(command)
 
@@ -92,21 +127,21 @@ class DaemonizeHAProxy:
                             universal_newlines=True)
 
         except Exception as e:
-            Functions.log(source, 'error', "%s" % (e))
+            Functions.log(source, Functions.ERROR, "%s" % (e))
 
 
     def __start(self):
-        source = "HAPROXY"
+        source = Functions.HAPROXY_LOG
         try:
             with self.process.stdout:
                 for line in iter(self.process.stdout.readline, b''): 
-                    Functions.log(source, "info", line)
+                    Functions.log(source, Functions.INFO, line)
 
             returncode = self.process.wait() 
-            Functions.log(source, "debug", "Return code %s" % (returncode))
+            Functions.log(source, Functions.DEBUG, "Return code %s" % (returncode))
 
         except Exception as e:
-            Functions.log(source, 'error', "%s" % (e))
+            Functions.log(source, Functions.ERROR, "%s" % (e))
 
     def is_alive(self):
         return self.thread.is_alive()
@@ -137,15 +172,15 @@ class Certbot:
                 filename = "%s/%s.pem" % (self.certs, host)
                 host_arg = '-d %s' % (host)
                 if not os.path.exists(filename):
-                    Functions.log("CERTBOT", "debug", "Request new certificate for %s" % (host))
+                    Functions.log(Functions.CERTBOT_LOG, Functions.DEBUG, "Request new certificate for %s" % (host))
                     request_certs.append(host_arg)
                 else:
                     creation_time = os.path.getctime(filename)
                     if (current_time - creation_time) // (24 * 3600) > 90:
-                        Functions.log("CERTBOT", "debug", "Request expired certificate for %s" % (host))
+                        Functions.log(Functions.CERTBOT_LOG, Functions.DEBUG, "Request expired certificate for %s" % (host))
                         request_certs.append(host_arg)
                     if (current_time - creation_time) // (24 * 3600) >= 45:
-                        Functions.log("CERTBOT", "debug", "Renew certificate for %s" % (host))
+                        Functions.log(Functions.CERTBOT_LOG, Functions.DEBUG, "Renew certificate for %s" % (host))
                         renew_certs.append(host_arg)
 
             certbot_certonly = ('/usr/bin/certbot certonly '
@@ -162,11 +197,11 @@ class Certbot:
 
             ret_reload = False
             if len(request_certs) > 0:
-                Functions.run_bash("CERTBOT", certbot_certonly, return_result=False)
+                Functions.run_bash(Functions.CERTBOT_LOG, certbot_certonly, return_result=False)
                 ret_reload = True
 
             if len(renew_certs) > 0:
-                Functions.run_bash("CERTBOT", "/usb/bin/certbot renew", return_result=False)
+                Functions.run_bash(Functions.CERTBOT_LOG, "/usb/bin/certbot renew", return_result=False)
                 ret_reload = True
 
             if ret_reload:
@@ -174,7 +209,7 @@ class Certbot:
 
             return ret_reload
         except Exception as e:
-            Functions.log("CERTBOT", "error", "%s" % (e))
+            Functions.log(Functions.CERTBOT_LOG, Functions.ERROR, "%s" % (e))
             return False
         
     def merge_certificate(self, cert, key, filename):

src/main.py

@@ -20,7 +20,7 @@ def start():
     processor_obj.save_config(haproxy_config)
     processor_obj.save_certs(certs_haproxy)
     letsencrypt_certs_found = processor_obj.get_letsencrypt_hosts()
-    Functions.log('EASYHAPROXY', 'debug', 'Found hosts: %s' % ", ".join(processor_obj.get_hosts())) # Needs to after save_config
+    Functions.log(Functions.EASYHAPROXY_LOG, Functions.DEBUG, 'Found hosts: %s' % ", ".join(processor_obj.get_hosts())) # Needs to after save_config
 
     old_haproxy = None
     haproxy = DaemonizeHAProxy()
@@ -37,11 +37,11 @@ def start():
             old_parsed = processor_obj.get_parsed_object()
             processor_obj.refresh()
             if DeepDiff(old_parsed, processor_obj.get_parsed_object()) != {} or not haproxy.is_alive():
-                Functions.log('EASYHAPROXY', 'debug', 'New configuration found. Reloading...')
+                Functions.log(Functions.EASYHAPROXY_LOG, Functions.DEBUG, 'New configuration found. Reloading...')
                 processor_obj.save_config(haproxy_config)
                 processor_obj.save_certs(certs_haproxy)
                 letsencrypt_certs_found = processor_obj.get_letsencrypt_hosts()
-                Functions.log('EASYHAPROXY', 'debug', 'Found hosts: %s' % ", ".join(processor_obj.get_hosts())) # Needs to after save_config
+                Functions.log(Functions.EASYHAPROXY_LOG, Functions.DEBUG, 'Found hosts: %s' % ", ".join(processor_obj.get_hosts())) # Needs to after save_config
                 old_haproxy = haproxy
                 haproxy = DaemonizeHAProxy()
                 haproxy.haproxy("reload")
@@ -49,26 +49,26 @@ def start():
 
             certbot.check_certificates(letsencrypt_certs_found)
         except Exception as e:
-            Functions.log('EASYHAPROXY', 'fatal', "Err: %s" % (e))
+            Functions.log(Functions.EASYHAPROXY_LOG, Functions.FATAL, "Err: %s" % (e))
-        Functions.log('EASYHAPROXY', 'debug', 'Heartbeat')
+        Functions.log(Functions.EASYHAPROXY_LOG, Functions.DEBUG, 'Heartbeat')
 
 
 
 
 def main():
-    Functions.run_bash('INIT', '/usr/sbin/haproxy -v')
+    Functions.run_bash(Functions.INIT_LOG, '/usr/sbin/haproxy -v')
 
-    Functions.log('INIT', 'info', "                      _                               ")
+    Functions.log(Functions.INIT_LOG, Functions.INFO, "                      _                               ")
-    Functions.log('INIT', 'info', " ___ __ _ ____  _ ___| |_  __ _ _ __ _ _ _____ ___  _ ")
+    Functions.log(Functions.INIT_LOG, Functions.INFO, " ___ __ _ ____  _ ___| |_  __ _ _ __ _ _ _____ ___  _ ")
-    Functions.log('INIT', 'info', "/ -_) _` (_-< || |___| ' \/ _` | '_ \ '_/ _ \ \ / || |")
+    Functions.log(Functions.INIT_LOG, Functions.INFO, "/ -_) _` (_-< || |___| ' \/ _` | '_ \ '_/ _ \ \ / || |")
-    Functions.log('INIT', 'info', "\___\__,_/__/\_, |   |_||_\__,_| .__/_| \___/_\_\\_, |")
+    Functions.log(Functions.INIT_LOG, Functions.INFO, "\___\__,_/__/\_, |   |_||_\__,_| .__/_| \___/_\_\\_, |")
-    Functions.log('INIT', 'info', "             |__/              |_|               |__/ ")
+    Functions.log(Functions.INIT_LOG, Functions.INFO, "             |__/              |_|               |__/ ")
 
-    Functions.log('INIT', 'info', "Release: %s" % (os.getenv("RELEASE_VERSION")))
+    Functions.log(Functions.INIT_LOG, Functions.INFO, "Release: %s" % (os.getenv("RELEASE_VERSION")))
-    Functions.log('INIT', 'debug', 'Environment:')
+    Functions.log(Functions.INIT_LOG, Functions.DEBUG, 'Environment:')
     for name, value in os.environ.items():
         if "HAPROXY" in name:
-            Functions.log('INIT', 'debug', "- {0}: {1}".format(name, value))
+            Functions.log(Functions.INIT_LOG, Functions.DEBUG, "- {0}: {1}".format(name, value))
 
     start()
 

src/processor/__init__.py

@@ -48,7 +48,7 @@ class ProcessorInterface:
         elif mode == "kubernetes":
             return Kubernetes()
         else:
-            Functions.log("FACTORY", "fatal", "Expected mode to be 'static', 'docker', 'swarm' or 'kubernetes'. I got '%s'" % (mode))
+            Functions.log("EASYHAPROXY", Functions.FATAL, "Expected mode to be 'static', 'docker', 'swarm' or 'kubernetes'. I got '%s'" % (mode))
             return None
 
     def refresh(self):

src/tests/test_functions.py

@@ -0,0 +1,101 @@
+import json
+import pytest
+import os
+import re
+import random
+import string
+from functions import Functions
+
+def test_functions_check_local_level():
+    assert Functions.skip_log('CERTBOT', Functions.INFO) == False
+    assert Functions.skip_log('HAPOROXY', Functions.INFO) == False
+    assert Functions.skip_log('EASYHAPROXY', Functions.INFO) == False
+
+    os.environ['CERTBOT_LOG_LEVEL'] = 'warn'
+    assert Functions.skip_log('CERTBOT', Functions.INFO) == True
+    os.environ['CERTBOT_LOG_LEVEL'] = ''
+
+    os.environ['HAPROXY_LOG_LEVEL'] = 'warn'
+    assert Functions.skip_log('HAPROXY', Functions.INFO) == True
+    os.environ['HAPROXY_LOG_LEVEL'] = ''
+
+    os.environ['EASYHAPROXY_LOG_LEVEL'] = 'warn'
+    assert Functions.skip_log('EASYHAPROXY', Functions.INFO) == True
+    os.environ['EASYHAPROXY_LOG_LEVEL'] = ''
+
+def test_function_load_and_save():
+    filename = '/tmp/x.txt'
+    try:
+        assert os.path.exists(filename) == False
+        text = ''.join(random.choice(string.ascii_uppercase + string.digits) for _ in range(50))
+        Functions.save(filename, text)
+        assert os.path.exists(filename) == True
+        assert Functions.load(filename) == text
+    finally:
+        os.unlink(filename)
+
+def test_functions_check_log_sanity():
+    print()
+    Functions.log(Functions.EASYHAPROXY_LOG, Functions.INFO, "Test 1")
+    assert Functions.debug_log is None
+
+    Functions.debug_log = []
+    try:
+        Functions.log(Functions.EASYHAPROXY_LOG, Functions.INFO, "Test 2")
+        assert len(Functions.debug_log) == 1
+        assert re.match("\[EASYHAPROXY\] .* \[INFO\]: Test 2", Functions.debug_log[0])
+
+        os.environ['CERTBOT_LOG_LEVEL'] = 'DEBUG'
+        Functions.log(Functions.EASYHAPROXY_LOG, Functions.INFO, "Test 3")
+        assert len(Functions.debug_log) == 2
+        assert re.match("\[EASYHAPROXY\] .* \[INFO\]: Test 3", Functions.debug_log[1])
+
+        os.environ['EASYHAPROXY_LOG_LEVEL'] = 'warn'
+        Functions.log(Functions.EASYHAPROXY_LOG, Functions.INFO, "Test 4")   # Should not log to debug
+        assert len(Functions.debug_log) == 2
+
+    finally:
+        os.environ['EASYHAPROXY_LOG_LEVEL'] = ''
+        Functions.debug_log = None
+
+def test_functions_run_bash_log_output():
+    print()
+    Functions.debug_log = []
+    try:
+        result = Functions.run_bash(Functions.EASYHAPROXY_LOG, "echo 'test run 1'", log_output=True, return_result=False)
+        assert result == []
+        assert len(Functions.debug_log) == 1
+        assert re.match("\[EASYHAPROXY\] .* \[INFO\]: test run 1", Functions.debug_log[0])
+    finally:
+        Functions.debug_log = None
+
+def test_functions_run_bash_no_log_output():
+    print()
+    Functions.debug_log = []
+    try:
+        result = Functions.run_bash(Functions.EASYHAPROXY_LOG, "echo 'test run 2'", log_output=False, return_result=False)
+        assert result == []
+        assert len(Functions.debug_log) == 0
+    finally:
+        Functions.debug_log = None
+
+def test_functions_run_bash_return():
+    print()
+    Functions.debug_log = []
+    try:
+        result = Functions.run_bash(Functions.EASYHAPROXY_LOG, "echo 'test run 3'", log_output=False, return_result=True)
+        assert len(Functions.debug_log) == 0
+        assert "".join(result) == 'test run 3'
+    finally:
+        Functions.debug_log = None
+
+def test_functions_run_bash_log_and_return_output():
+    print()
+    Functions.debug_log = []
+    try:
+        result = Functions.run_bash(Functions.EASYHAPROXY_LOG, "echo 'test run 4'", log_output=True, return_result=True)
+        assert "".join(result) == 'test run 4'
+        assert len(Functions.debug_log) == 1
+        assert re.match("\[EASYHAPROXY\] .* \[INFO\]: test run 4", Functions.debug_log[0])
+    finally:
+        Functions.debug_log = None