Configure logging format flexibly

Now we can get tempest log file with options in run_tests.sh.
This adds log.py and enables to configure log format more flexibly
using configuration file.
This adds a LoggerAdaptor and a Formatter to output each test name
to log lines.

Implements: blueprint add-logging-configuration

Change-Id: I88cf18bb8bbc152e62ac83a9c7dc26067b7a11bd

etc/logging.conf.sample

@@ -1,30 +1,41 @@
 [loggers]
-keys=root
-
-[formatters]
-keys=normal,debug
+keys=root,tempest
 
 [handlers]
-keys=file,devel
+keys=file,syslog,devel
+
+[formatters]
+keys=default,tests
 
 [logger_root]
 level=NOTSET
+handlers=syslog
+
+[logger_tempest]
+level=DEBUG
 handlers=file
+qualname=tempest
 
 [handler_file]
 class=FileHandler
 level=DEBUG
-formatter=normal
+formatter=tests
 args=('tempest.log', 'w')
 
+[handler_syslog]
+class=handlers.SysLogHandler
+level=ERROR
+formatter = default
+args = ('/dev/log', handlers.SysLogHandler.LOG_USER)
+
 [handler_devel]
 class=StreamHandler
 level=DEBUG
-formatter=debug
+formatter=default
 args=(sys.stdout,)
 
-[formatter_normal]
-format=%(asctime)s %(levelname)s %(message)s
+[formatter_default]
+format=%(name)s: %(levelname)s: %(message)s
 
-[formatter_debug]
-format=%(asctime)s %(levelname)s %(module)s %(funcName)s %(message)s
+[formatter_tests]
+class = tempest.common.log.TestsFormatter

run_tests.sh

@@ -75,6 +75,16 @@ if [ -n "$config_file" ]; then
     export TEMPEST_CONFIG=`basename "$config_file"`
 fi
 
+if [ $logging -eq 1 ]; then
+    if [ ! -f "$logging_config" ]; then
+        echo "No such logging config file: $logging_config"
+        exit 1
+    fi
+    logging_config=`readlink -f "$logging_config"`
+    export TEMPEST_LOG_CONFIG_DIR=`dirname "$logging_config"`
+    export TEMPEST_LOG_CONFIG=`basename "$logging_config"`
+fi
+
 cd `dirname "$0"`
 
 export NOSE_WITH_OPENSTACK=1
@@ -84,14 +94,6 @@ export NOSE_OPENSTACK_YELLOW=3.00
 export NOSE_OPENSTACK_SHOW_ELAPSED=1
 export NOSE_OPENSTACK_STDOUT=1
 
-if [ $logging -eq 1 ]; then
-    if [ ! -f "$logging_config" ]; then
-        echo "No such logging config file: $logging_config"
-        exit
-    fi
-    noseargs="$noseargs --logging-config=$logging_config"
-fi
-
 if [ $no_site_packages -eq 1 ]; then
   installvenvopts="--no-site-packages"
 fi

tempest/api/compute/__init__.py

@@ -15,10 +15,8 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
-
 from tempest import clients
+from tempest.common import log as logging
 from tempest import config
 from tempest.exceptions import InvalidConfiguration
 

tempest/api/compute/base.py

@@ -15,11 +15,11 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import time
 
 from tempest.api import compute
 from tempest import clients
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest import exceptions
 import tempest.test

tempest/api/identity/__init__.py

@@ -15,7 +15,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
+from tempest.common import log as logging
 
 LOG = logging.getLogger(__name__)
 

tempest/api/image/base.py

@@ -14,9 +14,8 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
 from tempest import clients
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest import exceptions
 import tempest.test

tempest/api/volume/admin/test_multi_backend.py

@@ -15,10 +15,10 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import testtools
 
 from tempest.api.volume import base
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest import config
 from tempest.services.volume.json.admin import volume_types_client

tempest/api/volume/base.py

@@ -15,10 +15,10 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import time
 
 from tempest import clients
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest import exceptions
 import tempest.test

tempest/api/volume/test_volumes_snapshots.py

@@ -12,10 +12,10 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import testtools
 
 from tempest.api.volume import base
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest.test import attr
 

tempest/clients.py

@@ -15,8 +15,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
+from tempest.common import log as logging
 from tempest import config
 from tempest import exceptions
 from tempest.services import botoclients

tempest/common/glance_http.py

@@ -19,7 +19,6 @@ import copy
 import hashlib
 import httplib
 import json
-import logging
 import posixpath
 import re
 import socket
@@ -35,6 +34,7 @@ if not hasattr(urlparse, 'parse_qsl'):
 
 import OpenSSL
 
+from tempest.common import log as logging
 from tempest import exceptions as exc
 
 

tempest/common/log.py

@@ -0,0 +1,116 @@
+# vim: tabstop=4 shiftwidth=4 softtabstop=4
+
+# Copyright 2013 NEC Corporation.
+# All Rights Reserved.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+import ConfigParser
+import inspect
+import logging
+import logging.config
+import os
+import re
+
+from oslo.config import cfg
+
+
+_DEFAULT_LOG_FORMAT = "%(asctime)s %(levelname)8s [%(name)s] %(message)s"
+_DEFAULT_LOG_DATE_FORMAT = "%Y-%m-%d %H:%M:%S"
+
+_loggers = {}
+
+
+def getLogger(name='unknown'):
+    if len(_loggers) == 0:
+        loaded = _load_log_config()
+        getLogger.adapter = TestsAdapter if loaded else None
+
+    if name not in _loggers:
+        logger = logging.getLogger(name)
+        if getLogger.adapter:
+            _loggers[name] = getLogger.adapter(logger, name)
+        else:
+            _loggers[name] = logger
+
+    return _loggers[name]
+
+
+def _load_log_config():
+    conf_dir = os.environ.get('TEMPEST_LOG_CONFIG_DIR', None)
+    conf_file = os.environ.get('TEMPEST_LOG_CONFIG', None)
+    if not conf_dir or not conf_file:
+        return False
+
+    log_config = os.path.join(conf_dir, conf_file)
+    try:
+        logging.config.fileConfig(log_config)
+    except ConfigParser.Error, exc:
+        raise cfg.ConfigFileParseError(log_config, str(exc))
+    return True
+
+
+class TestsAdapter(logging.LoggerAdapter):
+
+    def __init__(self, logger, project_name):
+        self.logger = logger
+        self.project = project_name
+        self.regexp = re.compile(r"test_\w+\.py")
+
+    def __getattr__(self, key):
+        return getattr(self.logger, key)
+
+    def _get_test_name(self):
+        frames = inspect.stack()
+        for frame in frames:
+            binary_name = frame[1]
+            if self.regexp.search(binary_name) and 'self' in frame[0].f_locals:
+                return frame[0].f_locals.get('self').id()
+            elif frame[3] == '_run_cleanups':
+                #NOTE(myamazaki): method calling addCleanup
+                return frame[0].f_locals.get('self').case.id()
+            elif frame[3] in ['setUpClass', 'tearDownClass']:
+                #NOTE(myamazaki): setUpClass or tearDownClass
+                return "%s.%s.%s" % (frame[0].f_locals['cls'].__module__,
+                                     frame[0].f_locals['cls'].__name__,
+                                     frame[3])
+        return None
+
+    def process(self, msg, kwargs):
+        if 'extra' not in kwargs:
+            kwargs['extra'] = {}
+        extra = kwargs['extra']
+
+        test_name = self._get_test_name()
+        if test_name:
+            extra.update({'testname': test_name})
+        extra['extra'] = extra.copy()
+
+        return msg, kwargs
+
+
+class TestsFormatter(logging.Formatter):
+    def __init__(self, fmt=None, datefmt=None):
+        super(TestsFormatter, self).__init__()
+        self.default_format = _DEFAULT_LOG_FORMAT
+        self.testname_format =\
+            "%(asctime)s %(levelname)8s [%(testname)s] %(message)s"
+        self.datefmt = _DEFAULT_LOG_DATE_FORMAT
+
+    def format(self, record):
+        extra = record.__dict__.get('extra', None)
+        if extra and 'testname' in extra:
+            self._fmt = self.testname_format
+        else:
+            self._fmt = self.default_format
+        return logging.Formatter.format(self, record)

tempest/common/rest_client.py

@@ -19,11 +19,11 @@ import collections
 import hashlib
 import httplib2
 import json
-import logging
 from lxml import etree
 import re
 import time
 
+from tempest.common import log as logging
 from tempest import exceptions
 from tempest.services.compute.xml.common import xml_to_json
 

tempest/config.py

@@ -15,12 +15,12 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import os
 import sys
 
 from oslo.config import cfg
 
+from tempest.common import log as logging
 from tempest.common.utils.misc import singleton
 
 LOG = logging.getLogger(__name__)

tempest/manager.py

@@ -15,8 +15,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
+from tempest.common import log as logging
 import tempest.config
 from tempest import exceptions
 # Tempest REST Fuzz testing client libs

tempest/scenario/test_server_advanced_ops.py

@@ -15,9 +15,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
-
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest.scenario import manager
 

tempest/scenario/test_server_basic_ops.py

@@ -15,8 +15,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest.scenario import manager
 

tempest/services/compute/xml/servers_client.py

@@ -16,12 +16,12 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import time
 import urllib
 
 from lxml import etree
 
+from tempest.common import log as logging
 from tempest.common.rest_client import RestClientXML
 from tempest import exceptions
 from tempest.services.compute.xml.common import Document

tempest/services/image/v1/json/image_client.py

@@ -18,12 +18,12 @@
 import copy
 import errno
 import json
-import logging
 import os
 import time
 import urllib
 
 from tempest.common import glance_http
+from tempest.common import log as logging
 from tempest.common.rest_client import RestClient
 from tempest import exceptions
 

tempest/services/volume/json/snapshots_client.py

@@ -13,10 +13,10 @@
 #    under the License.
 
 import json
-import logging
 import time
 import urllib
 
+from tempest.common import log as logging
 from tempest.common.rest_client import RestClient
 from tempest import exceptions
 

tempest/services/volume/xml/snapshots_client.py

@@ -12,12 +12,12 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import time
 import urllib
 
 from lxml import etree
 
+from tempest.common import log as logging
 from tempest.common.rest_client import RestClientXML
 from tempest import exceptions
 from tempest.services.compute.xml.common import Document

tempest/test.py

@@ -15,13 +15,13 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import time
 
 import nose.plugins.attrib
 import testresources
 import testtools
 
+from tempest.common import log as logging
 from tempest import config
 from tempest import manager
 

tempest/thirdparty/boto/test.py

@@ -16,7 +16,7 @@
 #    under the License.
 
 import contextlib
-import logging
+import logging as orig_logging
 import os
 import re
 import urlparse
@@ -28,6 +28,7 @@ from boto import s3
 import keystoneclient.exceptions
 
 import tempest.clients
+from tempest.common import log as logging
 from tempest.common.utils.file_utils import have_effective_read_access
 import tempest.config
 from tempest import exceptions
@@ -58,7 +59,7 @@ def decision_maker():
     A_I_IMAGES_READY = all_read(ami_path, aki_path, ari_path)
     boto_logger = logging.getLogger('boto')
     level = boto_logger.level
-    boto_logger.setLevel(logging.CRITICAL)  # suppress logging for these
+    boto_logger.setLevel(orig_logging.CRITICAL)  # suppress logging for these
 
     def _cred_sub_check(connection_data):
         if not id_matcher.match(connection_data["aws_access_key_id"]):

tempest/thirdparty/boto/test_ec2_instance_run.py

@@ -15,12 +15,11 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
 from boto import exception
 import testtools
 
 from tempest import clients
+from tempest.common import log as logging
 from tempest.common.utils.data_utils import rand_name
 from tempest.common.utils.linux.remote_client import RemoteClient
 from tempest import exceptions

tempest/thirdparty/boto/test_ec2_volumes.py

@@ -15,9 +15,8 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
-
 from tempest import clients
+from tempest.common import log as logging
 from tempest.test import attr
 from tempest.thirdparty.boto.test import BotoTestCase
 

tempest/thirdparty/boto/utils/s3.py

@@ -16,13 +16,14 @@
 #    under the License.
 
 import contextlib
-import logging
 import os
 import re
 
 import boto
 import boto.s3.key
 
+from tempest.common import log as logging
+
 LOG = logging.getLogger(__name__)
 
 

tempest/thirdparty/boto/utils/wait.py

@@ -15,13 +15,13 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import re
 import time
 
 import boto.exception
 from testtools import TestCase
 
+from tempest.common import log as logging
 import tempest.config
 
 LOG = logging.getLogger(__name__)

tempest/whitebox/manager.py

@@ -15,7 +15,6 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
-import logging
 import os
 import shlex
 import subprocess
@@ -23,6 +22,7 @@ import sys
 
 from sqlalchemy import create_engine, MetaData
 
+from tempest.common import log as logging
 from tempest.common.ssh import Client
 from tempest.common.utils.data_utils import rand_name
 from tempest import exceptions