VirtualBox

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

Last change on this file since 87672 was 84921, checked in by vboxsync, 4 years ago

ValKit: pylint 2.5.3 adjustments.

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

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