From 1c1d3d1ddc21ae28deabef9f5f6e310d46fdf0ef Mon Sep 17 00:00:00 2001 From: dongwenjuan Date: Mon, 28 Aug 2017 17:14:03 +0800 Subject: add running profiler in python For support bash and python both, I don't refactor the profiler_poc file, just call the func in python main. JIRA: DOCTOR-117 Change-Id: I5f06ecbd673c6a21acc94cc359a3f2b749b77b13 Signed-off-by: dongwenjuan --- etc/doctor.sample.conf | 2 + tests/common/utils.py | 14 ++++++ tests/config.py | 4 +- tests/main.py | 40 +++++++++++++++ tests/profiler-poc.py | 87 --------------------------------- tests/profiler_poc.py | 100 ++++++++++++++++++++++++++++++++++++++ tests/run.sh | 2 +- tests/scenario/common.py | 30 ++++-------- tests/scenario/network_failure.py | 6 +-- tox.ini | 1 + 10 files changed, 173 insertions(+), 113 deletions(-) delete mode 100644 tests/profiler-poc.py create mode 100644 tests/profiler_poc.py diff --git a/etc/doctor.sample.conf b/etc/doctor.sample.conf index 52d78d6b..f81d3b2d 100644 --- a/etc/doctor.sample.conf +++ b/etc/doctor.sample.conf @@ -31,6 +31,8 @@ #alarm_basename = doctor_alarm +#profiler_type = poc + [installer] #type = local #ip = 127.0.0.1 diff --git a/tests/common/utils.py b/tests/common/utils.py index 38fd97d8..2e823acb 100644 --- a/tests/common/utils.py +++ b/tests/common/utils.py @@ -9,6 +9,7 @@ import json import os import paramiko +import re def load_json_file(full_path): @@ -33,6 +34,19 @@ def write_json_file(full_path, data): file.write(json.dumps(data)) +def match_rep_in_file(regex, full_path): + if not os.path.isfile(full_path): + raise Exception('File(%s) does not exist' % full_path) + + with open(full_path, 'r') as file: + for line in file: + result = re.search(regex, line) + if result: + return result + + return None + + class SSHClient(object): def __init__(self, ip, username, password=None, pkey=None, key_filename=None, log=None, look_for_keys=False, diff --git a/tests/config.py b/tests/config.py index f33ab5d2..c71d5ad7 100644 --- a/tests/config.py +++ b/tests/config.py @@ -19,6 +19,7 @@ import network import inspector import monitor import os_clients +import profiler_poc import user @@ -34,7 +35,8 @@ def list_opts(): user.OPTS, network.OPTS, instance.OPTS, - alarm.OPTS)) + alarm.OPTS, + profiler_poc.OPTS)) ] diff --git a/tests/main.py b/tests/main.py index 7e7c3bc2..df7e95f3 100644 --- a/tests/main.py +++ b/tests/main.py @@ -14,6 +14,7 @@ import time from alarm import Alarm from common.constants import Host +from common.utils import match_rep_in_file import config from consumer import get_consumer from identity_auth import get_identity_auth @@ -26,6 +27,7 @@ import logger as doctor_log from network import Network from monitor import get_monitor from os_clients import nova_client +from profiler_poc import main as profiler_main from scenario.common import calculate_notification_time from scenario.network_failure import NetworkFault from user import User @@ -110,6 +112,11 @@ class DoctorTest(object): else: LOG.error('doctor test failed, notification_time=%s' % notification_time) sys.exit(1) + + if self.conf.profiler_type: + LOG.info('doctor test begin to run profile.......') + self.collect_logs() + self.run_profiler() except Exception as e: LOG.error('doctor test failed, Exception=%s' % e) sys.exit(1) @@ -145,6 +152,39 @@ class DoctorTest(object): time.sleep(2) self.check_host_status(self.down_host.name, 'up') + def collect_logs(self): + self.fault.get_disable_network_log() + + def run_profiler(self): + + log_file = '{0}/{1}'.format(sys.path[0], 'disable_network.log') + reg = '(?<=doctor set link down at )\d+.\d+' + linkdown = float(match_rep_in_file(reg, log_file).group(0)) + + log_file = '{0}/{1}'.format(sys.path[0], 'doctor.log') + reg = '(.* doctor mark vm.* error at )(\d+.\d+)' + vmdown = float(match_rep_in_file(reg, log_file).group(2)) + + reg = '(?<=doctor mark host.* down at )\d+.\d+' + hostdown = float(match_rep_in_file(reg, log_file).group(2)) + + reg = '(?<=doctor monitor detected at )\d+.\d+' + detected = float(match_rep_in_file(reg, log_file).group(0)) + + reg = '(?<=doctor consumer notified at )\d+.\d+' + notified = float(match_rep_in_file(reg, log_file).group(0)) + + # TODO(yujunz) check the actual delay to verify time sync status + # expected ~1s delay from $trigger to $linkdown + relative_start = linkdown + os.environ['DOCTOR_PROFILER_T00'] = str(int((linkdown - relative_start)*1000)) + os.environ['DOCTOR_PROFILER_T01'] = str(int((detected - relative_start) * 1000)) + os.environ['DOCTOR_PROFILER_T03'] = str(int((vmdown - relative_start) * 1000)) + os.environ['DOCTOR_PROFILER_T04'] = str(int((hostdown - relative_start) * 1000)) + os.environ['DOCTOR_PROFILER_T09'] = str(int((notified - relative_start) * 1000)) + + profiler_main(log=LOG) + def cleanup(self): self.unset_forced_down_hosts() self.inspector.stop() diff --git a/tests/profiler-poc.py b/tests/profiler-poc.py deleted file mode 100644 index 408cb09a..00000000 --- a/tests/profiler-poc.py +++ /dev/null @@ -1,87 +0,0 @@ -############################################################################## -# Copyright (c) 2016 ZTE Corporation and others. -# -# All rights reserved. This program and the accompanying materials -# are made available under the terms of the Apache License, Version 2.0 -# which accompanies this distribution, and is available at -# http://www.apache.org/licenses/LICENSE-2.0 -############################################################################## - -""" -PoC of performance profiler for OPNFV doctor project - -Usage: - -Export environment variables to set timestamp at each checkpoint in millisecond. -Valid check points are: DOCTOR_PROFILER_T{00-09} - -See also: https://goo.gl/98Osig -""" - -import json -import os - -OUTPUT = 'doctor_profiling_output' -PREFIX = 'DOCTOR_PROFILER' -TOTAL_CHECK_POINTS = 10 -MODULE_CHECK_POINTS = ['T00', 'T01', 'T04', 'T05', 'T06', 'T09'] -TAG_FORMAT = "{:<5}" -# Inspired by https://github.com/reorx/httpstat -TEMPLATE = """ -Total time cost: {total}(ms) -==============================================================================> - |Monitor|Inspector |Controller|Notifier|Evaluator | - |{M00} |{M01} |{M02} |{M03} |{M04} | - | | | | | | | | | | -link down:{T00}| | | | | | | | | - raw failure:{T01}| | | | | | | | - found affected:{T02}| | | | | | | - set VM error:{T03}| | | | | | - marked host down:{T04}| | | | | - notified VM error:{T05} | | | | - transformed event:{T06}| | | - evaluated event:{T07}| | - fired alarm:{T08}| - received alarm:{T09} -""" - - -def main(): - check_points = ["T{:02d}".format(i) for i in range(TOTAL_CHECK_POINTS)] - module_map = {"M{:02d}".format(i): - (MODULE_CHECK_POINTS[i], MODULE_CHECK_POINTS[i + 1]) - for i in range(len(MODULE_CHECK_POINTS) - 1)} - - # check point tags - elapsed_ms = {cp: os.getenv("{}_{}".format(PREFIX, cp)) - for cp in check_points} - - def format_tag(tag): - return TAG_FORMAT.format(tag or '?') - - tags = {cp: format_tag(ms) for cp, ms in elapsed_ms.iteritems()} - - def time_cost(cp): - if elapsed_ms[cp[0]] and elapsed_ms[cp[1]]: - return int(elapsed_ms[cp[1]]) - int(elapsed_ms[cp[0]]) - else: - return None - - # module time cost tags - modules_cost_ms = {module: time_cost(cp) - for module, cp in module_map.iteritems()} - - tags.update({module: format_tag(cost) - for module, cost in modules_cost_ms.iteritems()}) - - tags.update({'total': time_cost((check_points[0], check_points[-1]))}) - - profile = TEMPLATE.format(**tags) - - logfile = open('{}.json'.format(OUTPUT), 'w') - logfile.write(json.dumps(tags)) - - print profile - -if __name__ == '__main__': - main() diff --git a/tests/profiler_poc.py b/tests/profiler_poc.py new file mode 100644 index 00000000..ea36eaeb --- /dev/null +++ b/tests/profiler_poc.py @@ -0,0 +1,100 @@ +############################################################################## +# Copyright (c) 2016 ZTE Corporation and others. +# +# All rights reserved. This program and the accompanying materials +# are made available under the terms of the Apache License, Version 2.0 +# which accompanies this distribution, and is available at +# http://www.apache.org/licenses/LICENSE-2.0 +############################################################################## + +""" +PoC of performance profiler for OPNFV doctor project + +Usage: + +Export environment variables to set timestamp at each checkpoint in millisecond. +Valid check points are: DOCTOR_PROFILER_T{00-09} + +See also: https://goo.gl/98Osig +""" + +import json +import os + +from oslo_config import cfg + + +OPTS = [ + cfg.StrOpt('profiler_type', + default=os.environ.get('PROFILER_TYPE', 'poc'), + help='the type of installer'), +] + + +OUTPUT = 'doctor_profiling_output' +PREFIX = 'DOCTOR_PROFILER' +TOTAL_CHECK_POINTS = 10 +MODULE_CHECK_POINTS = ['T00', 'T01', 'T04', 'T05', 'T06', 'T09'] +TAG_FORMAT = "{:<5}" +# Inspired by https://github.com/reorx/httpstat +TEMPLATE = """ +Total time cost: {total}(ms) +==============================================================================> + |Monitor|Inspector |Controller|Notifier|Evaluator | + |{M00} |{M01} |{M02} |{M03} |{M04} | + | | | | | | | | | | +link down:{T00}| | | | | | | | | + raw failure:{T01}| | | | | | | | + found affected:{T02}| | | | | | | + set VM error:{T03}| | | | | | + marked host down:{T04}| | | | | + notified VM error:{T05} | | | | + transformed event:{T06}| | | + evaluated event:{T07}| | + fired alarm:{T08}| + received alarm:{T09} +""" + + +def main(log=None): + check_points = ["T{:02d}".format(i) for i in range(TOTAL_CHECK_POINTS)] + module_map = {"M{:02d}".format(i): + (MODULE_CHECK_POINTS[i], MODULE_CHECK_POINTS[i + 1]) + for i in range(len(MODULE_CHECK_POINTS) - 1)} + + # check point tags + elapsed_ms = {cp: os.getenv("{}_{}".format(PREFIX, cp)) + for cp in check_points} + + def format_tag(tag): + return TAG_FORMAT.format(tag or '?') + + tags = {cp: format_tag(ms) for cp, ms in elapsed_ms.items()} + + def time_cost(cp): + if elapsed_ms[cp[0]] and elapsed_ms[cp[1]]: + return int(elapsed_ms[cp[1]]) - int(elapsed_ms[cp[0]]) + else: + return None + + # module time cost tags + modules_cost_ms = {module: time_cost(cp) + for module, cp in module_map.items()} + + tags.update({module: format_tag(cost) + for module, cost in modules_cost_ms.items()}) + + tags.update({'total': time_cost((check_points[0], check_points[-1]))}) + + profile = TEMPLATE.format(**tags) + + logfile = open('{}.json'.format(OUTPUT), 'w') + logfile.write(json.dumps(tags)) + + print(profile) + if log: + log.info('%s' % profile) + + +if __name__ == '__main__': + main() diff --git a/tests/run.sh b/tests/run.sh index dceb0614..e1875e09 100755 --- a/tests/run.sh +++ b/tests/run.sh @@ -421,7 +421,7 @@ run_profiler() { export DOCTOR_PROFILER_T09=$(python -c \ "print(int(($notified-$relative_start)*1000))") - python profiler-poc.py > doctor_profiler.log 2>&1 + python profiler_poc.py > doctor_profiler.log 2>&1 fi } diff --git a/tests/scenario/common.py b/tests/scenario/common.py index e880e8b2..a33c50ff 100644 --- a/tests/scenario/common.py +++ b/tests/scenario/common.py @@ -6,35 +6,23 @@ # which accompanies this distribution, and is available at # http://www.apache.org/licenses/LICENSE-2.0 ############################################################################## -import os -import re import sys - - -def match_rep_in_file(regex, full_path): - if not os.path.isfile(full_path): - raise Exception('File(%s) does not exist' % full_path) - - with open(full_path, 'r') as file: - for line in file: - result = re.search(regex, line) - if result: - return result.group(0) - - return None +from common.utils import match_rep_in_file def calculate_notification_time(): log_file = '{0}/{1}'.format(sys.path[0], 'doctor.log') reg = '(?<=doctor monitor detected at )\d+.\d+' - detected = match_rep_in_file(reg, log_file) - if not detected: - raise Exception('Can not find detected time') + result = match_rep_in_file(reg, log_file) + if not result: + raise Exception('Can not match detected time') + detected = result.group(0) reg = '(?<=doctor consumer notified at )\d+.\d+' - notified = match_rep_in_file(reg, log_file) - if not notified: - raise Exception('Can not find notified time') + result = match_rep_in_file(reg, log_file) + if not result: + raise Exception('Can not match notified time') + notified = result.group(0) return float(notified) - float(detected) \ No newline at end of file diff --git a/tests/scenario/network_failure.py b/tests/scenario/network_failure.py index 1d9027a2..e9a239db 100644 --- a/tests/scenario/network_failure.py +++ b/tests/scenario/network_failure.py @@ -40,10 +40,10 @@ class NetworkFault(object): def cleanup(self): self.log.info('fault inject cleanup......') - self.get_diable_network_log() + self.get_disable_network_log() - def get_diable_network_log(self): - if not self.GetLog: + def get_disable_network_log(self): + if self.GetLog: self.log.info('Already get the disable_netork.log from down_host......') return if self.host is not None: diff --git a/tox.ini b/tox.ini index def3c76c..d4babeb8 100644 --- a/tox.ini +++ b/tox.ini @@ -22,6 +22,7 @@ passenv = CI_DEBUG INSTALLER_TYPE INSTALLER_IP + PROFILER_TYPE changedir = {toxinidir}/tests commands = python main.py -- cgit 1.2.3-korg