1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19 """
20 Contains the base class used to perform the execution and audit trail reporting of a set of tests.
21
22 Test selection is by default performed through the pysys.py launch script, which locates and
23 creates a set of class instances representing the tests to be executed. These are passed to the
24 base runner as a list of object references, so that the base runner can then iterate through the
25 list to perform the test execution. For more information see the L{pysys.baserunner.BaseRunner}
26 API documentation.
27
28 """
29 import os, os.path, sys, stat, re, traceback, time, math, logging, string, thread, threading, imp, textwrap
30
31 from pysys import log, ThreadedFileHandler
32 from pysys.constants import *
33 from pysys.exceptions import *
34 from pysys.utils.threadpool import *
35 from pysys.utils.loader import import_module
36 from pysys.utils.filecopy import filecopy
37 from pysys.utils.filegrep import filegrep
38 from pysys.utils.filediff import filediff
39 from pysys.utils.filegrep import orderedgrep
40 from pysys.utils.linecount import linecount
41 from pysys.process.helper import ProcessWrapper
42 from pysys.basetest import BaseTest
43 from pysys.process.user import ProcessUser
44
45 global_lock = threading.Lock()
46
47 N_CPUS = 1
48 try:
49
50 import multiprocessing
51 N_CPUS = multiprocessing.cpu_count()
52 except ImportError:
53 pass
54
56 """The base class for executing a set of PySys testcases.
57
58 BaseRunner is the parent class for running a set of PySys system testcases. The runner is instantiated
59 with a list of L{pysys.xml.descriptor.XMLDescriptorContainer} objects detailing the set of testcases to be run.
60 The runner iterates through the descriptor list and for each entry imports the L{pysys.basetest.BaseTest}
61 subclass for the testcase, creates an instance of the test class and then calls the setup, execute, validate
62 and cleanup methods of the test class instance. The runner is responsible for ensuring the output
63 subdirectory of each testcase is purged prior to test execution to remove stale output from a previous run,
64 detects any core files produced during execution of a testcase from processes started via the L{pysys.process}
65 module, and performs audit trail logging of the test results on completion of running a set of testcases.
66
67 The base runner contains the hook functions L{setup}, L{testComplete}, L{cycleComplete} and L{cleanup} to
68 allow a subclass to perform custom operations prior to the execution of a set of testcases, between the
69 execution of each testcase in a set, between each cycle of execution of a set of testcases, and on completion
70 of all testcases respectively. Subclasses are typically used should some global conditions need to be setup
71 prior to the set of testcasess being run (i.e. load data into a shared database, start an external process
72 etc), and subsequently cleaned up after test execution.
73
74 @ivar mode: The user defined modes to run the tests within
75 @type mode: string
76 @ivar outsubdir: The directory name for the output subdirectory
77 @type outsubdir: string
78 @ivar log: Reference to the logger instance of this class
79 @type log: logging.Logger
80 @ivar project: Reference to the project details as set on the module load of the launching executable
81 @type project: L{Project}
82
83 """
84
85 - def __init__(self, record, purge, cycle, mode, threads, outsubdir, descriptors, xargs):
86 """Create an instance of the BaseRunner class.
87
88 @param record: Indicates if the test results should be recorded
89 @param purge: Indicates if the output subdirectory should be purged on C{PASSED} result
90 @param cycle: The number of times to execute the set of requested testcases
91 @param mode: The user defined mode to run the testcases in
92 @param threads: The number of worker threads to execute the requested testcases
93 @param outsubdir: The name of the output subdirectory
94 @param descriptors: List of XML descriptor containers detailing the set of testcases to be run
95 @param xargs: The dictionary of additional arguments to be set as data attributes to the class
96
97 """
98 ProcessUser.__init__(self)
99 self.record = record
100 self.purge = purge
101 self.cycle = cycle
102 self.mode = mode
103 self.threads = threads
104 self.outsubdir = outsubdir
105 self.descriptors = descriptors
106 self.xargs = xargs
107 self.validateOnly = False
108 self.setKeywordArgs(xargs)
109
110 if self.threads == 0:
111 self.threads = N_CPUS
112
113 self.writers = []
114 for classname, module, filename, properties in PROJECT.writers:
115 module = import_module(module, sys.path)
116 writer = getattr(module, classname)(filename)
117 for key in properties.keys(): setattr(writer, key, properties[key])
118 self.writers.append(writer)
119
120 self.duration = 0
121 self.results = {}
122 self.resultsPointer = 0
123 self.resultsQueue = []
124
125
127 """Set the xargs as data attributes of the class.
128
129 Values in the xargs dictionary are set as data attributes using the builtin C{setattr()} method.
130 Thus an xargs dictionary of the form C{{'foo': 'bar'}} will result in a data attribute of the
131 form C{self.foo} with C{value bar}.
132
133 @param xargs: A dictionary of the user defined extra arguments
134
135 """
136 for key in xargs.keys():
137 setattr(self, key, xargs[key])
138
139
140
141
143 """Setup method which may optionally be overridden to perform custom setup operations prior to execution of a set of testcases.
144
145 """
146 pass
147
148
150 """Test complete method which performs completion actions after execution of a testcase.
151
152 The testComplete method performs purging of the output subdirectory of a testcase on completion
153 of the test execution. Purging involves removing all files with a zero file length in order to
154 only include files with content of interest. Should C{self.purge} be set, the purging will remove
155 all files (excluding the run.log) on a C{PASSED} outcome of the testcase in order to reduce the
156 on-disk memory footprint when running a large number of tests. Should a custom testComplete for
157 a subclass be required, the BaseRunner testComplete method should first be called.
158
159 @param testObj: Reference to the L{pysys.basetest.BaseTest} instance of the test just completed
160 @param dir: The directory to perform the purge on
161
162 """
163 if self.purge:
164 removeNonZero = True
165 for outcome in testObj.outcome:
166 if outcome != PASSED:
167 removeNonZero = False
168 break
169 else:
170 removeNonZero = False
171
172 try:
173 for file in os.listdir(dir):
174 path = "%s/%s" % (dir, file)
175 if PLATFORM in ['sunos', 'linux']:
176 size = os.lstat(path)[stat.ST_SIZE]
177 else:
178 size = os.stat(path)[stat.ST_SIZE]
179
180 if (size == 0) or (removeNonZero and 'run.log' not in file and self.isPurgableFile(path)):
181 count = 0
182 while count < 3:
183 try:
184 os.remove(path)
185 break
186 except:
187 time.sleep(0.1)
188 count = count + 1
189
190 except OSError as ex:
191 log.warning("Caught OSError while cleaning output directory:")
192 log.warning(ex)
193 log.warning("Output directory may not be completely clean")
194
195
197 """
198 This method is called by testComplete to provide runners with the
199 ability to veto deletion of non-empty files that should always be left
200 in a test's output directory even when the test has passed,
201 by returning False from this method. For example this could be used to
202 avoid deleting code coverage files.
203
204 By default this will return True.
205
206 @param path: The absolute path of the file to be purged
207 """
208 return True
209
210
212 """Cycle complete method which may optionally be overridden to perform custom operations between the repeated execution of a set of testcases.
213
214 """
215 pass
216
217
218
219 - def start(self, printSummary=True):
220 """Start the execution of a set of testcases, returning a dictionary of the testcase outcomes.
221
222 The start method is the main method for executing the set of requested testcases. The set of testcases
223 are executed a number of times determined by the C{self.cycle} attribute. When executing a testcase
224 all output from the execution is saved in the testcase output subdirectory; should C{self.cycle} be
225 set to more than 1, the output subdirectory is further split into cycle[n] directories to sandbox the
226 output from each iteration.
227
228 @param printSummary: Indicates if the test results should be reported on test completion
229
230 """
231
232 self.setup()
233
234
235 if self.record:
236 for writer in self.writers:
237 try: writer.setup(numTests=self.cycle * len(self.descriptors), xargs=self.xargs)
238 except: log.warn("caught %s: %s", sys.exc_info()[0], sys.exc_info()[1], exc_info=1)
239
240
241 if self.threads > 1: threadPool = ThreadPool(self.threads)
242
243
244 self.startTime = time.time()
245 for cycle in range(self.cycle):
246
247 try:
248 self.resultsPointer = 0
249 self.resultsQueue = []
250 self.results[cycle] = {}
251 for outcome in PRECEDENT: self.results[cycle][outcome] = []
252
253 counter = 0
254 for descriptor in self.descriptors:
255 self.resultsQueue.append(None)
256 container = TestContainer(counter, descriptor, cycle, self)
257 if self.threads > 1:
258 request = WorkRequest(container, callback=self.containerCallback, exc_callback=self.containerExceptionCallback)
259 threadPool.putRequest(request)
260 else:
261 self.containerCallback(thread.get_ident(), container())
262 counter = counter + 1
263 except KeyboardInterrupt:
264 log.info("test interrupt from keyboard")
265 self.handleKbrdInt()
266
267
268 if self.threads > 1:
269 try:
270 threadPool.wait()
271 except KeyboardInterrupt:
272 log.info("test interrupt from keyboard - joining threads ... ")
273 threadPool.dismissWorkers(self.threads, True)
274 self.handleKbrdInt(prompt=False)
275
276
277 try:
278 self.cycleComplete()
279 except KeyboardInterrupt:
280 log.info("test interrupt from keyboard")
281 self.handleKbrdInt()
282 except:
283 log.warn("caught %s: %s", sys.exc_info()[0], sys.exc_info()[1], exc_info=1)
284
285
286 if self.record:
287 for writer in self.writers:
288 try: writer.cleanup()
289 except: log.warn("caught %s: %s", sys.exc_info()[0], sys.exc_info()[1], exc_info=1)
290
291
292 if printSummary: self.printSummary()
293
294
295 self.cleanup()
296
297
298 return self.results
299
300
302 """Print the output summary at the completion of a test run.
303
304 """
305 log.critical("")
306 if self.threads > 1:
307 log.critical("Test duration (absolute): %.2f (secs)", time.time() - self.startTime)
308 log.critical("Test duration (additive): %.2f (secs)", self.duration)
309 else:
310 log.critical("Test duration: %.2f (secs)", time.time() - self.startTime)
311 log.critical("")
312 log.critical("Summary of non passes: ")
313 fails = 0
314 for cycle in self.results.keys():
315 for outcome in self.results[cycle].keys():
316 if outcome in FAILS : fails = fails + len(self.results[cycle][outcome])
317 if fails == 0:
318 log.critical(" THERE WERE NO NON PASSES")
319 else:
320 if len(self.results) == 1:
321 for outcome in FAILS:
322 for id in self.results[0][outcome]: log.critical(" %s: %s ", LOOKUP[outcome], id)
323 else:
324 for key in self.results.keys():
325 for outcome in FAILS:
326 for id in self.results[key][outcome]: log.critical(" [CYCLE %d] %s: %s ", key+1, LOOKUP[outcome], id)
327
328
330 """Callback method on completion of running a test.
331
332 @param container: A reference to the container object that ran the test
333
334 Called on completion of running a testcase, either directly by the BaseRunner class (or
335 a sub-class thereof), or from the ThreadPool when running with more than one worker thread.
336 The method is responsible for calling of the testComplete() method of the runner, recording
337 of the test result to the result writers, and for deletion of the test container object.
338
339 """
340 self.resultsQueue[container.counter] = container
341 if self.threads > 1: self.log.info("[%s] Queueing result for test %s" % (thread, container.descriptor.id))
342
343 spacer = True
344 for i in range(self.resultsPointer, len(self.resultsQueue)):
345 if self.resultsQueue[i] is None: break
346
347 if self.threads > 1:
348 if spacer: self.log.info(""); spacer = False
349 try:
350 for line in self.resultsQueue[i].testFileHandler.getBuffer(): self.log.info(line)
351 except:
352 pass
353 if stdoutHandler.level >= logging.WARN:
354 log.critical("%s: %s (%s)", LOOKUP[self.resultsQueue[i].testObj.getOutcome()], self.resultsQueue[i].descriptor.id, self.resultsQueue[i].descriptor.title)
355
356
357 self.testComplete(self.resultsQueue[i].testObj, self.resultsQueue[i].outsubdir)
358
359
360 if self.record:
361 for writer in self.writers:
362 try: writer.processResult(self.resultsQueue[i].testObj, cycle=self.resultsQueue[i].cycle,
363 testStart=self.resultsQueue[i].testStart, testTime=self.resultsQueue[i].testTime)
364 except: log.warn("caught %s: %s", sys.exc_info()[0], sys.exc_info()[1], exc_info=1)
365
366
367 if self.resultsQueue[i].kbrdInt == True: self.handleKbrdInt()
368
369
370 self.duration = self.duration + self.resultsQueue[i].testTime
371 self.results[self.resultsQueue[i].cycle][self.resultsQueue[i].testObj.getOutcome()].append(self.resultsQueue[i].descriptor.id)
372
373
374 self.resultsQueue[i] = None
375 self.resultsPointer = self.resultsPointer + 1
376
377
379 """Callback method for unhandled exceptions thrown when running a test.
380
381 @param exc_info: The tuple of values as created from sys.exc_info()
382
383 """
384 log.warn("caught %s: %s", exc_info[0], exc_info[1], exc_info=exc_info)
385
386
388 """Handle a keyboard exception caught during running of a set of testcases.
389
390 """
391 try:
392 if not prompt:
393 print "Keyboard interrupt detected, exiting ... "
394 self.printSummary()
395 self.cycleComplete()
396 self.cleanup()
397 sys.exit(1)
398
399 while 1:
400 print ""
401 print "Keyboard interrupt detected, continue running tests? [yes|no] ... ",
402 line = sys.stdin.readline().strip()
403 if line == "y" or line == "yes":
404 break
405 elif line == "n" or line == "no":
406 self.printSummary()
407 self.cycleComplete()
408 self.cleanup()
409 sys.exit(1)
410 except KeyboardInterrupt:
411 self.handleKbrdInt(prompt)
412
413
415 """Class used for co-ordinating the execution of a single test case.
416
417 """
418
419 - def __init__ (self, counter, descriptor, cycle, runner):
420 """Create an instance of the TestContainer class.
421
422 @param descriptor: A reference to the testcase descriptor
423 @param cycle: The cycle number of the test
424 @param runner: A reference to the runner that created this class
425
426 """
427 self.counter = counter
428 self.descriptor = descriptor
429 self.cycle = cycle
430 self.runner = runner
431 self.outsubdir = ""
432 self.testObj = None
433 self.testStart = None
434 self.testTime = None
435 self.testBuffer = []
436 self.testFileHandler = None
437 self.kbrdInt = False
438
439
441 """Over-ridden call builtin to allow the class instance to be called directly.
442
443 """
444 exc_info = []
445 self.testStart = time.time()
446 try:
447
448 if os.path.isabs(self.runner.outsubdir):
449 self.outsubdir = os.path.join(self.runner.outsubdir, self.descriptor.id)
450 else:
451 self.outsubdir = os.path.join(self.descriptor.output, self.runner.outsubdir)
452
453 if not os.path.exists(self.outsubdir):
454 os.makedirs(self.outsubdir)
455
456 if self.cycle == 0 and not self.runner.validateOnly:
457 self.purgeDirectory(self.outsubdir)
458
459 if self.runner.cycle > 1:
460 self.outsubdir = os.path.join(self.outsubdir, 'cycle%d' % (self.cycle+1))
461 os.makedirs(self.outsubdir)
462
463
464 self.testFileHandler = ThreadedFileHandler(os.path.join(self.outsubdir, 'run.log'))
465 self.testFileHandler.setFormatter(PROJECT.formatters.runlog)
466 self.testFileHandler.setLevel(logging.INFO)
467 if stdoutHandler.level == logging.DEBUG: self.testFileHandler.setLevel(logging.DEBUG)
468 log.addHandler(self.testFileHandler)
469 log.info(62*"=")
470 title = textwrap.wrap(self.descriptor.title.replace('\n','').strip(), 56)
471 log.info("%s%s"%("Id : ", self.descriptor.id))
472 if self.runner.cycle > 1:
473 log.info("Cycle: %d", self.cycle+1)
474 if len(title)>0: log.info("%s%s"%("Title: ", title[0]))
475 for l in title[1:]: log.info("%s%s"%(" ", l))
476 log.info(62*"=")
477 except KeyboardInterrupt:
478 self.kbrdInt = True
479
480 except:
481 exc_info.append(sys.exc_info())
482
483
484 global_lock.acquire()
485 try:
486 module = import_module(os.path.basename(self.descriptor.module), [os.path.dirname(self.descriptor.module)], True)
487 self.testObj = getattr(module, self.descriptor.classname)(self.descriptor, self.outsubdir, self.runner)
488
489 except KeyboardInterrupt:
490 self.kbrdInt = True
491
492 except:
493 exc_info.append(sys.exc_info())
494 self.testObj = BaseTest(self.descriptor, self.outsubdir, self.runner)
495 global_lock.release()
496
497
498 try:
499 if self.descriptor.state != 'runnable':
500 self.testObj.addOutcome(SKIPPED, 'Not runnable', abortOnError=False)
501
502 elif self.runner.mode and self.runner.mode not in self.descriptor.modes:
503 self.testObj.addOutcome(SKIPPED, "Unable to run test in %s mode"%self.runner.mode, abortOnError=False)
504
505 elif len(exc_info) > 0:
506 self.testObj.addOutcome(BLOCKED, 'Failed to set up test', abortOnError=False)
507 for info in exc_info:
508 log.warn("caught %s while setting up test %s: %s", info[0], self.descriptor.id, info[1], exc_info=info)
509
510 elif self.kbrdInt:
511 log.warn("test interrupt from keyboard")
512 self.testObj.addOutcome(BLOCKED, 'Test interrupt from keyboard', abortOnError=False)
513
514 else:
515 try:
516 if not self.runner.validateOnly:
517 self.testObj.setup()
518 self.testObj.execute()
519 self.testObj.validate()
520 except AbortExecution, e:
521 del self.testObj.outcome[:]
522 self.testObj.addOutcome(e.outcome, e.value, abortOnError=False, callRecord=e.callRecord)
523 log.info('Aborting test due to abortOnError set to true ...')
524
525 if self.detectCore(self.outsubdir):
526 self.testObj.addOutcome(DUMPEDCORE, 'Core detected in output subdirectory', abortOnError=False)
527
528 except KeyboardInterrupt:
529 self.kbrdInt = True
530 self.testObj.addOutcome(BLOCKED, 'Test interrupt from keyboard', abortOnError=False)
531
532 except:
533 log.warn("caught %s: %s", sys.exc_info()[0], sys.exc_info()[1], exc_info=1)
534 self.testObj.addOutcome(BLOCKED, '%s (%s)'%(sys.exc_info()[1], sys.exc_info()[0]), abortOnError=False)
535
536
537 try:
538 self.testObj.cleanup()
539
540 except KeyboardInterrupt:
541 self.kbrdInt = True
542 self.testObj.addOutcome(BLOCKED, 'Test interrupt from keyboard', abortOnError=False)
543
544
545 try:
546 self.testTime = math.floor(100*(time.time() - self.testStart))/100.0
547 log.info("")
548 log.info("Test duration: %.2f secs", self.testTime)
549 log.info("Test final outcome: %s", LOOKUP[self.testObj.getOutcome()])
550 if self.testObj.getOutcomeReason() and self.testObj.getOutcome() != PASSED:
551 log.info("Test failure reason: %s", self.testObj.getOutcomeReason())
552 log.info("")
553
554 self.testFileHandler.close()
555 log.removeHandler(self.testFileHandler)
556 except:
557 pass
558
559
560 return self
561
562
563
565 """Recursively purge a directory removing all files and sub-directories.
566
567 @param dir: The top level directory to be purged
568 @param delTop: Indicates if the top level directory should also be deleted
569
570 """
571 try:
572 for file in os.listdir(dir):
573 path = os.path.join(dir, file)
574 if PLATFORM in ['sunos', 'linux']:
575 mode = os.lstat(path)[stat.ST_MODE]
576 else:
577 mode = os.stat(path)[stat.ST_MODE]
578
579 if stat.S_ISLNK(mode):
580 os.unlink(path)
581 if stat.S_ISREG(mode):
582 os.remove(path)
583 elif stat.S_ISDIR(mode):
584 self.purgeDirectory(path, delTop=True)
585 if delTop: os.rmdir(dir)
586
587 except OSError as ex:
588 log.warning("Caught OSError in purgeDirectory():")
589 log.warning(ex)
590 log.warning("Directory %s may not be completely purged" % dir)
591
592
594 """Detect any core files in a directory (unix systems only), returning C{True} if a core is present.
595
596 @param dir: The directory to search for core files
597 @return: C{True} if a core detected, None if no core detected
598 @rtype: integer
599 """
600 try:
601 for file in os.listdir(dir):
602 path = os.path.join(dir, file)
603 mode = os.stat(path)[stat.ST_MODE]
604 if stat.S_ISREG(mode):
605 if re.search('^core', file): return True
606
607 except OSError as ex:
608 log.warning("Caught OSError in detectCore():")
609 log.warning(ex)
610