VirtualBox

source: vbox/trunk/src/VBox/ValidationKit/testdriver/reporter.py@ 70571

Last change on this file since 70571 was 70571, checked in by vboxsync, 7 years ago

testdriver/reporter.py: Python 3 adjustments.
  • Property svn:eol-style set to native
  • Property svn:keywords set to Author Date Id Revision
File size: 59.9 KB
Line 
1# -*- coding: utf-8 -*-
2# $Id: reporter.py 70571 2018-01-13 00:04:15Z vboxsync $
3# pylint: disable=C0302
4
5"""
6Testdriver reporter module.
7"""
8
9from __future__ import print_function;
10
11__copyright__ = \
12"""
13Copyright (C) 2010-2017 Oracle Corporation
14
15This file is part of VirtualBox Open Source Edition (OSE), as
16available from http://www.215389.xyz. This file is free software;
17you can redistribute it and/or modify it under the terms of the GNU
18General Public License (GPL) as published by the Free Software
19Foundation, in version 2 as it comes in the "COPYING" file of the
20VirtualBox OSE distribution. VirtualBox OSE is distributed in the
21hope that it will be useful, but WITHOUT ANY WARRANTY of any kind.
22
23The contents of this file may alternatively be used under the terms
24of the Common Development and Distribution License Version 1.0
25(CDDL) only, as it comes in the "COPYING.CDDL" file of the
26VirtualBox OSE distribution, in which case the provisions of the
27CDDL are applicable instead of those of the GPL.
28
29You may elect to license modified versions of this file under the
30terms and conditions of either the GPL or the CDDL or both.
31"""
32__version__ = "$Revision: 70571 $"
33
34
35# Standard Python imports.
36import array
37import datetime
38import errno
39import gc
40import os
41import os.path
42import sys
43import time
44import threading
45import traceback
46
47# Validation Kit imports.
48from common import utils;
49
50## test reporter instance
51g_oReporter = None; # type: ReporterBase
52g_sReporterName = None;
53
54
55class ReporterLock(object):
56 """
57 Work around problem with garbage collection triggering __del__ method with
58 logging while inside the logger lock and causing a deadlock.
59 """
60
61 def __init__(self, sName):
62 self.sName = sName;
63 self.oLock = threading.RLock();
64 self.oOwner = None;
65 self.cRecursion = 0;
66 self.fRestoreGC = False;
67
68 def acquire(self):
69 """ Acquire the lock. """
70 oSelf = threading.current_thread();
71
72 # Take the lock.
73 if not self.oLock.acquire():
74 return False;
75
76 self.oOwner = oSelf;
77 self.cRecursion += 1;
78
79 # Disable GC to avoid __del__ w/ log statement randomly reenter the logger.
80 if self.cRecursion == 1:
81 self.fRestoreGC = gc.isenabled();
82 if self.fRestoreGC:
83 gc.disable();
84
85 return True;
86
87 def release(self):
88 """ Release the lock. """
89 oSelf = threading.current_thread();
90
91 # Check the ownership.
92 if oSelf != self.oOwner:
93 raise threading.ThreadError();
94
95 # Drop one recursion.
96 self.cRecursion -= 1;
97 if self.cRecursion <= 0:
98
99 # Final recursion. Clear owner and re-enable GC.
100 self.oOwner = None;
101 if self.fRestoreGC:
102 self.fRestoreGC = False;
103 gc.enable();
104
105 self.oLock.release();
106
107## Reporter lock.
108g_oLock = ReporterLock('reporter');
109
110
111
112class PythonLoggingStream(object):
113 """
114 Python logging => testdriver/reporter.py stream.
115 """
116
117 def write(self, sText):
118 """Writes python log message to our stream."""
119 if g_oReporter != None:
120 sText = sText.rstrip("\r\n");
121 #g_oReporter.log(0, 'python: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
122 return True;
123
124 def flush(self):
125 """Flushes the stream."""
126 return True;
127
128
129class ReporterBase(object):
130 """
131 Base class for the reporters.
132 """
133
134 def __init__(self):
135 self.iVerbose = 1;
136 self.iDebug = 0;
137 self.cErrors = 0;
138 self.fTimedOut = False; # Once set, it trickles all the way up.
139 self.atTests = [];
140 self.sName = os.path.splitext(os.path.basename(sys.argv[0]))[0];
141
142 # Hook into the python logging.
143 import logging;
144 logging.basicConfig(stream = PythonLoggingStream(),
145 level = logging.DEBUG,
146 format = '%(name)-12s %(levelname)-8s %(message)s');
147 #
148 # Introspection and configuration.
149 #
150
151 def isLocal(self):
152 """Is this a local reporter?"""
153 return False;
154
155 def incVerbosity(self):
156 """Increases the verbosity level."""
157 self.iVerbose += 1;
158
159 def incDebug(self):
160 """Increases the debug level."""
161 self.iDebug += 1;
162
163 def appendToProcessName(self, sAppend):
164 """
165 Appends sAppend to the base process name.
166 Returns the new process name.
167 """
168 self.sName = os.path.splitext(os.path.basename(sys.argv[0]))[0] + sAppend;
169 return self.sName;
170
171
172 #
173 # Generic logging.
174 #
175
176 def log(self, iLevel, sText, sCaller, sTsPrf):
177 """
178 Writes the specfied text to the log if iLevel is less or requal
179 to iVerbose.
180 """
181 _ = iLevel; _ = sText; _ = sCaller; _ = sTsPrf;
182 return 0;
183
184 #
185 # XML output from the reporter.
186 #
187
188 def _xmlEscAttr(self, sValue):
189 """Escapes an XML attribute value."""
190 sValue = sValue.replace('&', '&amp;');
191 sValue = sValue.replace('<', '&lt;');
192 sValue = sValue.replace('>', '&gt;');
193 #sValue = sValue.replace('\'', '&apos;');
194 sValue = sValue.replace('"', '&quot;');
195 sValue = sValue.replace('\n', '&#xA');
196 sValue = sValue.replace('\r', '&#xD');
197 return sValue;
198
199 def _xmlWrite(self, asText, fIndent = True):
200 """XML output function for the reporter."""
201 _ = asText; _ = fIndent;
202 return None;
203
204 def xmlFlush(self, fRetry = False, fForce = False):
205 """Flushes XML output if buffered."""
206 _ = fRetry; _ = fForce;
207 return None;
208
209 #
210 # XML output from child.
211 #
212
213 def subXmlStart(self, oFileWrapper):
214 """Called by the file wrapper when the first bytes are written to the test pipe."""
215 _ = oFileWrapper;
216 return None;
217
218 def subXmlWrite(self, oFileWrapper, sRawXml, sCaller):
219 """Called by the file wrapper write method for test pipes."""
220 return self.log(0, 'raw xml%s: %s' % (oFileWrapper.sPrefix, sRawXml), sCaller, utils.getTimePrefix());
221
222 def subXmlEnd(self, oFileWrapper):
223 """Called by the file wrapper __del__ method for test pipes."""
224 _ = oFileWrapper;
225 return None;
226
227 #
228 # File output.
229 #
230
231 def addLogFile(self, oSrcFile, sSrcFilename, sAltName, sDescription, sKind, sCaller, sTsPrf):
232 """
233 Adds the file to the report.
234 Returns True on success, False on failure.
235 """
236 _ = oSrcFile; _ = sSrcFilename; _ = sAltName; _ = sDescription; _ = sKind; _ = sCaller; _ = sTsPrf;
237 return True;
238
239 def addLogString(self, sLog, sLogName, sDescription, sKind, sCaller, sTsPrf):
240 """
241 Adds the file to the report.
242 Returns True on success, False on failure.
243 """
244 _ = sLog; _ = sLogName; _ = sDescription; _ = sKind; _ = sCaller; _ = sTsPrf;
245 return True;
246
247 #
248 # Test reporting
249 #
250
251 def _testGetFullName(self):
252 """
253 Mangles the test names in atTest into a single name to make it easier
254 to spot where we are.
255 """
256 sName = '';
257 for t in self.atTests:
258 if sName != '':
259 sName += ', ';
260 sName += t[0];
261 return sName;
262
263 def testIncErrors(self):
264 """Increates the error count."""
265 self.cErrors += 1;
266 return self.cErrors;
267
268 def testSetTimedOut(self):
269 """Sets time out indicator for the current test and increases the error counter."""
270 self.fTimedOut = True;
271 self.cErrors += 1;
272 return None;
273
274 def testStart(self, sName, sCaller):
275 """ Starts a new test, may be nested. """
276 (sTsPrf, sTsIso) = utils.getTimePrefixAndIsoTimestamp();
277 self._xmlWrite([ '<Test timestamp="%s" name="%s">' % (sTsIso, self._xmlEscAttr(sName),), ]);
278 self.atTests.append((sName, self.cErrors, self.fTimedOut));
279 self.fTimedOut = False;
280 return self.log(1, ' %-50s: TESTING' % (self._testGetFullName()), sCaller, sTsPrf);
281
282 def testValue(self, sName, sValue, sUnit, sCaller):
283 """ Reports a benchmark value or something simiarlly useful. """
284 (sTsPrf, sTsIso) = utils.getTimePrefixAndIsoTimestamp();
285 self._xmlWrite([ '<Value timestamp="%s" name="%s" unit="%s" value="%s"/>'
286 % (sTsIso, self._xmlEscAttr(sName), self._xmlEscAttr(sUnit), self._xmlEscAttr(sValue)), ]);
287 return self.log(0, '** %-48s: %12s %s' % (sName, sValue, sUnit), sCaller, sTsPrf);
288
289 def testFailure(self, sDetails, sCaller):
290 """ Reports a failure. """
291 (sTsPrf, sTsIso) = utils.getTimePrefixAndIsoTimestamp();
292 self.cErrors = self.cErrors + 1;
293 self._xmlWrite([ '<FailureDetails timestamp="%s" text="%s"/>' % (sTsIso, self._xmlEscAttr(sDetails),), ]);
294 return self.log(0, sDetails, sCaller, sTsPrf);
295
296 def testDone(self, fSkipped, sCaller):
297 """
298 Marks the current test as DONE, pops it and maks the next test on the
299 stack current.
300 Returns (name, errors).
301 """
302 (sTsPrf, sTsIso) = utils.getTimePrefixAndIsoTimestamp();
303 sFullName = self._testGetFullName();
304
305 # safe pop
306 if len(self.atTests) <= 0:
307 self.log(0, 'testDone on empty test stack!', sCaller, sTsPrf);
308 return ('internal error', 0);
309 fTimedOut = self.fTimedOut;
310 sName, cErrorsStart, self.fTimedOut = self.atTests.pop();
311
312 # log + xml.
313 cErrors = self.cErrors - cErrorsStart;
314 if cErrors == 0:
315 if fSkipped is not True:
316 self._xmlWrite([ ' <Passed timestamp="%s"/>' % (sTsIso,), '</Test>' ],);
317 self.log(1, '** %-50s: PASSED' % (sFullName,), sCaller, sTsPrf);
318 else:
319 self._xmlWrite([ ' <Skipped timestamp="%s"/>' % (sTsIso,), '</Test>' ]);
320 self.log(1, '** %-50s: SKIPPED' % (sFullName,), sCaller, sTsPrf);
321 elif fTimedOut:
322 self._xmlWrite([ ' <TimedOut timestamp="%s" errors="%d"/>' % (sTsIso, cErrors), '</Test>' ]);
323 self.log(0, '** %-50s: TIMED-OUT - %d errors' % (sFullName, cErrors), sCaller, sTsPrf);
324 else:
325 self._xmlWrite([ ' <Failed timestamp="%s" errors="%d"/>' % (sTsIso, cErrors), '</Test>' ]);
326 self.log(0, '** %-50s: FAILED - %d errors' % (sFullName, cErrors), sCaller, sTsPrf);
327
328 # Flush buffers when reaching the last test.
329 if not self.atTests:
330 self.xmlFlush(fRetry = True);
331
332 return (sName, cErrors);
333
334 def testErrorCount(self):
335 """
336 Returns the number of errors accumulated by the current test.
337 """
338 cTests = len(self.atTests);
339 if cTests <= 0:
340 return self.cErrors;
341 return self.cErrors - self.atTests[cTests - 1][1];
342
343 def testCleanup(self, sCaller):
344 """
345 Closes all open test as failed.
346 Returns True if no open tests, False if there were open tests.
347 """
348 if not self.atTests:
349 return True;
350 for _ in range(len(self.atTests)):
351 self.testFailure('Test not closed by test drver', sCaller)
352 self.testDone(False, sCaller);
353 return False;
354
355 #
356 # Misc.
357 #
358
359 def doPollWork(self, sDebug = None):
360 """
361 Check if any pending stuff expired and needs doing.
362 """
363 _ = sDebug;
364 return None;
365
366
367
368
369class LocalReporter(ReporterBase):
370 """
371 Local reporter instance.
372 """
373
374 def __init__(self):
375 ReporterBase.__init__(self);
376 self.oLogFile = None;
377 self.oXmlFile = None;
378 self.fXmlOk = True;
379 self.iSubXml = 0;
380 self.iOtherFile = 0;
381 self.fnGetIsoTimestamp = utils.getIsoTimestamp; # Hack to get a timestamp in __del__.
382 self.oStdErr = sys.stderr; # Hack for __del__ output.
383
384 #
385 # Figure the main log directory.
386 #
387 try:
388 import user;
389 self.sDefLogDir = os.path.abspath(os.path.join(user.home, "VBoxTestLogs"));
390 except:
391 self.sDefLogDir = os.path.abspath("VBoxTestLogs");
392 try:
393 sLogDir = os.path.abspath(os.environ.get('TESTBOX_REPORTER_LOG_DIR', self.sDefLogDir));
394 if not os.path.isdir(sLogDir):
395 os.makedirs(sLogDir, 0o750);
396 except:
397 sLogDir = self.sDefLogDir;
398 if not os.path.isdir(sLogDir):
399 os.makedirs(sLogDir, 0o750);
400
401 #
402 # Make a subdirectory for this test run.
403 #
404 sTs = datetime.datetime.utcnow().strftime('%Y-%m-%dT%H-%M-%S.log');
405 self.sLogDir = sLogDir = os.path.join(sLogDir, '%s-%s' % (sTs, self.sName));
406 try:
407 os.makedirs(self.sLogDir, 0o750);
408 except:
409 self.sLogDir = '%s-%s' % (self.sLogDir, os.getpid());
410 os.makedirs(self.sLogDir, 0o750);
411
412 #
413 # Open the log file and write a header.
414 #
415 sLogName = os.path.join(self.sLogDir, 'testsuite.log');
416 sTsIso = utils.getIsoTimestamp();
417 if sys.version_info[0] >= 3: # Add 'b' to prevent write taking issue with encode('utf-8') not returning a string.
418 self.oLogFile = utils.openNoInherit(sLogName, "wb");
419 else:
420 self.oLogFile = utils.openNoInherit(sLogName, "w");
421 self.oLogFile.write(('Created log file at %s.\nRunning: %s' % (sTsIso, sys.argv)).encode('utf-8'));
422
423 #
424 # Open the xml log file and write the mandatory introduction.
425 #
426 # Note! This is done here and not in the base class because the remote
427 # logger doesn't really need this. It doesn't need the outer
428 # test wrapper either.
429 #
430 sXmlName = os.path.join(self.sLogDir, 'testsuite.xml');
431 if sys.version_info[0] >= 3: # Add 'b' to prevent write taking issue with encode('utf-8') not returning a string.
432 self.oXmlFile = utils.openNoInherit(sXmlName, "wb");
433 else:
434 self.oXmlFile = utils.openNoInherit(sXmlName, "w");
435 self._xmlWrite([ '<?xml version="1.0" encoding="UTF-8" ?>',
436 '<Test timestamp="%s" name="%s">' % (sTsIso, self._xmlEscAttr(self.sName),), ],
437 fIndent = False);
438
439 def __del__(self):
440 """Ends and completes the log files."""
441 try: sTsIso = self.fnGetIsoTimestamp();
442 except Exception as oXcpt:
443 sTsIso = str(oXcpt);
444
445 if self.oLogFile is not None:
446 try:
447 self.oLogFile.write(('\nThe End %s\n' % (sTsIso,)).encode('utf-8'));
448 self.oLogFile.close();
449 except: pass;
450 self.oLogFile = None;
451
452 if self.oXmlFile is not None:
453 self._closeXml(sTsIso);
454 self.oXmlFile = None;
455
456 def _closeXml(self, sTsIso):
457 """Closes the XML file."""
458 if self.oXmlFile is not None:
459 # pop the test stack
460 while self.atTests:
461 sName, cErrorsStart, self.fTimedOut = self.atTests.pop();
462 self._xmlWrite([ '<End timestamp="%s" errors="%d"/>' % (sTsIso, self.cErrors - cErrorsStart,),
463 '</%s>' % (sName,), ]);
464
465 # The outer one is not on the stack.
466 self._xmlWrite([ ' <End timestamp="%s"/>' % (sTsIso,),
467 '</Test>', ], fIndent = False);
468 try:
469 self.oXmlFile.close();
470 self.oXmlFile = None;
471 except:
472 pass;
473
474 def _xmlWrite(self, asText, fIndent = True):
475 """Writes to the XML file."""
476 for sText in asText:
477 if fIndent:
478 sIndent = ''.ljust((len(self.atTests) + 1) * 2);
479 sText = sIndent + sText;
480 sText += '\n';
481
482 try:
483 self.oXmlFile.write(sText.encode('utf-8'));
484 except:
485 if self.fXmlOk:
486 traceback.print_exc();
487 self.fXmlOk = False;
488 return False;
489 return True;
490
491 #
492 # Overridden methods.
493 #
494
495 def isLocal(self):
496 """Is this a local reporter?"""
497 return True;
498
499 def log(self, iLevel, sText, sCaller, sTsPrf):
500 if iLevel <= self.iVerbose:
501 # format it.
502 if self.iDebug > 0:
503 sLogText = '%s %30s: %s' % (sTsPrf, sCaller, sText);
504 else:
505 sLogText = '%s %s' % (sTsPrf, sText);
506
507 # output it.
508 sAscii = sLogText.encode('ascii', 'replace');
509 if self.iDebug == 0:
510 print('%s: %s' % (self.sName, sAscii), file = self.oStdErr);
511 else:
512 print('%s' % (sAscii), file = self.oStdErr);
513 sLogText += '\n';
514 try:
515 self.oLogFile.write(sLogText.encode('utf-8'));
516 except:
517 pass;
518 return 0;
519
520 def addLogFile(self, oSrcFile, sSrcFilename, sAltName, sDescription, sKind, sCaller, sTsPrf):
521 # Figure the destination filename.
522 iOtherFile = self.iOtherFile;
523 self.iOtherFile += 1;
524 sDstFilename = os.path.join(self.sLogDir, 'other-%d-%s.log' \
525 % (iOtherFile, os.path.splitext(os.path.basename(sSrcFilename))[0]));
526 self.log(0, '** Other log file: %s - %s (%s)' % (sDstFilename, sDescription, sSrcFilename), sCaller, sTsPrf);
527
528 # Open the destination file and copy over the data.
529 fRc = True;
530 try:
531 oDstFile = utils.openNoInherit(sDstFilename, 'w');
532 except Exception as oXcpt:
533 self.log(0, 'error opening %s: %s' % (sDstFilename, oXcpt), sCaller, sTsPrf);
534 else:
535 while True:
536 try:
537 abBuf = oSrcFile.read(65536);
538 except Exception as oXcpt:
539 fRc = False;
540 self.log(0, 'error reading %s: %s' % (sSrcFilename, oXcpt), sCaller, sTsPrf);
541 else:
542 try:
543 oDstFile.write(abBuf);
544 except Exception as oXcpt:
545 fRc = False;
546 self.log(0, 'error writing %s: %s' % (sDstFilename, oXcpt), sCaller, sTsPrf);
547 else:
548 if abBuf:
549 continue;
550 break;
551 oDstFile.close();
552
553 # Leave a mark in the XML log.
554 self._xmlWrite(['<LogFile timestamp="%s" filename="%s" source="%s" kind="%s" ok="%s">%s</LogFile>\n'
555 % (utils.getIsoTimestamp(), self._xmlEscAttr(os.path.basename(sDstFilename)), self._xmlEscAttr(sSrcFilename), \
556 self._xmlEscAttr(sKind), fRc, self._xmlEscAttr(sDescription))] );
557 _ = sAltName;
558 return fRc;
559
560 def addLogString(self, sLog, sLogName, sDescription, sKind, sCaller, sTsPrf):
561 # Figure the destination filename.
562 iOtherFile = self.iOtherFile;
563 self.iOtherFile += 1;
564 sDstFilename = os.path.join(self.sLogDir, 'other-%d-%s.log' \
565 % (iOtherFile, os.path.splitext(os.path.basename(sLogName))[0]));
566 self.log(0, '** Other log file: %s - %s (%s)' % (sDstFilename, sDescription, sLogName), sCaller, sTsPrf);
567
568 # Open the destination file and copy over the data.
569 fRc = True;
570 try:
571 oDstFile = utils.openNoInherit(sDstFilename, 'w');
572 except Exception as oXcpt:
573 self.log(0, 'error opening %s: %s' % (sDstFilename, oXcpt), sCaller, sTsPrf);
574 else:
575 try:
576 oDstFile.write(sLog);
577 except Exception as oXcpt:
578 fRc = False;
579 self.log(0, 'error writing %s: %s' % (sDstFilename, oXcpt), sCaller, sTsPrf);
580
581 oDstFile.close();
582
583 # Leave a mark in the XML log.
584 self._xmlWrite(['<LogFile timestamp="%s" filename="%s" source="%s" kind="%s" ok="%s">%s</LogFile>\n'
585 % (utils.getIsoTimestamp(), self._xmlEscAttr(os.path.basename(sDstFilename)), self._xmlEscAttr(sLogName), \
586 self._xmlEscAttr(sKind), fRc, self._xmlEscAttr(sDescription))] );
587 return fRc;
588
589 def subXmlStart(self, oFileWrapper):
590 # Open a new file and just include it from the main XML.
591 iSubXml = self.iSubXml;
592 self.iSubXml += 1;
593 sSubXmlName = os.path.join(self.sLogDir, 'sub-%d.xml' % (iSubXml,));
594 try:
595 oFileWrapper.oSubXmlFile = utils.openNoInherit(sSubXmlName, "w");
596 except:
597 errorXcpt('open(%s)' % oFileWrapper.oSubXmlName);
598 oFileWrapper.oSubXmlFile = None;
599 else:
600 self._xmlWrite(['<Include timestamp="%s" filename="%s"/>\n'
601 % (utils.getIsoTimestamp(), self._xmlEscAttr(os.path.basename(sSubXmlName)))]);
602 return None;
603
604 def subXmlWrite(self, oFileWrapper, sRawXml, sCaller):
605 if oFileWrapper.oSubXmlFile is not None:
606 try:
607 oFileWrapper.oSubXmlFile.write(sRawXml);
608 except:
609 pass;
610 if sCaller is None: pass; # pychecker - NOREF
611 return None;
612
613 def subXmlEnd(self, oFileWrapper):
614 if oFileWrapper.oSubXmlFile is not None:
615 try:
616 oFileWrapper.oSubXmlFile.close();
617 oFileWrapper.oSubXmlFile = None;
618 except:
619 pass;
620 return None;
621
622
623
624class RemoteReporter(ReporterBase):
625 """
626 Reporter that talks to the test manager server.
627 """
628
629
630 ## The XML sync min time (seconds).
631 kcSecXmlFlushMin = 30;
632 ## The XML sync max time (seconds).
633 kcSecXmlFlushMax = 120;
634 ## The XML sync idle time before flushing (seconds).
635 kcSecXmlFlushIdle = 5;
636 ## The XML sync line count threshold.
637 kcLinesXmlFlush = 512;
638
639 ## The retry timeout.
640 kcSecTestManagerRetryTimeout = 120;
641 ## The request timeout.
642 kcSecTestManagerRequestTimeout = 30;
643
644
645 def __init__(self):
646 ReporterBase.__init__(self);
647 self.sTestManagerUrl = os.environ.get('TESTBOX_MANAGER_URL');
648 self.sTestBoxUuid = os.environ.get('TESTBOX_UUID');
649 self.idTestBox = int(os.environ.get('TESTBOX_ID'));
650 self.idTestSet = int(os.environ.get('TESTBOX_TEST_SET_ID'));
651 self._asXml = [];
652 self._secTsXmlFlush = utils.timestampSecond();
653 self._secTsXmlLast = self._secTsXmlFlush;
654 self._fXmlFlushing = False;
655 self.oOutput = sys.stdout; # Hack for __del__ output.
656 self.fFlushEachLine = True;
657 self.fDebugXml = 'TESTDRIVER_REPORTER_DEBUG_XML' in os.environ;
658
659 # Prepare the TM connecting.
660 from common import constants;
661 if sys.version_info[0] >= 3:
662 import urllib;
663 self._fnUrlEncode = urllib.parse.urlencode; # pylint: disable=no-member
664 self._fnUrlParseQs = urllib.parse.parse_qs; # pylint: disable=no-member
665 self._oParsedTmUrl = urllib.parse.urlparse(self.sTestManagerUrl); # pylint: disable=no-member
666 import http.client as httplib; # pylint: disable=no-name-in-module,import-error
667 else:
668 import urllib;
669 self._fnUrlEncode = urllib.urlencode; # pylint: disable=no-member
670 import urlparse; # pylint: disable=import-error
671 self._fnUrlParseQs = urlparse.parse_qs; # pylint: disable=no-member
672 self._oParsedTmUrl = urlparse.urlparse(self.sTestManagerUrl); # pylint: disable=no-member
673 import httplib; # pylint: disable=no-name-in-module,import-error
674
675 if sys.version_info[0] >= 3 \
676 or (sys.version_info[0] == 2 and sys.version_info[1] >= 6):
677 if self._oParsedTmUrl.scheme == 'https': # pylint: disable=E1101
678 self._fnTmConnect = lambda: httplib.HTTPSConnection(self._oParsedTmUrl.hostname,
679 timeout = self.kcSecTestManagerRequestTimeout);
680 else:
681 self._fnTmConnect = lambda: httplib.HTTPConnection( self._oParsedTmUrl.hostname,
682 timeout = self.kcSecTestManagerRequestTimeout);
683 else:
684 if self._oParsedTmUrl.scheme == 'https': # pylint: disable=E1101
685 self._fnTmConnect = lambda: httplib.HTTPSConnection(self._oParsedTmUrl.hostname);
686 else:
687 self._fnTmConnect = lambda: httplib.HTTPConnection( self._oParsedTmUrl.hostname);
688 self._dHttpHeader = \
689 {
690 'Content-Type': 'application/x-www-form-urlencoded; charset=utf-8',
691 'User-Agent': 'TestDriverReporter/%s.0 (%s, %s)' % (__version__, utils.getHostOs(), utils.getHostArch(),),
692 'Accept': 'text/plain,application/x-www-form-urlencoded',
693 'Accept-Encoding': 'identity',
694 'Cache-Control': 'max-age=0',
695 #'Connection': 'keep-alive',
696 };
697
698 dParams = {
699 constants.tbreq.ALL_PARAM_TESTBOX_UUID: self.sTestBoxUuid,
700 constants.tbreq.ALL_PARAM_TESTBOX_ID: self.idTestBox,
701 constants.tbreq.RESULT_PARAM_TEST_SET_ID: self.idTestSet,
702 };
703 self._sTmServerPath = '/%s/testboxdisp.py?%s' \
704 % ( self._oParsedTmUrl.path.strip('/'), # pylint: disable=E1101
705 self._fnUrlEncode(dParams), );
706
707 def __del__(self):
708 """Flush pending log messages?"""
709 if self._asXml:
710 self._xmlDoFlush(self._asXml, fRetry = True, fDtor = True);
711
712 def _writeOutput(self, sText):
713 """ Does the actual writing and flushing. """
714 if sys.version_info[0] >= 3:
715 print(sText, file = self.oOutput);
716 else:
717 print(sText.encode('ascii', 'replace'), file = self.oOutput);
718 if self.fFlushEachLine: self.oOutput.flush();
719 return None;
720
721 #
722 # Talking to TM.
723 #
724
725 def _processTmStatusResponse(self, oConn, sOperation, fClose = True):
726 """
727 Processes HTTP reponse from the test manager.
728 Returns True, False or None. None should be retried, the others not.
729 May raise exception on HTTP issue (retry ok).
730 """
731 if sys.version_info[0] >= 3: import http.client as httplib; # pylint: disable=no-name-in-module,import-error
732 else: import httplib; # pylint: disable=import-error
733 from common import constants;
734
735 # Read the response and (optionally) close the connection.
736 oResponse = oConn.getresponse();
737 try:
738 sRspBody = oResponse.read();
739 except httplib.IncompleteRead as oXcpt:
740 self._writeOutput('%s: %s: Warning: httplib.IncompleteRead: %s [expected %s, got %s]'
741 % (utils.getTimePrefix(), sOperation, oXcpt, oXcpt.expected, len(oXcpt.partial),));
742 sRspBody = oXcpt.partial;
743 if fClose is True:
744 try: oConn.close();
745 except: pass;
746
747 # Check the content type.
748 sContentType = oResponse.getheader('Content-Type');
749 if sContentType is not None and sContentType == 'application/x-www-form-urlencoded; charset=utf-8':
750
751 # Parse the body and check the RESULT parameter.
752 dResponse = self._fnUrlParseQs(sRspBody, strict_parsing = True);
753 sResult = dResponse.get(constants.tbresp.ALL_PARAM_RESULT, None);
754 if isinstance(sResult, list):
755 sResult = sResult[0] if len(sResult) == 1 else '%d results' % (len(sResult),);
756
757 if sResult is not None:
758 if sResult == constants.tbresp.STATUS_ACK:
759 return True;
760 if sResult == constants.tbresp.STATUS_NACK:
761 self._writeOutput('%s: %s: Failed (%s). (dResponse=%s)'
762 % (utils.getTimePrefix(), sOperation, sResult, dResponse,));
763 return False;
764
765 self._writeOutput('%s: %s: Failed - dResponse=%s' % (utils.getTimePrefix(), sOperation, dResponse,));
766 else:
767 self._writeOutput('%s: %s: Unexpected Content-Type: %s' % (utils.getTimePrefix(), sOperation, sContentType,));
768 self._writeOutput('%s: %s: Body: %s' % (utils.getTimePrefix(), sOperation, sRspBody,));
769 return None;
770
771 def _doUploadFile(self, oSrcFile, sSrcFilename, sDescription, sKind, sMime):
772 """ Uploads the given file to the test manager. """
773
774 # Prepare header and url.
775 dHeader = dict(self._dHttpHeader);
776 dHeader['Content-Type'] = 'application/octet-stream';
777 self._writeOutput('%s: _doUploadFile: sHeader=%s' % (utils.getTimePrefix(), dHeader,));
778 oSrcFile.seek(0, 2);
779 self._writeOutput('%s: _doUploadFile: size=%d' % (utils.getTimePrefix(), oSrcFile.tell(),));
780 oSrcFile.seek(0);
781
782 from common import constants;
783 sUrl = self._sTmServerPath + '&' \
784 + self._fnUrlEncode({ constants.tbreq.UPLOAD_PARAM_NAME: os.path.basename(sSrcFilename),
785 constants.tbreq.UPLOAD_PARAM_DESC: sDescription,
786 constants.tbreq.UPLOAD_PARAM_KIND: sKind,
787 constants.tbreq.UPLOAD_PARAM_MIME: sMime,
788 constants.tbreq.ALL_PARAM_ACTION: constants.tbreq.UPLOAD,
789 });
790
791 # Retry loop.
792 secStart = utils.timestampSecond();
793 while True:
794 try:
795 oConn = self._fnTmConnect();
796 oConn.request('POST', sUrl, oSrcFile.read(), dHeader);
797 fRc = self._processTmStatusResponse(oConn, '_doUploadFile', fClose = True);
798 oConn.close();
799 if fRc is not None:
800 return fRc;
801 except:
802 logXcpt('warning: exception during UPLOAD request');
803
804 if utils.timestampSecond() - secStart >= self.kcSecTestManagerRetryTimeout:
805 self._writeOutput('%s: _doUploadFile: Timed out.' % (utils.getTimePrefix(),));
806 break;
807 try: oSrcFile.seek(0);
808 except:
809 logXcpt();
810 break;
811 self._writeOutput('%s: _doUploadFile: Retrying...' % (utils.getTimePrefix(), ));
812 time.sleep(2);
813
814 return False;
815
816 def _doUploadString(self, sSrc, sSrcName, sDescription, sKind, sMime):
817 """ Uploads the given string as a separate file to the test manager. """
818
819 # Prepare header and url.
820 dHeader = dict(self._dHttpHeader);
821 dHeader['Content-Type'] = 'application/octet-stream';
822 self._writeOutput('%s: _doUploadString: sHeader=%s' % (utils.getTimePrefix(), dHeader,));
823 self._writeOutput('%s: _doUploadString: size=%d' % (utils.getTimePrefix(), sys.getsizeof(sSrc),));
824
825 from common import constants;
826 sUrl = self._sTmServerPath + '&' \
827 + self._fnUrlEncode({ constants.tbreq.UPLOAD_PARAM_NAME: os.path.basename(sSrcName),
828 constants.tbreq.UPLOAD_PARAM_DESC: sDescription,
829 constants.tbreq.UPLOAD_PARAM_KIND: sKind,
830 constants.tbreq.UPLOAD_PARAM_MIME: sMime,
831 constants.tbreq.ALL_PARAM_ACTION: constants.tbreq.UPLOAD,
832 });
833
834 # Retry loop.
835 secStart = utils.timestampSecond();
836 while True:
837 try:
838 oConn = self._fnTmConnect();
839 oConn.request('POST', sUrl, sSrc, dHeader);
840 fRc = self._processTmStatusResponse(oConn, '_doUploadString', fClose = True);
841 oConn.close();
842 if fRc is not None:
843 return fRc;
844 except:
845 logXcpt('warning: exception during UPLOAD request');
846
847 if utils.timestampSecond() - secStart >= self.kcSecTestManagerRetryTimeout:
848 self._writeOutput('%s: _doUploadString: Timed out.' % (utils.getTimePrefix(),));
849 break;
850 self._writeOutput('%s: _doUploadString: Retrying...' % (utils.getTimePrefix(), ));
851 time.sleep(2);
852
853 return False;
854
855 def _xmlDoFlush(self, asXml, fRetry = False, fDtor = False):
856 """
857 The code that does the actual talking to the server.
858 Used by both xmlFlush and __del__.
859 """
860 secStart = utils.timestampSecond();
861 while True:
862 fRc = None;
863 try:
864 # Post.
865 from common import constants;
866 sPostBody = self._fnUrlEncode({constants.tbreq.XML_RESULT_PARAM_BODY: '\n'.join(asXml),});
867 oConn = self._fnTmConnect();
868 oConn.request('POST',
869 self._sTmServerPath + ('&%s=%s' % (constants.tbreq.ALL_PARAM_ACTION, constants.tbreq.XML_RESULTS)),
870 sPostBody,
871 self._dHttpHeader);
872
873 fRc = self._processTmStatusResponse(oConn, '_xmlDoFlush', fClose = True);
874 if fRc is True:
875 if self.fDebugXml:
876 self._writeOutput('_xmlDoFlush:\n%s' % ('\n'.join(asXml),));
877 return (None, False);
878 if fRc is False:
879 self._writeOutput('_xmlDoFlush: Failed - we should abort the test, really.');
880 return (None, True);
881 except Exception as oXcpt:
882 if not fDtor:
883 logXcpt('warning: exception during XML_RESULTS request');
884 else:
885 self._writeOutput('warning: exception during XML_RESULTS request: %s' % (oXcpt,));
886
887 if fRetry is not True \
888 or utils.timestampSecond() - secStart >= self.kcSecTestManagerRetryTimeout:
889 break;
890 time.sleep(2);
891
892 return (asXml, False);
893
894
895 #
896 # Overridden methods.
897 #
898
899 def isLocal(self):
900 return False;
901
902 def log(self, iLevel, sText, sCaller, sTsPrf):
903 if iLevel <= self.iVerbose:
904 if self.iDebug > 0:
905 sLogText = '%s %30s: %s' % (sTsPrf, sCaller, sText);
906 else:
907 sLogText = '%s %s: %s' % (sTsPrf, self.sName, sText);
908 self._writeOutput(sLogText);
909 return 0;
910
911 def addLogFile(self, oSrcFile, sSrcFilename, sAltName, sDescription, sKind, sCaller, sTsPrf):
912 fRc = True;
913 if sKind in [ 'text', 'log', 'process'] \
914 or sKind.startswith('log/') \
915 or sKind.startswith('info/') \
916 or sKind.startswith('process/'):
917 self.log(0, '*** Uploading "%s" - KIND: "%s" - DESC: "%s" ***'
918 % (sSrcFilename, sKind, sDescription), sCaller, sTsPrf);
919 self.xmlFlush();
920 g_oLock.release();
921 try:
922 self._doUploadFile(oSrcFile, sAltName, sDescription, sKind, 'text/plain');
923 finally:
924 g_oLock.acquire();
925 elif sKind.startswith('screenshot/'):
926 self.log(0, '*** Uploading "%s" - KIND: "%s" - DESC: "%s" ***'
927 % (sSrcFilename, sKind, sDescription), sCaller, sTsPrf);
928 self.xmlFlush();
929 g_oLock.release();
930 try:
931 self._doUploadFile(oSrcFile, sAltName, sDescription, sKind, 'image/png');
932 finally:
933 g_oLock.acquire();
934 elif sKind.startswith('misc/'):
935 self.log(0, '*** Uploading "%s" - KIND: "%s" - DESC: "%s" ***'
936 % (sSrcFilename, sKind, sDescription), sCaller, sTsPrf);
937 self.xmlFlush();
938 g_oLock.release();
939 try:
940 self._doUploadFile(oSrcFile, sAltName, sDescription, sKind, 'application/octet-stream');
941 finally:
942 g_oLock.acquire();
943 else:
944 self.log(0, '*** UNKNOWN FILE "%s" - KIND "%s" - DESC "%s" ***'
945 % (sSrcFilename, sKind, sDescription), sCaller, sTsPrf);
946 return fRc;
947
948 def addLogString(self, sLog, sLogName, sDescription, sKind, sCaller, sTsPrf):
949 fRc = True;
950 if sKind in [ 'text', 'log', 'process'] \
951 or sKind.startswith('log/') \
952 or sKind.startswith('info/') \
953 or sKind.startswith('process/'):
954 self.log(0, '*** Uploading "%s" - KIND: "%s" - DESC: "%s" ***'
955 % (sLogName, sKind, sDescription), sCaller, sTsPrf);
956 self.xmlFlush();
957 g_oLock.release();
958 try:
959 self._doUploadString(sLog, sLogName, sDescription, sKind, 'text/plain');
960 finally:
961 g_oLock.acquire();
962 else:
963 self.log(0, '*** UNKNOWN FILE "%s" - KIND "%s" - DESC "%s" ***'
964 % (sLogName, sKind, sDescription), sCaller, sTsPrf);
965 return fRc;
966
967 def xmlFlush(self, fRetry = False, fForce = False):
968 """
969 Flushes the XML back log. Called with the lock held, may leave it
970 while communicating with the server.
971 """
972 if not self._fXmlFlushing:
973 asXml = self._asXml;
974 self._asXml = [];
975 if asXml or fForce is True:
976 self._fXmlFlushing = True;
977
978 g_oLock.release();
979 try:
980 (asXml, fIncErrors) = self._xmlDoFlush(asXml, fRetry = fRetry);
981 finally:
982 g_oLock.acquire();
983
984 if fIncErrors:
985 self.testIncErrors();
986
987 self._fXmlFlushing = False;
988 if asXml is None:
989 self._secTsXmlFlush = utils.timestampSecond();
990 else:
991 self._asXml = asXml + self._asXml;
992 return True;
993
994 self._secTsXmlFlush = utils.timestampSecond();
995 return False;
996
997 def _xmlFlushIfNecessary(self, fPolling = False, sDebug = None):
998 """Flushes the XML back log if necessary."""
999 tsNow = utils.timestampSecond();
1000 cSecs = tsNow - self._secTsXmlFlush;
1001 cSecsLast = tsNow - self._secTsXmlLast;
1002 if fPolling is not True:
1003 self._secTsXmlLast = tsNow;
1004
1005 # Absolute flush thresholds.
1006 if cSecs >= self.kcSecXmlFlushMax:
1007 return self.xmlFlush();
1008 if len(self._asXml) >= self.kcLinesXmlFlush:
1009 return self.xmlFlush();
1010
1011 # Flush if idle long enough.
1012 if cSecs >= self.kcSecXmlFlushMin \
1013 and cSecsLast >= self.kcSecXmlFlushIdle:
1014 return self.xmlFlush();
1015
1016 _ = sDebug;
1017 return False;
1018
1019 def _xmlWrite(self, asText, fIndent = True):
1020 """XML output function for the reporter."""
1021 self._asXml += asText;
1022 self._xmlFlushIfNecessary();
1023 _ = fIndent; # No pretty printing, thank you.
1024 return None;
1025
1026 def subXmlStart(self, oFileWrapper):
1027 oFileWrapper.sXmlBuffer = '';
1028 return None;
1029
1030 def subXmlWrite(self, oFileWrapper, sRawXml, sCaller):
1031 oFileWrapper.sXmlBuffer += sRawXml;
1032 _ = sCaller;
1033 return None;
1034
1035 def subXmlEnd(self, oFileWrapper):
1036 sRawXml = oFileWrapper.sXmlBuffer;
1037 ## @todo should validate the document here and maybe auto terminate things. Adding some hints to have the server do
1038 # this instead.
1039 g_oLock.acquire();
1040 try:
1041 self._asXml += [ '<PushHint testdepth="%d"/>' % (len(self.atTests),),
1042 sRawXml,
1043 '<PopHint testdepth="%d"/>' % (len(self.atTests),),];
1044 self._xmlFlushIfNecessary();
1045 finally:
1046 g_oLock.release();
1047 return None;
1048
1049 def doPollWork(self, sDebug = None):
1050 if self._asXml:
1051 g_oLock.acquire();
1052 try:
1053 self._xmlFlushIfNecessary(fPolling = True, sDebug = sDebug);
1054 finally:
1055 g_oLock.release();
1056 return None;
1057
1058
1059#
1060# Helpers
1061#
1062
1063def logXcptWorker(iLevel, fIncErrors, sPrefix="", sText=None, cFrames=1):
1064 """
1065 Log an exception, optionally with a preceeding message and more than one
1066 call frame.
1067 """
1068 g_oLock.acquire();
1069 try:
1070
1071 if fIncErrors:
1072 g_oReporter.testIncErrors();
1073
1074 ## @todo skip all this if iLevel is too high!
1075
1076 # Try get exception info.
1077 sTsPrf = utils.getTimePrefix();
1078 try:
1079 oType, oValue, oTraceback = sys.exc_info();
1080 except:
1081 oType = oValue = oTraceback = None;
1082 if oType is not None:
1083
1084 # Try format the info
1085 try:
1086 rc = 0;
1087 sCaller = utils.getCallerName(oTraceback.tb_frame);
1088 if sText is not None:
1089 rc = g_oReporter.log(iLevel, "%s%s" % (sPrefix, sText), sCaller, sTsPrf);
1090 asInfo = [];
1091 try:
1092 asInfo = asInfo + traceback.format_exception_only(oType, oValue);
1093 if cFrames is not None and cFrames <= 1:
1094 asInfo = asInfo + traceback.format_tb(oTraceback, 1);
1095 else:
1096 asInfo.append('Traceback:')
1097 asInfo = asInfo + traceback.format_tb(oTraceback, cFrames);
1098 asInfo.append('Stack:')
1099 asInfo = asInfo + traceback.format_stack(oTraceback.tb_frame.f_back, cFrames);
1100 except:
1101 g_oReporter.log(0, '** internal-error: Hit exception #2! %s' % (traceback.format_exc()), sCaller, sTsPrf);
1102
1103 if asInfo:
1104 # Do the logging.
1105 for sItem in asInfo:
1106 asLines = sItem.splitlines();
1107 for sLine in asLines:
1108 rc = g_oReporter.log(iLevel, '%s%s' % (sPrefix, sLine), sCaller, sTsPrf);
1109
1110 else:
1111 g_oReporter.log(iLevel, 'No exception info...', sCaller, sTsPrf);
1112 rc = -3;
1113 except:
1114 g_oReporter.log(0, '** internal-error: Hit exception! %s' % (traceback.format_exc()), None, sTsPrf);
1115 rc = -2;
1116 else:
1117 g_oReporter.log(0, '** internal-error: No exception! %s'
1118 % (utils.getCallerName(iFrame=3)), utils.getCallerName(iFrame=3), sTsPrf);
1119 rc = -1;
1120
1121 finally:
1122 g_oLock.release();
1123 return rc;
1124
1125#
1126# The public Classes
1127#
1128class FileWrapper(object):
1129 """ File like class for TXS EXEC and similar. """
1130 def __init__(self, sPrefix):
1131 self.sPrefix = sPrefix;
1132
1133 def __del__(self):
1134 self.close();
1135
1136 def close(self):
1137 """ file.close """
1138 # Nothing to be done.
1139 return;
1140
1141 def read(self, cb):
1142 """file.read"""
1143 _ = cb;
1144 return "";
1145
1146 def write(self, sText):
1147 """file.write"""
1148 if isinstance(sText, array.array):
1149 try:
1150 sText = sText.tostring();
1151 except:
1152 pass;
1153 g_oLock.acquire();
1154 try:
1155 sTsPrf = utils.getTimePrefix();
1156 sCaller = utils.getCallerName();
1157 asLines = sText.splitlines();
1158 for sLine in asLines:
1159 g_oReporter.log(0, '%s: %s' % (self.sPrefix, sLine), sCaller, sTsPrf);
1160 except:
1161 traceback.print_exc();
1162 finally:
1163 g_oLock.release();
1164 return None;
1165
1166class FileWrapperTestPipe(object):
1167 """ File like class for the test pipe (TXS EXEC and similar). """
1168 def __init__(self):
1169 self.sPrefix = '';
1170 self.fStarted = False;
1171 self.fClosed = False;
1172 self.sTagBuffer = None;
1173
1174 def __del__(self):
1175 self.close();
1176
1177 def close(self):
1178 """ file.close """
1179 if self.fStarted is True and self.fClosed is False:
1180 self.fClosed = True;
1181 try: g_oReporter.subXmlEnd(self);
1182 except:
1183 try: traceback.print_exc();
1184 except: pass;
1185 return True;
1186
1187 def read(self, cb = None):
1188 """file.read"""
1189 _ = cb;
1190 return "";
1191
1192 def write(self, sText):
1193 """file.write"""
1194 # lazy start.
1195 if self.fStarted is not True:
1196 try:
1197 g_oReporter.subXmlStart(self);
1198 except:
1199 traceback.print_exc();
1200 self.fStarted = True;
1201
1202 if isinstance(sText, array.array):
1203 try:
1204 sText = sText.tostring();
1205 except:
1206 pass;
1207 try:
1208 g_oReporter.subXmlWrite(self, sText, utils.getCallerName());
1209 # Parse the supplied text and look for <Failed.../> tags to keep track of the
1210 # error counter. This is only a very lazy aproach.
1211 sText.strip();
1212 idxText = 0;
1213 while sText:
1214 if self.sTagBuffer is None:
1215 # Look for the start of a tag.
1216 idxStart = sText[idxText:].find('<');
1217 if idxStart != -1:
1218 # Look for the end of the tag.
1219 idxEnd = sText[idxStart:].find('>');
1220
1221 # If the end was found inside the current buffer, parse the line,
1222 # else we have to save it for later.
1223 if idxEnd != -1:
1224 idxEnd += idxStart + 1;
1225 self._processXmlElement(sText[idxStart:idxEnd]);
1226 idxText = idxEnd;
1227 else:
1228 self.sTagBuffer = sText[idxStart:];
1229 idxText = len(sText);
1230 else:
1231 idxText = len(sText);
1232 else:
1233 # Search for the end of the tag and parse the whole tag.
1234 idxEnd = sText[idxText:].find('>');
1235 if idxEnd != -1:
1236 idxEnd += idxStart + 1;
1237 self._processXmlElement(self.sTagBuffer + sText[idxText:idxEnd]);
1238 self.sTagBuffer = None;
1239 idxText = idxEnd;
1240 else:
1241 self.sTagBuffer = self.sTagBuffer + sText[idxText:];
1242 idxText = len(sText);
1243
1244 sText = sText[idxText:];
1245 sText = sText.lstrip();
1246 except:
1247 traceback.print_exc();
1248 return None;
1249
1250 def _processXmlElement(self, sElement):
1251 """
1252 Processes a complete XML tag (so far we only search for the Failed to tag
1253 to keep track of the error counter.
1254 """
1255 # Make sure we don't parse any space between < and the element name.
1256 sElement = sElement.strip();
1257
1258 # Find the end of the name
1259 idxEndName = sElement.find(' ');
1260 if idxEndName == -1:
1261 idxEndName = sElement.find('/');
1262 if idxEndName == -1:
1263 idxEndName = sElement.find('>');
1264
1265 if idxEndName != -1:
1266 if sElement[1:idxEndName] == 'Failed':
1267 g_oLock.acquire();
1268 try:
1269 g_oReporter.testIncErrors();
1270 finally:
1271 g_oLock.release();
1272 else:
1273 error('_processXmlElement(%s)' % sElement);
1274
1275
1276#
1277# The public APIs.
1278#
1279
1280def log(sText):
1281 """Writes the specfied text to the log."""
1282 g_oLock.acquire();
1283 try:
1284 rc = g_oReporter.log(1, sText, utils.getCallerName(), utils.getTimePrefix());
1285 except:
1286 rc = -1;
1287 finally:
1288 g_oLock.release();
1289 return rc;
1290
1291def logXcpt(sText=None, cFrames=1):
1292 """
1293 Log an exception, optionally with a preceeding message and more than one
1294 call frame.
1295 """
1296 return logXcptWorker(1, False, "", sText, cFrames);
1297
1298def log2(sText):
1299 """Log level 2: Writes the specfied text to the log."""
1300 g_oLock.acquire();
1301 try:
1302 rc = g_oReporter.log(2, sText, utils.getCallerName(), utils.getTimePrefix());
1303 except:
1304 rc = -1;
1305 finally:
1306 g_oLock.release();
1307 return rc;
1308
1309def log2Xcpt(sText=None, cFrames=1):
1310 """
1311 Log level 2: Log an exception, optionally with a preceeding message and
1312 more than one call frame.
1313 """
1314 return logXcptWorker(2, False, "", sText, cFrames);
1315
1316def maybeErr(fIsError, sText):
1317 """ Maybe error or maybe normal log entry. """
1318 if fIsError is True:
1319 return error(sText);
1320 return log(sText);
1321
1322def maybeErrXcpt(fIsError, sText=None, cFrames=1):
1323 """ Maybe error or maybe normal log exception entry. """
1324 if fIsError is True:
1325 return errorXcpt(sText, cFrames);
1326 return logXcpt(sText, cFrames);
1327
1328def maybeLog(fIsNotError, sText):
1329 """ Maybe error or maybe normal log entry. """
1330 if fIsNotError is not True:
1331 return error(sText);
1332 return log(sText);
1333
1334def maybeLogXcpt(fIsNotError, sText=None, cFrames=1):
1335 """ Maybe error or maybe normal log exception entry. """
1336 if fIsNotError is not True:
1337 return errorXcpt(sText, cFrames);
1338 return logXcpt(sText, cFrames);
1339
1340def error(sText):
1341 """
1342 Writes the specfied error message to the log.
1343
1344 This will add an error to the current test.
1345
1346 Always returns False for the convenience of methods returning boolean
1347 success indicators.
1348 """
1349 g_oLock.acquire();
1350 try:
1351 g_oReporter.testIncErrors();
1352 g_oReporter.log(0, '** error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1353 except:
1354 pass;
1355 finally:
1356 g_oLock.release();
1357 return False;
1358
1359def errorXcpt(sText=None, cFrames=1):
1360 """
1361 Log an error caused by an exception. If sText is given, it will preceed
1362 the exception information. cFrames can be used to display more stack.
1363
1364 This will add an error to the current test.
1365
1366 Always returns False for the convenience of methods returning boolean
1367 success indicators.
1368 """
1369 logXcptWorker(0, True, '** error: ', sText, cFrames);
1370 return False;
1371
1372def errorTimeout(sText):
1373 """
1374 Flags the current test as having timed out and writes the specified message to the log.
1375
1376 This will add an error to the current test.
1377
1378 Always returns False for the convenience of methods returning boolean
1379 success indicators.
1380 """
1381 g_oLock.acquire();
1382 try:
1383 g_oReporter.testSetTimedOut();
1384 g_oReporter.log(0, '** timeout-error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1385 except:
1386 pass;
1387 finally:
1388 g_oLock.release();
1389 return False;
1390
1391def fatal(sText):
1392 """
1393 Writes a fatal error to the log.
1394
1395 This will add an error to the current test.
1396
1397 Always returns False for the convenience of methods returning boolean
1398 success indicators.
1399 """
1400 g_oLock.acquire();
1401 try:
1402 g_oReporter.testIncErrors();
1403 g_oReporter.log(0, '** fatal error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1404 except:
1405 pass
1406 finally:
1407 g_oLock.release();
1408 return False;
1409
1410def fatalXcpt(sText=None, cFrames=1):
1411 """
1412 Log a fatal error caused by an exception. If sText is given, it will
1413 preceed the exception information. cFrames can be used to display more
1414 stack.
1415
1416 This will add an error to the current test.
1417
1418 Always returns False for the convenience of methods returning boolean
1419 success indicators.
1420 """
1421 logXcptWorker(0, True, "** fatal error: ", sText, cFrames);
1422 return False;
1423
1424def addLogFile(sFilename, sKind, sDescription = '', sAltName = None):
1425 """
1426 Adds the specified log file to the report if the file exists.
1427
1428 The sDescription is a free form description of the log file.
1429
1430 The sKind parameter is for adding some machine parsable hint what kind of
1431 log file this really is.
1432
1433 Returns True on success, False on failure (no ENOENT errors are logged).
1434 """
1435 sTsPrf = utils.getTimePrefix();
1436 sCaller = utils.getCallerName();
1437 fRc = False;
1438 if sAltName is None:
1439 sAltName = sFilename;
1440
1441 try:
1442 oSrcFile = utils.openNoInherit(sFilename, 'rb');
1443 except IOError as oXcpt:
1444 if oXcpt.errno != errno.ENOENT:
1445 logXcpt('addLogFile(%s,%s,%s)' % (sFilename, sDescription, sKind));
1446 else:
1447 logXcpt('addLogFile(%s,%s,%s) IOError' % (sFilename, sDescription, sKind));
1448 except:
1449 logXcpt('addLogFile(%s,%s,%s)' % (sFilename, sDescription, sKind));
1450 else:
1451 g_oLock.acquire();
1452 try:
1453 fRc = g_oReporter.addLogFile(oSrcFile, sFilename, sAltName, sDescription, sKind, sCaller, sTsPrf);
1454 finally:
1455 g_oLock.release();
1456 oSrcFile.close();
1457 return fRc;
1458
1459def addLogString(sLog, sLogName, sKind, sDescription = ''):
1460 """
1461 Adds the specified log string to the report.
1462
1463 The sLog parameter sets the name of the log file.
1464
1465 The sDescription is a free form description of the log file.
1466
1467 The sKind parameter is for adding some machine parsable hint what kind of
1468 log file this really is.
1469
1470 Returns True on success, False on failure (no ENOENT errors are logged).
1471 """
1472 sTsPrf = utils.getTimePrefix();
1473 sCaller = utils.getCallerName();
1474 fRc = False;
1475
1476 g_oLock.acquire();
1477 try:
1478 fRc = g_oReporter.addLogString(sLog, sLogName, sDescription, sKind, sCaller, sTsPrf);
1479 finally:
1480 g_oLock.release();
1481 return fRc;
1482
1483def isLocal():
1484 """Is this a local reporter?"""
1485 return g_oReporter.isLocal()
1486
1487def incVerbosity():
1488 """Increases the verbosity level."""
1489 return g_oReporter.incVerbosity()
1490
1491def incDebug():
1492 """Increases the debug level."""
1493 return g_oReporter.incDebug()
1494
1495def appendToProcessName(sAppend):
1496 """
1497 Appends sAppend to the base process name.
1498 Returns the new process name.
1499 """
1500 return g_oReporter.appendToProcessName(sAppend);
1501
1502def getErrorCount():
1503 """
1504 Get the current error count for the entire test run.
1505 """
1506 g_oLock.acquire();
1507 try:
1508 cErrors = g_oReporter.cErrors;
1509 finally:
1510 g_oLock.release();
1511 return cErrors;
1512
1513def doPollWork(sDebug = None):
1514 """
1515 This can be called from wait loops and similar to make the reporter call
1516 home with pending XML and such.
1517 """
1518 g_oReporter.doPollWork(sDebug);
1519 return None;
1520
1521
1522#
1523# Test reporting, a bit similar to RTTestI*.
1524#
1525
1526def testStart(sName):
1527 """
1528 Starts a new test (pushes it).
1529 """
1530 g_oLock.acquire();
1531 try:
1532 rc = g_oReporter.testStart(sName, utils.getCallerName());
1533 finally:
1534 g_oLock.release();
1535 return rc;
1536
1537def testValue(sName, sValue, sUnit):
1538 """
1539 Reports a benchmark value or something simiarlly useful.
1540 """
1541 g_oLock.acquire();
1542 try:
1543 rc = g_oReporter.testValue(sName, str(sValue), sUnit, utils.getCallerName());
1544 finally:
1545 g_oLock.release();
1546 return rc;
1547
1548def testFailure(sDetails):
1549 """
1550 Reports a failure.
1551 We count these calls and testDone will use them to report PASSED or FAILED.
1552
1553 Returns False so that a return False line can be saved.
1554 """
1555 g_oLock.acquire();
1556 try:
1557 g_oReporter.testFailure(sDetails, utils.getCallerName());
1558 finally:
1559 g_oLock.release();
1560 return False;
1561
1562def testFailureXcpt(sDetails = ''):
1563 """
1564 Reports a failure with exception.
1565 We count these calls and testDone will use them to report PASSED or FAILED.
1566
1567 Returns False so that a return False line can be saved.
1568 """
1569 # Extract exception info.
1570 try:
1571 oType, oValue, oTraceback = sys.exc_info();
1572 except:
1573 oType = oValue, oTraceback = None;
1574 if oType is not None:
1575 sCaller = utils.getCallerName(oTraceback.tb_frame);
1576 sXcpt = ' '.join(traceback.format_exception_only(oType, oValue));
1577 else:
1578 sCaller = utils.getCallerName();
1579 sXcpt = 'No exception at %s' % (sCaller,);
1580
1581 # Use testFailure to do the work.
1582 g_oLock.acquire();
1583 try:
1584 if sDetails == '':
1585 g_oReporter.testFailure('Exception: %s' % (sXcpt,), sCaller);
1586 else:
1587 g_oReporter.testFailure('%s: %s' % (sDetails, sXcpt), sCaller);
1588 finally:
1589 g_oLock.release();
1590 return False;
1591
1592def testDone(fSkipped = False):
1593 """
1594 Completes the current test (pops it), logging PASSED / FAILURE.
1595
1596 Returns a tuple with the name of the test and its error count.
1597 """
1598 g_oLock.acquire();
1599 try:
1600 rc = g_oReporter.testDone(fSkipped, utils.getCallerName());
1601 finally:
1602 g_oLock.release();
1603 return rc;
1604
1605def testErrorCount():
1606 """
1607 Gets the error count of the current test.
1608
1609 Returns the number of errors.
1610 """
1611 g_oLock.acquire();
1612 try:
1613 cErrors = g_oReporter.testErrorCount();
1614 finally:
1615 g_oLock.release();
1616 return cErrors;
1617
1618def testCleanup():
1619 """
1620 Closes all open tests with a generic error condition.
1621
1622 Returns True if no open tests, False if something had to be closed with failure.
1623 """
1624 g_oLock.acquire();
1625 try:
1626 fRc = g_oReporter.testCleanup(utils.getCallerName());
1627 g_oReporter.xmlFlush(fRetry = False, fForce = True);
1628 finally:
1629 g_oLock.release();
1630 return fRc;
1631
1632
1633#
1634# Sub XML stuff.
1635#
1636
1637def addSubXmlFile(sFilename):
1638 """
1639 Adds a sub-xml result file to the party.
1640 """
1641 fRc = False;
1642 try:
1643 oSrcFile = utils.openNoInherit(sFilename, 'r');
1644 except IOError as oXcpt:
1645 if oXcpt.errno != errno.ENOENT:
1646 logXcpt('addSubXmlFile(%s)' % (sFilename,));
1647 except:
1648 logXcpt('addSubXmlFile(%s)' % (sFilename,));
1649 else:
1650 try:
1651 oWrapper = FileWrapperTestPipe()
1652 oWrapper.write(oSrcFile.read());
1653 oWrapper.close();
1654 except:
1655 logXcpt('addSubXmlFile(%s)' % (sFilename,));
1656 oSrcFile.close();
1657
1658 return fRc;
1659
1660
1661#
1662# Other useful debugging tools.
1663#
1664
1665def logAllStacks(cFrames = None):
1666 """
1667 Logs the stacks of all python threads.
1668 """
1669 sTsPrf = utils.getTimePrefix();
1670 sCaller = utils.getCallerName();
1671 g_oLock.acquire();
1672
1673 cThread = 0;
1674 for idThread, oStack in sys._current_frames().items(): # >=2.5, a bit ugly - pylint: disable=W0212
1675 try:
1676 if cThread > 0:
1677 g_oReporter.log(1, '', sCaller, sTsPrf);
1678 g_oReporter.log(1, 'Thread %s (%#x)' % (idThread, idThread), sCaller, sTsPrf);
1679 try:
1680 asInfo = traceback.format_stack(oStack, cFrames);
1681 except:
1682 g_oReporter.log(1, ' Stack formatting failed w/ exception', sCaller, sTsPrf);
1683 else:
1684 for sInfo in asInfo:
1685 asLines = sInfo.splitlines();
1686 for sLine in asLines:
1687 g_oReporter.log(1, sLine, sCaller, sTsPrf);
1688 except:
1689 pass;
1690 cThread += 1;
1691
1692 g_oLock.release();
1693 return None;
1694
1695def checkTestManagerConnection():
1696 """
1697 Checks the connection to the test manager.
1698
1699 Returns True if the connection is fine, False if not, None if not remote
1700 reporter.
1701
1702 Note! This as the sideeffect of flushing XML.
1703 """
1704 g_oLock.acquire();
1705 try:
1706 fRc = g_oReporter.xmlFlush(fRetry = False, fForce = True);
1707 finally:
1708 g_oLock.release();
1709 return fRc;
1710
1711def flushall(fSkipXml = False):
1712 """
1713 Flushes all output streams, both standard and logger related.
1714 This may also push data to the remote test manager.
1715 """
1716 try: sys.stdout.flush();
1717 except: pass;
1718 try: sys.stderr.flush();
1719 except: pass;
1720
1721 if fSkipXml is not True:
1722 g_oLock.acquire();
1723 try:
1724 g_oReporter.xmlFlush(fRetry = False);
1725 finally:
1726 g_oLock.release();
1727
1728 return True;
1729
1730
1731#
1732# Module initialization.
1733#
1734
1735def _InitReporterModule():
1736 """
1737 Instantiate the test reporter.
1738 """
1739 global g_oReporter, g_sReporterName
1740
1741 g_sReporterName = os.getenv("TESTBOX_REPORTER", "local");
1742 if g_sReporterName == "local":
1743 g_oReporter = LocalReporter();
1744 elif g_sReporterName == "remote":
1745 g_oReporter = RemoteReporter(); # Correct, but still plain stupid. pylint: disable=redefined-variable-type
1746 else:
1747 print(os.path.basename(__file__) + ": Unknown TESTBOX_REPORTER value: '" + g_sReporterName + "'", file = sys.stderr);
1748 raise Exception("Unknown TESTBOX_REPORTER value '" + g_sReporterName + "'");
1749
1750if __name__ != "checker": # pychecker avoidance.
1751 _InitReporterModule();
1752
Note: See TracBrowser for help on using the repository browser.

© 2025 Oracle Support Privacy / Do Not Sell My Info Terms of Use Trademark Policy Automated Access Etiquette