Leverage logging config and refactor the logger

JIRA: FUNCTEST-690

The detailed benefits are listed in the JIRA description.

1. Refactored the functest_logger to make use of configuration file
2. Avoided configuring the logging every time a logger is initialized
3. Applied separate logging configuration fo unit test by removing
saving log to file

Change-Id: I6e27eaba727ae6d704f0301f15359dc3ea7b2f97
Signed-off-by: helenyao <yaohelan@huawei.com>

9 files changed, 95 insertions, 28 deletions

diff --git a/functest/ci/config_functest.yaml b/functest/ci/config_functest.yaml
index 25be17240..f1efd904c 100755
--- a/functest/ci/config_functest.yaml
+++ b/functest/ci/config_functest.yaml
@@ -30,6 +30,7 @@ general:
         functest:           /home/opnfv/functest
         functest_test:      /home/opnfv/repos/functest/functest/opnfv_tests
         results:            /home/opnfv/functest/results
+        functest_logging_cfg:   /home/opnfv/repos/functest/functest/ci/logging.json
         functest_conf:      /home/opnfv/functest/conf
         functest_data:      /home/opnfv/functest/data
         dir_vIMS_data:      /home/opnfv/functest/data/vIMS/
diff --git a/functest/ci/logging.json b/functest/ci/logging.json
new file mode 100644
index 000000000..3f454e8fa
--- /dev/null
+++ b/functest/ci/logging.json
@@ -0,0 +1,29 @@
+{

+    "version": 1,

+    "disable_existing_loggers": false,

+    "formatters": {

+        "standard": {

+            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"

+        }

+    },

+    "handlers": {

+        "console": {

+            "level": "INFO",

+            "class": "logging.StreamHandler",

+            "formatter": "standard"

+        },

+        "file": {

+            "level": "DEBUG",

+            "class": "logging.FileHandler",

+            "formatter": "standard",

+            "filename": "/home/opnfv/functest/results/functest.log"

+        }

+    },

+    "loggers": {

+        "": {

+            "handlers": ["console", "file"],

+            "level": "DEBUG",

+            "propagate": "yes"

+        }

+    }

+}

diff --git a/functest/tests/unit/cli/commands/test_cli_env.py b/functest/tests/unit/cli/commands/test_cli_env.py
index f70761dcd..4b6ea57a7 100644
--- a/functest/tests/unit/cli/commands/test_cli_env.py
+++ b/functest/tests/unit/cli/commands/test_cli_env.py
@@ -11,7 +11,6 @@ import unittest
 from git.exc import NoSuchPathError
 import mock
 
-mock.patch('logging.FileHandler').start()  # noqa
 from functest.cli.commands import cli_env
 from functest.utils.constants import CONST
 from functest.tests.unit import test_utils
diff --git a/functest/tests/unit/core/test_testcase_base.py b/functest/tests/unit/core/test_testcase_base.py
index 8df524b0f..94d2e966b 100644..100755
--- a/functest/tests/unit/core/test_testcase_base.py
+++ b/functest/tests/unit/core/test_testcase_base.py
@@ -12,8 +12,6 @@ import mock
 import os
 import unittest
 
-mock.patch('logging.FileHandler').start()  # noqa
-
 from functest.core import testcase_base
 
 
diff --git a/functest/tests/unit/odl/test_odl.py b/functest/tests/unit/odl/test_odl.py
index 59ab2c654..568fdc828 100644
--- a/functest/tests/unit/odl/test_odl.py
+++ b/functest/tests/unit/odl/test_odl.py
@@ -19,7 +19,6 @@ from robot.errors import DataError, RobotError
 from robot.result import testcase
 from robot.utils.robottime import timestamp_to_secs
 
-mock.patch('logging.FileHandler').start()  # noqa
 from functest.core import testcase_base
 from functest.opnfv_tests.sdn.odl import odl
 
diff --git a/functest/tests/unit/test_logging.ini b/functest/tests/unit/test_logging.ini
new file mode 100644
index 000000000..3d5b947c8
--- /dev/null
+++ b/functest/tests/unit/test_logging.ini
@@ -0,0 +1,27 @@
+[loggers]

+keys=root,functest_logger

+

+[logger_root]

+level=DEBUG

+handlers=console

+

+[logger_functest_logger]

+level=DEBUG

+handlers=console

+qualname=functest.utils.functest_logger

+propagate=0

+

+[handlers]

+keys=console

+

+[handler_console]

+class=StreamHandler

+level=INFO

+formatter=standard

+args=(sys.stdout,)

+

+[formatters]

+keys=standard

+

+[formatter_standard]

+format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
\ No newline at end of file
diff --git a/functest/tests/unit/utils/test_functest_utils.py b/functest/tests/unit/utils/test_functest_utils.py
index c4b566608..ce9086a7a 100644
--- a/functest/tests/unit/utils/test_functest_utils.py
+++ b/functest/tests/unit/utils/test_functest_utils.py
@@ -18,7 +18,6 @@ import mock
 import requests
 
 from functest.tests.unit import test_utils
-mock.patch('logging.FileHandler').start()  # noqa
 from functest.utils import functest_utils
 
 
diff --git a/functest/utils/functest_logger.py b/functest/utils/functest_logger.py
index c0fba082a..f09f56be0 100644..100755
--- a/functest/utils/functest_logger.py
+++ b/functest/utils/functest_logger.py
@@ -20,36 +20,50 @@
 #  logger = fl.Logger("script_name").getLogger()
 #  logger.info("message to be shown with - INFO - ")
 #  logger.debug("message to be shown with - DEBUG -")
-
 import logging
+import logging.config
 import os
 
+import json
 
-class Logger:
-    def __init__(self, logger_name):
+from functest.utils.constants import CONST
+
+logger = logging.getLogger(__name__)
+
+
+def is_debug():
+    if CONST.CI_DEBUG and CONST.CI_DEBUG.lower() == "true":
+        return True
+    return False
 
-        CI_DEBUG = os.getenv('CI_DEBUG')
 
+def setup_logging(default_path=CONST.dir_functest_logging_cfg,
+                  default_level=logging.INFO,
+                  env_key='LOG_CFG'):
+    path = default_path
+    value = os.getenv(env_key, None)
+    if value:
+        path = value
+    if os.path.exists(path):
+        with open(path, 'rt') as f:
+            config = json.load(f)
+            if (config['handlers'] and
+                    config['handlers']['console']):
+                stream_level = logging.INFO
+                if is_debug():
+                    stream_level = logging.DEBUG
+                config['handlers']['console']['level'] = stream_level
+            logging.config.dictConfig(config)
+    else:
+        logging.basicConfig(level=default_level)
+
+
+setup_logging()
+
+
+class Logger:
+    def __init__(self, logger_name):
         self.logger = logging.getLogger(logger_name)
-        self.logger.propagate = 0
-        self.logger.setLevel(logging.DEBUG)
-
-        ch = logging.StreamHandler()
-        formatter = logging.Formatter('%(asctime)s - %(name)s - '
-                                      '%(levelname)s - %(message)s')
-        ch.setFormatter(formatter)
-        if CI_DEBUG is not None and CI_DEBUG.lower() == "true":
-            ch.setLevel(logging.DEBUG)
-            self.logger.parent.level = logging.DEBUG
-        else:
-            ch.setLevel(logging.INFO)
-            self.logger.parent.level = logging.INFO
-        self.logger.addHandler(ch)
-
-        hdlr = logging.FileHandler('/home/opnfv/functest/results/functest.log')
-        hdlr.setFormatter(formatter)
-        hdlr.setLevel(logging.DEBUG)
-        self.logger.addHandler(hdlr)
 
     def getLogger(self):
         return self.logger
diff --git a/run_unit_tests.sh b/run_unit_tests.sh
index 79d05d3d1..5167d78c6 100755
--- a/run_unit_tests.sh
+++ b/run_unit_tests.sh
@@ -38,6 +38,7 @@ nosetests --with-xunit \
          --cover-package=functest.utils \
          --cover-xml \
          --cover-html \
+         --log-config=$(pwd)/functest/tests/unit/test_logging.ini \
          functest/tests/unit
 rc=$?