reporter.py@ 62026

Last change on this file since 62026 was 62026, checked in by vboxsync, 8 years ago
testdriver/reporter.py: XML flushing debug code (must be removed lated)
Property svn:eol-style set to `native` Property svn:keywords set to `Author Date Id Revision`
File size: 54.8 KB

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

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

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

Download in other formats: