reporter.py@ 62104

Last change on this file since 62104 was 62104, checked in by vboxsync, 8 years ago
testdriver: Changed reporter.flushall() to also flush the XML stream to the server (helps with VBox install/uninstall which is already using it). Made startVmAndconnectToTxsViaTcp do a flushall before starting the VM. Added report.doPollWork in vbox.TestDriver.waitForTasksSleepWorker.
Property svn:eol-style set to `native` Property svn:keywords set to `Author Date Id Revision`
File size: 55.2 KB

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

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

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

Download in other formats: