VirtualBox

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

Last change on this file was 106061, checked in by vboxsync, 3 months ago

Copyright year updates by scm.

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