VirtualBox

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

Last change on this file since 90780 was 90616, checked in by vboxsync, 3 years ago

ValKit: More Python 3.9 API changes needed (array.array.tostring() -> .tobytes()) [committed too much] bugref:10079

  • Property svn:eol-style set to native
  • Property svn:keywords set to Author Date Id Revision
File size: 65.7 KB
Line 
1# -*- coding: utf-8 -*-
2# $Id: reporter.py 90616 2021-08-11 07:27:39Z 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: 90616 $"
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 if sys.version_info < (3, 9, 0):
1226 # Removed since Python 3.9.
1227 sText = sText.tostring(); # pylint: disable=no-member
1228 else:
1229 sText = sText.tobytes();
1230 except:
1231 pass;
1232 if hasattr(sText, 'decode'):
1233 try:
1234 sText = sText.decode('utf-8', 'ignore');
1235 except:
1236 pass;
1237 g_oLock.acquire();
1238 try:
1239 sTsPrf = utils.getTimePrefix();
1240 sCaller = utils.getCallerName();
1241 asLines = sText.splitlines();
1242 for sLine in asLines:
1243 g_oReporter.log(0, '%s: %s' % (self.sPrefix, sLine), sCaller, sTsPrf);
1244 except:
1245 traceback.print_exc();
1246 finally:
1247 g_oLock.release();
1248 return None;
1249
1250class FileWrapperTestPipe(object):
1251 """ File like class for the test pipe (TXS EXEC and similar). """
1252 def __init__(self):
1253 self.sPrefix = '';
1254 self.fStarted = False;
1255 self.fClosed = False;
1256 self.sTagBuffer = None;
1257
1258 def __del__(self):
1259 self.close();
1260
1261 def close(self):
1262 """ file.close """
1263 if self.fStarted is True and self.fClosed is False:
1264 self.fClosed = True;
1265 try: g_oReporter.subXmlEnd(self);
1266 except:
1267 try: traceback.print_exc();
1268 except: pass;
1269 return True;
1270
1271 def read(self, cb = None):
1272 """file.read"""
1273 _ = cb;
1274 return "";
1275
1276 def write(self, sText):
1277 """file.write"""
1278 # lazy start.
1279 if self.fStarted is not True:
1280 try:
1281 g_oReporter.subXmlStart(self);
1282 except:
1283 traceback.print_exc();
1284 self.fStarted = True;
1285
1286 # Turn non-string stuff into strings.
1287 if not utils.isString(sText):
1288 if isinstance(sText, array.array):
1289 try:
1290 if sys.version_info < (3, 9, 0):
1291 # Removed since Python 3.9.
1292 sText = sText.tostring(); # pylint: disable=no-member
1293 else:
1294 sText = sText.tobytes();
1295 except:
1296 pass;
1297 if hasattr(sText, 'decode'):
1298 try: sText = sText.decode('utf-8', 'ignore');
1299 except: pass;
1300
1301 try:
1302 g_oReporter.subXmlWrite(self, sText, utils.getCallerName());
1303 # Parse the supplied text and look for <Failed.../> tags to keep track of the
1304 # error counter. This is only a very lazy aproach.
1305 sText.strip();
1306 idxText = 0;
1307 while sText:
1308 if self.sTagBuffer is None:
1309 # Look for the start of a tag.
1310 idxStart = sText[idxText:].find('<');
1311 if idxStart != -1:
1312 # Look for the end of the tag.
1313 idxEnd = sText[idxStart:].find('>');
1314
1315 # If the end was found inside the current buffer, parse the line,
1316 # else we have to save it for later.
1317 if idxEnd != -1:
1318 idxEnd += idxStart + 1;
1319 self._processXmlElement(sText[idxStart:idxEnd]);
1320 idxText = idxEnd;
1321 else:
1322 self.sTagBuffer = sText[idxStart:];
1323 idxText = len(sText);
1324 else:
1325 idxText = len(sText);
1326 else:
1327 # Search for the end of the tag and parse the whole tag.
1328 idxEnd = sText[idxText:].find('>');
1329 if idxEnd != -1:
1330 idxEnd += idxStart + 1;
1331 self._processXmlElement(self.sTagBuffer + sText[idxText:idxEnd]);
1332 self.sTagBuffer = None;
1333 idxText = idxEnd;
1334 else:
1335 self.sTagBuffer = self.sTagBuffer + sText[idxText:];
1336 idxText = len(sText);
1337
1338 sText = sText[idxText:];
1339 sText = sText.lstrip();
1340 except:
1341 traceback.print_exc();
1342 return None;
1343
1344 def _processXmlElement(self, sElement):
1345 """
1346 Processes a complete XML tag (so far we only search for the Failed to tag
1347 to keep track of the error counter.
1348 """
1349 # Make sure we don't parse any space between < and the element name.
1350 sElement = sElement.strip();
1351
1352 # Find the end of the name
1353 idxEndName = sElement.find(' ');
1354 if idxEndName == -1:
1355 idxEndName = sElement.find('/');
1356 if idxEndName == -1:
1357 idxEndName = sElement.find('>');
1358
1359 if idxEndName != -1:
1360 if sElement[1:idxEndName] == 'Failed':
1361 g_oLock.acquire();
1362 try:
1363 g_oReporter.testIncErrors();
1364 finally:
1365 g_oLock.release();
1366 else:
1367 error('_processXmlElement(%s)' % sElement);
1368
1369
1370#
1371# The public APIs.
1372#
1373
1374def log(sText):
1375 """Writes the specfied text to the log."""
1376 g_oLock.acquire();
1377 try:
1378 rc = g_oReporter.log(1, sText, utils.getCallerName(), utils.getTimePrefix());
1379 except:
1380 rc = -1;
1381 finally:
1382 g_oLock.release();
1383 return rc;
1384
1385def logXcpt(sText=None, cFrames=1):
1386 """
1387 Log an exception, optionally with a preceeding message and more than one
1388 call frame.
1389 """
1390 return logXcptWorker(1, False, "", sText, cFrames);
1391
1392def log2(sText):
1393 """Log level 2: Writes the specfied text to the log."""
1394 g_oLock.acquire();
1395 try:
1396 rc = g_oReporter.log(2, sText, utils.getCallerName(), utils.getTimePrefix());
1397 except:
1398 rc = -1;
1399 finally:
1400 g_oLock.release();
1401 return rc;
1402
1403def log2Xcpt(sText=None, cFrames=1):
1404 """
1405 Log level 2: Log an exception, optionally with a preceeding message and
1406 more than one call frame.
1407 """
1408 return logXcptWorker(2, False, "", sText, cFrames);
1409
1410def log3(sText):
1411 """Log level 3: Writes the specfied text to the log."""
1412 g_oLock.acquire();
1413 try:
1414 rc = g_oReporter.log(3, sText, utils.getCallerName(), utils.getTimePrefix());
1415 except:
1416 rc = -1;
1417 finally:
1418 g_oLock.release();
1419 return rc;
1420
1421def log3Xcpt(sText=None, cFrames=1):
1422 """
1423 Log level 3: Log an exception, optionally with a preceeding message and
1424 more than one call frame.
1425 """
1426 return logXcptWorker(3, False, "", sText, cFrames);
1427
1428def log4(sText):
1429 """Log level 4: Writes the specfied text to the log."""
1430 g_oLock.acquire();
1431 try:
1432 rc = g_oReporter.log(4, sText, utils.getCallerName(), utils.getTimePrefix());
1433 except:
1434 rc = -1;
1435 finally:
1436 g_oLock.release();
1437 return rc;
1438
1439def log4Xcpt(sText=None, cFrames=1):
1440 """
1441 Log level 4: Log an exception, optionally with a preceeding message and
1442 more than one call frame.
1443 """
1444 return logXcptWorker(4, False, "", sText, cFrames);
1445
1446def log5(sText):
1447 """Log level 2: Writes the specfied text to the log."""
1448 g_oLock.acquire();
1449 try:
1450 rc = g_oReporter.log(5, sText, utils.getCallerName(), utils.getTimePrefix());
1451 except:
1452 rc = -1;
1453 finally:
1454 g_oLock.release();
1455 return rc;
1456
1457def log5Xcpt(sText=None, cFrames=1):
1458 """
1459 Log level 5: Log an exception, optionally with a preceeding message and
1460 more than one call frame.
1461 """
1462 return logXcptWorker(5, False, "", sText, cFrames);
1463
1464def log6(sText):
1465 """Log level 6: Writes the specfied text to the log."""
1466 g_oLock.acquire();
1467 try:
1468 rc = g_oReporter.log(6, sText, utils.getCallerName(), utils.getTimePrefix());
1469 except:
1470 rc = -1;
1471 finally:
1472 g_oLock.release();
1473 return rc;
1474
1475def log6Xcpt(sText=None, cFrames=1):
1476 """
1477 Log level 6: Log an exception, optionally with a preceeding message and
1478 more than one call frame.
1479 """
1480 return logXcptWorker(6, False, "", sText, cFrames);
1481
1482def maybeErr(fIsError, sText):
1483 """ Maybe error or maybe normal log entry. """
1484 if fIsError is True:
1485 return error(sText);
1486 return log(sText);
1487
1488def maybeErrXcpt(fIsError, sText=None, cFrames=1):
1489 """ Maybe error or maybe normal log exception entry. """
1490 if fIsError is True:
1491 return errorXcpt(sText, cFrames);
1492 return logXcpt(sText, cFrames);
1493
1494def maybeLog(fIsNotError, sText):
1495 """ Maybe error or maybe normal log entry. """
1496 if fIsNotError is not True:
1497 return error(sText);
1498 return log(sText);
1499
1500def maybeLogXcpt(fIsNotError, sText=None, cFrames=1):
1501 """ Maybe error or maybe normal log exception entry. """
1502 if fIsNotError is not True:
1503 return errorXcpt(sText, cFrames);
1504 return logXcpt(sText, cFrames);
1505
1506def error(sText):
1507 """
1508 Writes the specfied error message to the log.
1509
1510 This will add an error to the current test.
1511
1512 Always returns False for the convenience of methods returning boolean
1513 success indicators.
1514 """
1515 g_oLock.acquire();
1516 try:
1517 g_oReporter.testIncErrors();
1518 g_oReporter.log(0, '** error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1519 except:
1520 pass;
1521 finally:
1522 g_oLock.release();
1523 return False;
1524
1525def errorXcpt(sText=None, cFrames=1):
1526 """
1527 Log an error caused by an exception. If sText is given, it will preceed
1528 the exception information. cFrames can be used to display more stack.
1529
1530 This will add an error to the current test.
1531
1532 Always returns False for the convenience of methods returning boolean
1533 success indicators.
1534 """
1535 logXcptWorker(0, True, '** error: ', sText, cFrames);
1536 return False;
1537
1538def errorTimeout(sText):
1539 """
1540 Flags the current test as having timed out and writes the specified message to the log.
1541
1542 This will add an error to the current test.
1543
1544 Always returns False for the convenience of methods returning boolean
1545 success indicators.
1546 """
1547 g_oLock.acquire();
1548 try:
1549 g_oReporter.testSetTimedOut();
1550 g_oReporter.log(0, '** timeout-error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1551 except:
1552 pass;
1553 finally:
1554 g_oLock.release();
1555 return False;
1556
1557def fatal(sText):
1558 """
1559 Writes a fatal error to the log.
1560
1561 This will add an error to the current test.
1562
1563 Always returns False for the convenience of methods returning boolean
1564 success indicators.
1565 """
1566 g_oLock.acquire();
1567 try:
1568 g_oReporter.testIncErrors();
1569 g_oReporter.log(0, '** fatal error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1570 except:
1571 pass
1572 finally:
1573 g_oLock.release();
1574 return False;
1575
1576def fatalXcpt(sText=None, cFrames=1):
1577 """
1578 Log a fatal error caused by an exception. If sText is given, it will
1579 preceed the exception information. cFrames can be used to display more
1580 stack.
1581
1582 This will add an error to the current test.
1583
1584 Always returns False for the convenience of methods returning boolean
1585 success indicators.
1586 """
1587 logXcptWorker(0, True, "** fatal error: ", sText, cFrames);
1588 return False;
1589
1590def addLogFile(sFilename, sKind, sDescription = '', sAltName = None):
1591 """
1592 Adds the specified log file to the report if the file exists.
1593
1594 The sDescription is a free form description of the log file.
1595
1596 The sKind parameter is for adding some machine parsable hint what kind of
1597 log file this really is.
1598
1599 Returns True on success, False on failure (no ENOENT errors are logged).
1600 """
1601 sTsPrf = utils.getTimePrefix();
1602 sCaller = utils.getCallerName();
1603 fRc = False;
1604 if sAltName is None:
1605 sAltName = sFilename;
1606
1607 try:
1608 oSrcFile = utils.openNoInherit(sFilename, 'rb');
1609 except IOError as oXcpt:
1610 if oXcpt.errno != errno.ENOENT:
1611 logXcpt('addLogFile(%s,%s,%s)' % (sFilename, sDescription, sKind));
1612 else:
1613 logXcpt('addLogFile(%s,%s,%s) IOError' % (sFilename, sDescription, sKind));
1614 except:
1615 logXcpt('addLogFile(%s,%s,%s)' % (sFilename, sDescription, sKind));
1616 else:
1617 g_oLock.acquire();
1618 try:
1619 fRc = g_oReporter.addLogFile(oSrcFile, sFilename, sAltName, sDescription, sKind, sCaller, sTsPrf);
1620 finally:
1621 g_oLock.release();
1622 oSrcFile.close();
1623 return fRc;
1624
1625def addLogString(sLog, sLogName, sKind, sDescription = ''):
1626 """
1627 Adds the specified log string to the report.
1628
1629 The sLog parameter sets the name of the log file.
1630
1631 The sDescription is a free form description of the log file.
1632
1633 The sKind parameter is for adding some machine parsable hint what kind of
1634 log file this really is.
1635
1636 Returns True on success, False on failure (no ENOENT errors are logged).
1637 """
1638 sTsPrf = utils.getTimePrefix();
1639 sCaller = utils.getCallerName();
1640 fRc = False;
1641
1642 g_oLock.acquire();
1643 try:
1644 fRc = g_oReporter.addLogString(sLog, sLogName, sDescription, sKind, sCaller, sTsPrf);
1645 finally:
1646 g_oLock.release();
1647 return fRc;
1648
1649def isLocal():
1650 """Is this a local reporter?"""
1651 return g_oReporter.isLocal()
1652
1653def incVerbosity():
1654 """Increases the verbosity level."""
1655 return g_oReporter.incVerbosity()
1656
1657def incDebug():
1658 """Increases the debug level."""
1659 return g_oReporter.incDebug()
1660
1661def getVerbosity():
1662 """Returns the current verbosity level."""
1663 return g_oReporter.getVerbosity()
1664
1665def getDebug():
1666 """Returns the current debug level."""
1667 return g_oReporter.getDebug()
1668
1669def appendToProcessName(sAppend):
1670 """
1671 Appends sAppend to the base process name.
1672 Returns the new process name.
1673 """
1674 return g_oReporter.appendToProcessName(sAppend);
1675
1676def getErrorCount():
1677 """
1678 Get the current error count for the entire test run.
1679 """
1680 g_oLock.acquire();
1681 try:
1682 cErrors = g_oReporter.cErrors;
1683 finally:
1684 g_oLock.release();
1685 return cErrors;
1686
1687def doPollWork(sDebug = None):
1688 """
1689 This can be called from wait loops and similar to make the reporter call
1690 home with pending XML and such.
1691 """
1692 g_oReporter.doPollWork(sDebug);
1693 return None;
1694
1695
1696#
1697# Test reporting, a bit similar to RTTestI*.
1698#
1699
1700def testStart(sName):
1701 """
1702 Starts a new test (pushes it).
1703 """
1704 g_oLock.acquire();
1705 try:
1706 rc = g_oReporter.testStart(sName, utils.getCallerName());
1707 finally:
1708 g_oLock.release();
1709 return rc;
1710
1711def testValue(sName, sValue, sUnit):
1712 """
1713 Reports a benchmark value or something simiarlly useful.
1714 """
1715 g_oLock.acquire();
1716 try:
1717 rc = g_oReporter.testValue(sName, str(sValue), sUnit, utils.getCallerName());
1718 finally:
1719 g_oLock.release();
1720 return rc;
1721
1722def testFailure(sDetails):
1723 """
1724 Reports a failure.
1725 We count these calls and testDone will use them to report PASSED or FAILED.
1726
1727 Returns False so that a return False line can be saved.
1728 """
1729 g_oLock.acquire();
1730 try:
1731 g_oReporter.testFailure(sDetails, utils.getCallerName());
1732 finally:
1733 g_oLock.release();
1734 return False;
1735
1736def testFailureXcpt(sDetails = ''):
1737 """
1738 Reports a failure with exception.
1739 We count these calls and testDone will use them to report PASSED or FAILED.
1740
1741 Returns False so that a return False line can be saved.
1742 """
1743 # Extract exception info.
1744 try:
1745 oType, oValue, oTraceback = sys.exc_info();
1746 except:
1747 oType = oValue, oTraceback = None;
1748 if oType is not None:
1749 sCaller = utils.getCallerName(oTraceback.tb_frame);
1750 sXcpt = ' '.join(formatExceptionOnly(oType, oValue, sCaller, utils.getTimePrefix()));
1751 else:
1752 sCaller = utils.getCallerName();
1753 sXcpt = 'No exception at %s' % (sCaller,);
1754
1755 # Use testFailure to do the work.
1756 g_oLock.acquire();
1757 try:
1758 if sDetails == '':
1759 g_oReporter.testFailure('Exception: %s' % (sXcpt,), sCaller);
1760 else:
1761 g_oReporter.testFailure('%s: %s' % (sDetails, sXcpt), sCaller);
1762 finally:
1763 g_oLock.release();
1764 return False;
1765
1766def testDone(fSkipped = False):
1767 """
1768 Completes the current test (pops it), logging PASSED / FAILURE.
1769
1770 Returns a tuple with the name of the test and its error count.
1771 """
1772 g_oLock.acquire();
1773 try:
1774 rc = g_oReporter.testDone(fSkipped, utils.getCallerName());
1775 finally:
1776 g_oLock.release();
1777 return rc;
1778
1779def testErrorCount():
1780 """
1781 Gets the error count of the current test.
1782
1783 Returns the number of errors.
1784 """
1785 g_oLock.acquire();
1786 try:
1787 cErrors = g_oReporter.testErrorCount();
1788 finally:
1789 g_oLock.release();
1790 return cErrors;
1791
1792def testCleanup():
1793 """
1794 Closes all open tests with a generic error condition.
1795
1796 Returns True if no open tests, False if something had to be closed with failure.
1797 """
1798 g_oLock.acquire();
1799 try:
1800 fRc = g_oReporter.testCleanup(utils.getCallerName());
1801 g_oReporter.xmlFlush(fRetry = False, fForce = True);
1802 finally:
1803 g_oLock.release();
1804 fRc = False;
1805 return fRc;
1806
1807
1808#
1809# Sub XML stuff.
1810#
1811
1812def addSubXmlFile(sFilename):
1813 """
1814 Adds a sub-xml result file to the party.
1815 """
1816 fRc = False;
1817 try:
1818 oSrcFile = utils.openNoInherit(sFilename, 'r');
1819 except IOError as oXcpt:
1820 if oXcpt.errno != errno.ENOENT:
1821 logXcpt('addSubXmlFile(%s)' % (sFilename,));
1822 except:
1823 logXcpt('addSubXmlFile(%s)' % (sFilename,));
1824 else:
1825 try:
1826 oWrapper = FileWrapperTestPipe()
1827 oWrapper.write(oSrcFile.read());
1828 oWrapper.close();
1829 except:
1830 logXcpt('addSubXmlFile(%s)' % (sFilename,));
1831 oSrcFile.close();
1832
1833 return fRc;
1834
1835
1836#
1837# Other useful debugging tools.
1838#
1839
1840def logAllStacks(cFrames = None):
1841 """
1842 Logs the stacks of all python threads.
1843 """
1844 sTsPrf = utils.getTimePrefix();
1845 sCaller = utils.getCallerName();
1846 g_oLock.acquire();
1847
1848 cThread = 0;
1849 for idThread, oStack in sys._current_frames().items(): # >=2.5, a bit ugly - pylint: disable=protected-access
1850 try:
1851 if cThread > 0:
1852 g_oReporter.log(1, '', sCaller, sTsPrf);
1853 g_oReporter.log(1, 'Thread %s (%#x)' % (idThread, idThread), sCaller, sTsPrf);
1854 try:
1855 asInfo = traceback.format_stack(oStack, cFrames);
1856 except:
1857 g_oReporter.log(1, ' Stack formatting failed w/ exception', sCaller, sTsPrf);
1858 else:
1859 for sInfo in asInfo:
1860 asLines = sInfo.splitlines();
1861 for sLine in asLines:
1862 g_oReporter.log(1, sLine, sCaller, sTsPrf);
1863 except:
1864 pass;
1865 cThread += 1;
1866
1867 g_oLock.release();
1868 return None;
1869
1870def checkTestManagerConnection():
1871 """
1872 Checks the connection to the test manager.
1873
1874 Returns True if the connection is fine, False if not, None if not remote
1875 reporter.
1876
1877 Note! This as the sideeffect of flushing XML.
1878 """
1879 g_oLock.acquire();
1880 try:
1881 fRc = g_oReporter.xmlFlush(fRetry = False, fForce = True);
1882 finally:
1883 g_oLock.release();
1884 fRc = False;
1885 return fRc;
1886
1887def flushall(fSkipXml = False):
1888 """
1889 Flushes all output streams, both standard and logger related.
1890 This may also push data to the remote test manager.
1891 """
1892 try: sys.stdout.flush();
1893 except: pass;
1894 try: sys.stderr.flush();
1895 except: pass;
1896
1897 if fSkipXml is not True:
1898 g_oLock.acquire();
1899 try:
1900 g_oReporter.xmlFlush(fRetry = False);
1901 finally:
1902 g_oLock.release();
1903
1904 return True;
1905
1906
1907#
1908# Module initialization.
1909#
1910
1911def _InitReporterModule():
1912 """
1913 Instantiate the test reporter.
1914 """
1915 global g_oReporter, g_sReporterName
1916
1917 g_sReporterName = os.getenv("TESTBOX_REPORTER", "local");
1918 if g_sReporterName == "local":
1919 g_oReporter = LocalReporter();
1920 elif g_sReporterName == "remote":
1921 g_oReporter = RemoteReporter(); # Correct, but still plain stupid. pylint: disable=redefined-variable-type
1922 else:
1923 print(os.path.basename(__file__) + ": Unknown TESTBOX_REPORTER value: '" + g_sReporterName + "'", file = sys.stderr);
1924 raise Exception("Unknown TESTBOX_REPORTER value '" + g_sReporterName + "'");
1925
1926if __name__ != "checker": # pychecker avoidance.
1927 _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