From: Thierry Parmentelat Date: Sun, 1 Mar 2015 07:22:55 +0000 (+0100) Subject: nicer displays of various durations X-Git-Tag: tests-5.3-10~27 X-Git-Url: http://git.onelab.eu/?p=tests.git;a=commitdiff_plain;h=193c1f9c7cae0bb34a243210f15f094bdd82c7b4 nicer displays of various durations --- diff --git a/system/Completer.py b/system/Completer.py index 2e1586d..5cf3c9b 100755 --- a/system/Completer.py +++ b/system/Completer.py @@ -9,9 +9,10 @@ import utils ### takes in argument a list of tasks that are instances ### of a CompleterTask subclass class Completer: - def __init__ (self, tasks, verbose=True): + def __init__ (self, tasks, verbose=True, message=None): self.tasks=tasks self.verbose=verbose + self.message="({})".format(message) if message else "" def run (self, timeout_timedelta, silent_timedelta, period=None): begin = datetime.now() timeout = begin+timeout_timedelta @@ -30,7 +31,10 @@ class Completer: if success: fine.append(task) for task in fine: tasks.remove(task) if not tasks: - print "Completer duration = {}".format(int(datetime.now()-begin)) + if self.verbose: + duration = datetime.now()-begin + print "total completer {} {}s".format(self.message, + int(duration.total_seconds())) return True if datetime.now() > timeout: for task in tasks: diff --git a/system/TestMain.py b/system/TestMain.py index 3fa6816..dd4fbd3 100755 --- a/system/TestMain.py +++ b/system/TestMain.py @@ -6,9 +6,9 @@ import sys, os, os.path from optparse import OptionParser import traceback -from time import strftime import readline import glob +from datetime import datetime import utils from TestPlc import TestPlc, Ignored @@ -190,9 +190,6 @@ steps refer to a method in TestPlc or to a step_* module help="prompts before each step") parser.add_option("-n","--dry-run", action="store_true", dest="dry_run", default=False, help="Show environment and exits") -# dropped when added Completer.py -# parser.add_option("-r","--restart-nm", action="store_true", dest="forcenm", default=False, -# help="Force the NM to restart in ssh_slices step") parser.add_option("-t","--trace", action="store", dest="trace_file", default=None, help="Trace file location") (self.options, self.args) = parser.parse_args() @@ -410,7 +407,7 @@ steps refer to a method in TestPlc or to a step_* module # do all steps on all plcs TIME_FORMAT="%H-%M-%S" - TRACE_FORMAT="TRACE: %(plc_counter)d %(beg)s->%(end)s status=%(status)s step=%(stepname)s plc=%(plcname)s force=%(force)s\n" + TRACE_FORMAT="TRACE: %(plc_counter)d %(begin)s->%(seconds)ss=%(duration)s status=%(status)s step=%(stepname)s plc=%(plcname)s force=%(force)s\n" for (stepname,method,force,cross,qualifier) in all_step_infos: plc_counter=0 for (spec,plc_obj) in all_plcs: @@ -422,7 +419,8 @@ steps refer to a method in TestPlc or to a step_* module across_plcs = [ o for (s,o) in all_plcs if o!=plc_obj ] # run the step - beg=strftime(TIME_FORMAT) + beg_time = datetime.now() + begin = beg_time.strftime(TIME_FORMAT) if not spec['failed_step'] or force or self.options.interactive or self.options.keep_going: skip_step=False if self.options.interactive: @@ -497,7 +495,9 @@ steps refer to a method in TestPlc or to a step_* module utils.header("********** %d SKIPPED Step %s on %s (%s)"%(plc_counter,stepname,plcname,why)) status="UNDEF" if not self.options.dry_run: - end=strftime(TIME_FORMAT) + delay = datetime.now()-beg_time + seconds = int(delay.total_seconds()) + duration = str(delay) # always do this on stdout print TRACE_FORMAT%locals() # duplicate on trace_file if provided diff --git a/system/TestPlc.py b/system/TestPlc.py index 1d1d7c3..0b07291 100644 --- a/system/TestPlc.py +++ b/system/TestPlc.py @@ -107,7 +107,7 @@ class slice_mapper__tasks (object): test_site = TestSite(self,site_spec) test_slice=TestSlice(self,test_site,slice_spec) tasks += slice_method (test_slice, self.options) - return Completer (tasks).run (decorator_self.timeout, decorator_self.silent, decorator_self.period) + return Completer (tasks, message=method.__name__).run (decorator_self.timeout, decorator_self.silent, decorator_self.period) # restore the doc text from the TestSlice method even if a bit odd wrappee.__name__ = method.__name__ wrappee.__doc__ = slice_method.__doc__ @@ -1040,7 +1040,8 @@ class TestPlc: utils.header("checking nodes boot state (expected %s)"%target_boot_state) tasks = [ CompleterTaskBootState (self,hostname) \ for (hostname,_) in self.all_node_infos() ] - return Completer (tasks).run (timeout, graceout, period) + message = 'check_boot_state={}'.format(target_boot_state) + return Completer (tasks, message=message).run (timeout, graceout, period) def nodes_booted(self): return self.nodes_check_boot_state('boot',timeout_minutes=30,silent_minutes=28) @@ -1065,7 +1066,7 @@ class TestPlc: period=timedelta (seconds=period_seconds) node_infos = self.all_node_infos() tasks = [ CompleterTaskPingNode (h) for (h,_) in node_infos ] - return Completer (tasks).run (timeout, graceout, period) + return Completer (tasks, message='ping_node').run (timeout, graceout, period) # ping node before we try to reach ssh, helpful for troubleshooting failing bootCDs def ping_node (self): @@ -1080,15 +1081,17 @@ class TestPlc: vservername=self.vservername if debug: message="debug" + completer_message = 'ssh_node_debug' local_key = "keys/%(vservername)s-debug.rsa"%locals() else: message="boot" + completer_message = 'ssh_node_boot' local_key = "keys/key_admin.rsa" utils.header("checking ssh access to nodes (expected in %s mode)"%message) node_infos = self.all_node_infos() tasks = [ CompleterTaskNodeSsh (nodename, qemuname, local_key, boot_state=message) \ for (nodename,qemuname) in node_infos ] - return Completer (tasks).run (timeout, graceout, period) + return Completer (tasks, message=completer_message).run (timeout, graceout, period) def ssh_node_debug(self): "Tries to ssh into nodes in debug mode with the debug ssh key" @@ -1161,7 +1164,7 @@ class TestPlc: test_node = TestNode (self,test_site,node) test_sliver = TestSliver (self, test_node, test_slice) tasks.append ( CompleterTaskInitscript (test_sliver, stamp)) - return Completer (tasks).run (timedelta(minutes=5), timedelta(minutes=4), timedelta(seconds=10)) + return Completer (tasks, message='check_initscripts').run (timedelta(minutes=5), timedelta(minutes=4), timedelta(seconds=10)) def check_initscripts(self): "check that the initscripts have triggered" @@ -1351,7 +1354,7 @@ class TestPlc: period = timedelta (seconds=period_seconds) tasks = [ CompleterTaskSystemSlice (test_node, self.options.dry_run) \ for test_node in self.all_nodes() ] - return Completer (tasks) . run (timeout, silent, period) + return Completer (tasks, message='_check_system_slice') . run (timeout, silent, period) def plcsh_stress_test (self): "runs PLCAPI stress test, that checks Add/Update/Delete on all types - preserves contents" diff --git a/system/TestSlice.py b/system/TestSlice.py index 0043d4c..f7e406b 100644 --- a/system/TestSlice.py +++ b/system/TestSlice.py @@ -10,7 +10,7 @@ from TestKey import TestKey from TestUser import TestUser from TestNode import TestNode, CompleterTaskNodeSsh from TestSsh import TestSsh -from Completer import Completer, CompleterTask +from Completer import CompleterTask class CompleterTaskSliceSsh (CompleterTask): @@ -182,7 +182,6 @@ class TestSlice: tasks.append( CompleterTaskSliceSsh(self.test_plc,node_spec['node_fields']['hostname'], slicename,private_key,command,expected,dry_run)) return tasks -# return Completer (tasks).run (timeout, graceout, period) def ssh_slice_basics (self, options, *args, **kwds): "the slice is expected to be UP and we just check a few simple sanity commands, including 'ps' to check for /proc" diff --git a/system/TestSliceSfa.py b/system/TestSliceSfa.py index eba256d..341f518 100644 --- a/system/TestSliceSfa.py +++ b/system/TestSliceSfa.py @@ -200,4 +200,4 @@ class TestSliceSfa: (site_spec,node_spec) = self.test_plc.locate_node(nodename) tasks.append( CompleterTaskSliceSsh(self.test_plc,node_spec['node_fields']['hostname'], slicename,private_key,command,expected=True,dry_run=dry_run)) - return Completer (tasks).run (timeout, graceout, period) + return Completer (tasks, message='ssh_slice_sfa').run (timeout, graceout, period)