Add logging to file for OSTF tests
After that change when performing a OSTF test its result will be logged to a file under /var/log/ostf directory. Each file has name in format cluseter_CLUSTER_ID_TESTSET.log, for example: cluster_1_smoke.log * added ResultsLogger for logging tests restuts * removed deprecation because of wrong import in models Change-Id: If69a4292fcc66565ba969396d591e38eddba92ce Closes-Bug: #1297958
This commit is contained in:
Sebastian Kalinowski
parent
32cf2541ab
commit
727cd3cc93
|
|
@ -17,10 +17,58 @@ import logging
|
|||
import logging.handlers
|
||||
|
||||
|
||||
_LOG_TIME_FORMAT = "%Y-%m-%d %H:%M:%S"
|
||||
|
||||
|
||||
class ResultsLogger(object):
|
||||
"""Logger used to log results of OSTF tests. Resutls are stored in
|
||||
/var/log/ostf/ dir. Each cluster has one log file per each set of tests.
|
||||
"""
|
||||
|
||||
def __init__(self, testset, cluster_id):
|
||||
self.testset = testset
|
||||
self.cluster_id = cluster_id
|
||||
self.filename = self._make_filename()
|
||||
self._logger = self._init_file_logger()
|
||||
|
||||
def _init_file_logger(self):
|
||||
logger = logging.getLogger('ostf-results-log-{0}-{1}'.format(
|
||||
self.cluster_id, self.testset))
|
||||
|
||||
if not logger.handlers:
|
||||
log_dir = '/var/log/ostf'
|
||||
log_file = os.path.join(log_dir, self.filename)
|
||||
|
||||
file_handler = logging.handlers.WatchedFileHandler(log_file)
|
||||
file_handler.setLevel(logging.DEBUG)
|
||||
|
||||
formatter = logging.Formatter(
|
||||
'%(asctime)s %(message)s',
|
||||
_LOG_TIME_FORMAT)
|
||||
file_handler.setFormatter(formatter)
|
||||
|
||||
logger.addHandler(file_handler)
|
||||
|
||||
logger.propagate = 0
|
||||
|
||||
return logger
|
||||
|
||||
def _make_filename(self):
|
||||
return 'cluster_{cluster_id}_{testset}.log'.format(
|
||||
testset=self.testset, cluster_id=self.cluster_id)
|
||||
|
||||
def log_results(self, test_id, test_name, status, message, traceback):
|
||||
status = status.upper()
|
||||
msg = "{status} {test_name} ({test_id}) {message} {traceback}".format(
|
||||
test_name=test_name, test_id=test_id, status=status,
|
||||
message=message, traceback=traceback)
|
||||
self._logger.info(msg)
|
||||
|
||||
|
||||
def setup(log_file=None):
|
||||
formatter = logging.Formatter(
|
||||
'%(asctime)s %(levelname)s (%(module)s) %(message)s',
|
||||
"%Y-%m-%d %H:%M:%S")
|
||||
_LOG_TIME_FORMAT)
|
||||
log = logging.getLogger(None)
|
||||
stream_handler = logging.StreamHandler()
|
||||
stream_handler.setLevel(logging.INFO)
|
||||
|
|
|
|||
|
|
@ -19,6 +19,7 @@ import signal
|
|||
|
||||
from oslo.config import cfg
|
||||
|
||||
from fuel_plugin.ostf_adapter.logger import ResultsLogger
|
||||
from fuel_plugin.ostf_adapter.nose_plugin import nose_test_runner
|
||||
from fuel_plugin.ostf_adapter.nose_plugin import nose_utils
|
||||
from fuel_plugin.ostf_adapter.storage import engine, models
|
||||
|
|
@ -53,6 +54,8 @@ class NoseDriver(object):
|
|||
else:
|
||||
argv_add = [test_set.test_path] + test_set.additional_arguments
|
||||
|
||||
results_log = ResultsLogger(test_set.id, test_run.cluster_id)
|
||||
|
||||
lock_path = cfg.CONF.adapter.lock_dir
|
||||
test_run.pid = nose_utils.run_proc(self._run_tests,
|
||||
lock_path,
|
||||
|
|
@ -61,10 +64,12 @@ class NoseDriver(object):
|
|||
test_run.cluster_id,
|
||||
ostf_os_access_creds,
|
||||
argv_add,
|
||||
token).pid
|
||||
token,
|
||||
results_log).pid
|
||||
|
||||
def _run_tests(self, lock_path, dbpath, test_run_id,
|
||||
cluster_id, ostf_os_access_creds, argv_add, token):
|
||||
cluster_id, ostf_os_access_creds, argv_add, token,
|
||||
results_log):
|
||||
cleanup_flag = False
|
||||
|
||||
def raise_exception_handler(signum, stack_frame):
|
||||
|
|
@ -91,7 +96,7 @@ class NoseDriver(object):
|
|||
nose_test_runner.SilentTestProgram(
|
||||
addplugins=[nose_storage_plugin.StoragePlugin(
|
||||
session, test_run_id, str(cluster_id),
|
||||
ostf_os_access_creds, token
|
||||
ostf_os_access_creds, token, results_log
|
||||
)],
|
||||
exit=False,
|
||||
argv=['ostf_tests'] + argv_add)
|
||||
|
|
|
|||
|
|
@ -34,12 +34,13 @@ class StoragePlugin(plugins.Plugin):
|
|||
score = 15000
|
||||
|
||||
def __init__(self, session, test_run_id, cluster_id,
|
||||
ostf_os_access_creds, token):
|
||||
ostf_os_access_creds, token, results_log):
|
||||
|
||||
self.session = session
|
||||
self.test_run_id = test_run_id
|
||||
self.cluster_id = cluster_id
|
||||
self.ostf_os_access_creds = ostf_os_access_creds
|
||||
self.results_log = results_log
|
||||
|
||||
super(StoragePlugin, self).__init__()
|
||||
self._start_time = None
|
||||
|
|
@ -59,8 +60,26 @@ class StoragePlugin(plugins.Plugin):
|
|||
def configure(self, options, conf):
|
||||
self.conf = conf
|
||||
|
||||
def _add_message(
|
||||
self, test, err=None, status=None):
|
||||
def _add_test_results(self, test, data):
|
||||
test_id = test.id()
|
||||
|
||||
models.Test.add_result(
|
||||
self.session,
|
||||
self.test_run_id,
|
||||
test_id,
|
||||
data
|
||||
)
|
||||
if data['status'] != 'running':
|
||||
test_name = nose_utils.get_description(test)[0]
|
||||
self.results_log.log_results(
|
||||
test_id,
|
||||
test_name=test_name,
|
||||
status=data['status'],
|
||||
message=data['message'],
|
||||
traceback=data['traceback'],
|
||||
)
|
||||
|
||||
def _add_message(self, test, err=None, status=None):
|
||||
data = {
|
||||
'status': status,
|
||||
'time_taken': self.taken,
|
||||
|
|
@ -70,19 +89,18 @@ class StoragePlugin(plugins.Plugin):
|
|||
}
|
||||
if err:
|
||||
exc_type, exc_value, exc_traceback = err
|
||||
|
||||
if not status == 'error':
|
||||
data['step'], data['message'] = \
|
||||
nose_utils.format_failure_message(exc_value)
|
||||
|
||||
tests_to_update = nose_utils.get_tests_ids_to_update(test)
|
||||
if status != 'skipped':
|
||||
data['traceback'] = nose_utils.format_exception(err)
|
||||
|
||||
for test_id in tests_to_update:
|
||||
models.Test.add_result(
|
||||
self.session,
|
||||
self.test_run_id,
|
||||
test_id,
|
||||
data
|
||||
)
|
||||
tests_to_update = nose_utils.get_tests_to_update(test)
|
||||
|
||||
for test in tests_to_update:
|
||||
self._add_test_results(test, data)
|
||||
self.session.commit()
|
||||
|
||||
def addSuccess(self, test, capt=None):
|
||||
|
|
|
|||
|
|
@ -144,7 +144,7 @@ def get_module(module_path):
|
|||
pass
|
||||
|
||||
|
||||
def get_tests_ids_to_update(test):
|
||||
def get_tests_to_update(test):
|
||||
'''
|
||||
Sometimes (e.g. unhandles exception is occured in
|
||||
setUpClass of test case) tests can be packed in
|
||||
|
|
@ -154,15 +154,15 @@ def get_tests_ids_to_update(test):
|
|||
(which is not good by any means and you are free to
|
||||
modify that if you can)
|
||||
'''
|
||||
tests_ids = []
|
||||
tests = []
|
||||
|
||||
if isinstance(test, case.Test):
|
||||
tests_ids.append(test.id())
|
||||
tests.append(test)
|
||||
elif isinstance(test, ContextSuite):
|
||||
for sub_test in test._tests:
|
||||
tests_ids.extend(get_tests_ids_to_update(sub_test))
|
||||
tests.extend(get_tests_to_update(sub_test))
|
||||
|
||||
return tests_ids
|
||||
return tests
|
||||
|
||||
|
||||
def process_deployment_tags(cluster_depl_tags, test_depl_tags):
|
||||
|
|
|
|||
|
|
@ -20,7 +20,7 @@ from sqlalchemy import desc
|
|||
from sqlalchemy.ext.declarative import declarative_base
|
||||
from sqlalchemy.ext.associationproxy import association_proxy
|
||||
from sqlalchemy.orm import joinedload, relationship, object_mapper
|
||||
from sqlalchemy.dialects.postgres import ARRAY
|
||||
from sqlalchemy.dialects.postgresql import ARRAY
|
||||
|
||||
from fuel_plugin.ostf_adapter import nose_plugin
|
||||
from fuel_plugin.ostf_adapter.storage import fields, engine
|
||||
|
|
|
|||
|
|
@ -0,0 +1,74 @@
|
|||
# -*- coding: utf-8 -*-
|
||||
|
||||
# Copyright 2014 Mirantis, Inc.
|
||||
#
|
||||
# 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 mock
|
||||
from unittest2 import TestCase
|
||||
|
||||
from fuel_plugin.ostf_adapter.logger import ResultsLogger
|
||||
|
||||
|
||||
class TestResultsLogger(TestCase):
|
||||
|
||||
def get_logger(self, **kwargs):
|
||||
options = {
|
||||
'testset': 'testset',
|
||||
'cluster_id': 1,
|
||||
}
|
||||
options.update(kwargs)
|
||||
return ResultsLogger(**options)
|
||||
|
||||
def test_filename(self):
|
||||
logger = self.get_logger(testset='testset_name',
|
||||
cluster_id=99)
|
||||
expected = "cluster_99_testset_name.log"
|
||||
|
||||
self.assertEqual(logger.filename, expected)
|
||||
|
||||
def test_log_format_on_success(self):
|
||||
logger = self.get_logger()
|
||||
logger._logger = mock.Mock()
|
||||
|
||||
logger.log_results(
|
||||
test_id='tests.successful.test', test_name='Successful test',
|
||||
status='SUCCESS', message='', traceback='')
|
||||
|
||||
expected = 'SUCCESS Successful test (tests.successful.test) '
|
||||
logger._logger.info.assert_called_once_with(expected)
|
||||
|
||||
def test_log_format_on_fail(self):
|
||||
logger = self.get_logger()
|
||||
logger._logger = mock.Mock()
|
||||
|
||||
logger.log_results(
|
||||
test_id='tests.failing.test', test_name='Failing test',
|
||||
status='FAIL', message='Message after fail', traceback='TRACEBACK')
|
||||
|
||||
expected = ('FAIL Failing test (tests.failing.test) '
|
||||
'Message after fail TRACEBACK')
|
||||
logger._logger.info.assert_called_once_with(expected)
|
||||
|
||||
def test_log_format_on_error(self):
|
||||
logger = self.get_logger()
|
||||
logger._logger = mock.Mock()
|
||||
|
||||
logger.log_results(
|
||||
test_id='tests.error.test', test_name='Error test',
|
||||
status='ERROR', message='Message after error',
|
||||
traceback="TRACEBACK")
|
||||
|
||||
expected = ('ERROR Error test (tests.error.test) '
|
||||
'Message after error TRACEBACK')
|
||||
logger._logger.info.assert_called_once_with(expected)
|
||||
Loading…
Reference in New Issue