reporter.py@ 78327

Last change on this file since 78327 was 77507, checked in by vboxsync, 6 years ago
Validation Kit/reporter.py: Don't upload empty files (with 0 bytes size) to the Test Manager.
Property svn:eol-style set to `native` Property svn:keywords set to `Author Date Id Revision`
File size: 60.6 KB

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

Note: See TracBrowser for help on using the repository browser.

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

Download in other formats: