VirtualBox

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

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

ValKit: More Python 3.9 API changes needed (array.array.tostring() -> .tobytes()) bugref:10079

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

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