reporter.py@ 62084

Last change on this file since 62084 was 62084, checked in by vboxsync, 9 years ago
testdriver/report.py: More xml flush debug.
Property svn:eol-style set to `native` Property svn:keywords set to `Author Date Id Revision`
File size: 54.9 KB

Line
1	# -- coding: utf-8 --
2	# $Id: reporter.py 62084 2016-07-06 20:23:43Z 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.215389.xyz. 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: 62084 $"
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	self._writeOutput('xml-debug/%s: flushing!' % (len(self._asXml),)); # temporarily while debugging flush/poll
874	g_oLock.release();
875	(asXml, fIncErrors) = self._xmlDoFlush(asXml, fRetry = fRetry);
876	g_oLock.acquire();
877
878	if fIncErrors:
879	self.testIncErrors();
880
881	self._fXmlFlushing = False;
882	if asXml is None:
883	self._secTsXmlFlush = utils.timestampSecond();
884	else:
885	self._asXml = asXml + self._asXml;
886	return True;
887
888	self._secTsXmlFlush = utils.timestampSecond();
889	return False;
890
891	def _xmlFlushIfNecessary(self):
892	"""Flushes the XML back log if necessary."""
893	tsNow = utils.timestampSecond();
894	cSecs = tsNow - self._secTsXmlFlush;
895	cSecsLast = tsNow - self._secTsXmlLast;
896	self._secTsXmlLast = tsNow;
897	self._writeOutput('xml-debug/%s: %s s since flush, %s s since poll'
898	% (len(self._asXml), cSecs, cSecsLast,)); # temporarily while debugging flush/poll problem.
899
900	# Absolute flush thresholds.
901	if cSecs >= self.kcSecXmlFlushMax:
902	return self.xmlFlush();
903	if len(self._asXml) >= self.kcLinesXmlFlush:
904	return self.xmlFlush();
905
906	# Flush if idle long enough.
907	if cSecs >= self.kcSecXmlFlushMin \
908	and cSecsLast >= self.kcSecXmlFlushIdle:
909	return self.xmlFlush();
910
911	return False;
912
913	def _xmlWrite(self, asText, fIndent = True):
914	"""XML output function for the reporter."""
915	self._writeOutput('xml-debug/%s: %s' % (len(self._asXml), asText)); # temporarily while debugging flush/poll problem.
916	self._asXml += asText;
917	self._xmlFlushIfNecessary();
918	_ = fIndent; # No pretty printing, thank you.
919	return None;
920
921	def subXmlStart(self, oFileWrapper):
922	oFileWrapper.sXmlBuffer = '';
923	return None;
924
925	def subXmlWrite(self, oFileWrapper, sRawXml, sCaller):
926	oFileWrapper.sXmlBuffer += sRawXml;
927	_ = sCaller;
928	return None;
929
930	def subXmlEnd(self, oFileWrapper):
931	sRawXml = oFileWrapper.sXmlBuffer;
932	## @todo should validate the document here and maybe auto terminate things. Adding some hints to have the server do
933	# this instead.
934	g_oLock.acquire();
935	self._asXml += [ '<PushHint testdepth="%d"/>' % (len(self.atTests),),
936	sRawXml,
937	'<PopHint testdepth="%d"/>' % (len(self.atTests),),];
938	self._xmlFlushIfNecessary();
939	g_oLock.release();
940	return None;
941
942	def doPollWork(self):
943	if len(self._asXml) > 0:
944	g_oLock.acquire();
945	self._xmlFlushIfNecessary();
946	g_oLock.release();
947	return None;
948
949
950	#
951	# Helpers
952	#
953
954	def logXcptWorker(iLevel, fIncErrors, sPrefix="", sText=None, cFrames=1):
955	"""
956	Log an exception, optionally with a preceeding message and more than one
957	call frame.
958	"""
959	g_oLock.acquire();
960	if fIncErrors:
961	g_oReporter.testIncErrors();
962
963	## @todo skip all this if iLevel is too high!
964
965	# Try get exception info.
966	sTsPrf = utils.getTimePrefix();
967	try:
968	oType, oValue, oTraceback = sys.exc_info();
969	except:
970	oType = oValue = oTraceback = None;
971	if oType is not None:
972
973	# Try format the info
974	try:
975	rc = 0;
976	sCaller = utils.getCallerName(oTraceback.tb_frame);
977	if sText is not None:
978	rc = g_oReporter.log(iLevel, "%s%s" % (sPrefix, sText), sCaller, sTsPrf);
979	asInfo = [];
980	try:
981	asInfo = asInfo + traceback.format_exception_only(oType, oValue);
982	if cFrames is not None and cFrames <= 1:
983	asInfo = asInfo + traceback.format_tb(oTraceback, 1);
984	else:
985	asInfo.append('Traceback:')
986	asInfo = asInfo + traceback.format_tb(oTraceback, cFrames);
987	asInfo.append('Stack:')
988	asInfo = asInfo + traceback.format_stack(oTraceback.tb_frame.f_back, cFrames);
989	except:
990	g_oReporter.log(0, '** internal-error: Hit exception #2! %s' % (traceback.format_exc()), sCaller, sTsPrf);
991
992	if len(asInfo) > 0:
993	# Do the logging.
994	for sItem in asInfo:
995	asLines = sItem.splitlines();
996	for sLine in asLines:
997	rc = g_oReporter.log(iLevel, '%s%s' % (sPrefix, sLine), sCaller, sTsPrf);
998
999	else:
1000	g_oReporter.log(iLevel, 'No exception info...', sCaller, sTsPrf);
1001	rc = -3;
1002	except:
1003	g_oReporter.log(0, '** internal-error: Hit exception! %s' % (traceback.format_exc()), None, sTsPrf);
1004	rc = -2;
1005	else:
1006	g_oReporter.log(0, '** internal-error: No exception! %s'
1007	% (utils.getCallerName(iFrame=3)), utils.getCallerName(iFrame=3), sTsPrf);
1008	rc = -1;
1009
1010	g_oLock.release();
1011	return rc;
1012
1013	#
1014	# The public Classes
1015	#
1016	class FileWrapper(object):
1017	""" File like class for TXS EXEC and similar. """
1018	def __init__(self, sPrefix):
1019	self.sPrefix = sPrefix;
1020
1021	def __del__(self):
1022	self.close();
1023
1024	def close(self):
1025	""" file.close """
1026	# Nothing to be done.
1027	return;
1028
1029	def read(self, cb):
1030	"""file.read"""
1031	_ = cb;
1032	return "";
1033
1034	def write(self, sText):
1035	"""file.write"""
1036	if isinstance(sText, array.array):
1037	try:
1038	sText = sText.tostring();
1039	except:
1040	pass;
1041	g_oLock.acquire();
1042	try:
1043	sTsPrf = utils.getTimePrefix();
1044	sCaller = utils.getCallerName();
1045	asLines = sText.splitlines();
1046	for sLine in asLines:
1047	g_oReporter.log(0, '%s: %s' % (self.sPrefix, sLine), sCaller, sTsPrf);
1048	except:
1049	traceback.print_exc();
1050	g_oLock.release();
1051	return None;
1052
1053	class FileWrapperTestPipe(object):
1054	""" File like class for the test pipe (TXS EXEC and similar). """
1055	def __init__(self):
1056	self.sPrefix = '';
1057	self.fStarted = False;
1058	self.fClosed = False;
1059	self.sTagBuffer = None;
1060
1061	def __del__(self):
1062	self.close();
1063
1064	def close(self):
1065	""" file.close """
1066	if self.fStarted is True and self.fClosed is False:
1067	self.fClosed = True;
1068	try: g_oReporter.subXmlEnd(self);
1069	except:
1070	try: traceback.print_exc();
1071	except: pass;
1072	return True;
1073
1074	def read(self, cb = None):
1075	"""file.read"""
1076	_ = cb;
1077	return "";
1078
1079	def write(self, sText):
1080	"""file.write"""
1081	# lazy start.
1082	if self.fStarted is not True:
1083	try:
1084	g_oReporter.subXmlStart(self);
1085	except:
1086	traceback.print_exc();
1087	self.fStarted = True;
1088
1089	if isinstance(sText, array.array):
1090	try:
1091	sText = sText.tostring();
1092	except:
1093	pass;
1094	try:
1095	g_oReporter.subXmlWrite(self, sText, utils.getCallerName());
1096	# Parse the supplied text and look for <Failed.../> tags to keep track of the
1097	# error counter. This is only a very lazy aproach.
1098	sText.strip();
1099	idxText = 0;
1100	while len(sText) > 0:
1101	if self.sTagBuffer is None:
1102	# Look for the start of a tag.
1103	idxStart = sText[idxText:].find('<');
1104	if idxStart != -1:
1105	# Look for the end of the tag.
1106	idxEnd = sText[idxStart:].find('>');
1107
1108	# If the end was found inside the current buffer, parse the line,
1109	# else we have to save it for later.
1110	if idxEnd != -1:
1111	idxEnd += idxStart + 1;
1112	self._processXmlElement(sText[idxStart:idxEnd]);
1113	idxText = idxEnd;
1114	else:
1115	self.sTagBuffer = sText[idxStart:];
1116	idxText = len(sText);
1117	else:
1118	idxText = len(sText);
1119	else:
1120	# Search for the end of the tag and parse the whole tag.
1121	idxEnd = sText[idxText:].find('>');
1122	if idxEnd != -1:
1123	idxEnd += idxStart + 1;
1124	self._processXmlElement(self.sTagBuffer + sText[idxText:idxEnd]);
1125	self.sTagBuffer = None;
1126	idxText = idxEnd;
1127	else:
1128	self.sTagBuffer = self.sTagBuffer + sText[idxText:];
1129	idxText = len(sText);
1130
1131	sText = sText[idxText:];
1132	sText = sText.lstrip();
1133	except:
1134	traceback.print_exc();
1135	return None;
1136
1137	def _processXmlElement(self, sElement):
1138	"""
1139	Processes a complete XML tag (so far we only search for the Failed to tag
1140	to keep track of the error counter.
1141	"""
1142	# Make sure we don't parse any space between < and the element name.
1143	sElement = sElement.strip();
1144
1145	# Find the end of the name
1146	idxEndName = sElement.find(' ');
1147	if idxEndName == -1:
1148	idxEndName = sElement.find('/');
1149	if idxEndName == -1:
1150	idxEndName = sElement.find('>');
1151
1152	if idxEndName != -1:
1153	if sElement[1:idxEndName] == 'Failed':
1154	g_oLock.acquire();
1155	g_oReporter.testIncErrors();
1156	g_oLock.release();
1157	else:
1158	error('_processXmlElement(%s)' % sElement);
1159
1160
1161	#
1162	# The public APIs.
1163	#
1164
1165	def log(sText):
1166	"""Writes the specfied text to the log."""
1167	g_oLock.acquire();
1168	try:
1169	rc = g_oReporter.log(1, sText, utils.getCallerName(), utils.getTimePrefix());
1170	except:
1171	rc = -1;
1172	g_oLock.release();
1173	return rc;
1174
1175	def logXcpt(sText=None, cFrames=1):
1176	"""
1177	Log an exception, optionally with a preceeding message and more than one
1178	call frame.
1179	"""
1180	return logXcptWorker(1, False, "", sText, cFrames);
1181
1182	def log2(sText):
1183	"""Log level 2: Writes the specfied text to the log."""
1184	g_oLock.acquire();
1185	try:
1186	rc = g_oReporter.log(2, sText, utils.getCallerName(), utils.getTimePrefix());
1187	except:
1188	rc = -1;
1189	g_oLock.release();
1190	return rc;
1191
1192	def log2Xcpt(sText=None, cFrames=1):
1193	"""
1194	Log level 2: Log an exception, optionally with a preceeding message and
1195	more than one call frame.
1196	"""
1197	return logXcptWorker(2, False, "", sText, cFrames);
1198
1199	def maybeErr(fIsError, sText):
1200	""" Maybe error or maybe normal log entry. """
1201	if fIsError is True:
1202	return error(sText);
1203	return log(sText);
1204
1205	def maybeErrXcpt(fIsError, sText=None, cFrames=1):
1206	""" Maybe error or maybe normal log exception entry. """
1207	if fIsError is True:
1208	return errorXcpt(sText, cFrames);
1209	return logXcpt(sText, cFrames);
1210
1211	def maybeLog(fIsNotError, sText):
1212	""" Maybe error or maybe normal log entry. """
1213	if fIsNotError is not True:
1214	return error(sText);
1215	return log(sText);
1216
1217	def maybeLogXcpt(fIsNotError, sText=None, cFrames=1):
1218	""" Maybe error or maybe normal log exception entry. """
1219	if fIsNotError is not True:
1220	return errorXcpt(sText, cFrames);
1221	return logXcpt(sText, cFrames);
1222
1223	def error(sText):
1224	"""
1225	Writes the specfied error message to the log.
1226
1227	This will add an error to the current test.
1228
1229	Always returns False for the convenience of methods returning boolean
1230	success indicators.
1231	"""
1232	g_oLock.acquire();
1233	g_oReporter.testIncErrors();
1234	try:
1235	g_oReporter.log(0, '** error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1236	except:
1237	pass;
1238	g_oLock.release();
1239	return False;
1240
1241	def errorXcpt(sText=None, cFrames=1):
1242	"""
1243	Log an error caused by an exception. If sText is given, it will preceed
1244	the exception information. cFrames can be used to display more stack.
1245
1246	This will add an error to the current test.
1247
1248	Always returns False for the convenience of methods returning boolean
1249	success indicators.
1250	"""
1251	logXcptWorker(0, True, '** error: ', sText, cFrames);
1252	return False;
1253
1254	def errorTimeout(sText):
1255	"""
1256	Flags the current test as having timed out and writes the specified message to the log.
1257
1258	This will add an error to the current test.
1259
1260	Always returns False for the convenience of methods returning boolean
1261	success indicators.
1262	"""
1263	g_oLock.acquire();
1264	g_oReporter.testSetTimedOut();
1265	try:
1266	g_oReporter.log(0, '** timeout-error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1267	except:
1268	pass;
1269	g_oLock.release();
1270	return False;
1271
1272	def fatal(sText):
1273	"""
1274	Writes a fatal error to the log.
1275
1276	This will add an error to the current test.
1277
1278	Always returns False for the convenience of methods returning boolean
1279	success indicators.
1280	"""
1281	g_oLock.acquire();
1282	g_oReporter.testIncErrors();
1283	try:
1284	g_oReporter.log(0, '** fatal error: %s' % (sText), utils.getCallerName(), utils.getTimePrefix());
1285	except:
1286	pass
1287	g_oLock.release();
1288	return False;
1289
1290	def fatalXcpt(sText=None, cFrames=1):
1291	"""
1292	Log a fatal error caused by an exception. If sText is given, it will
1293	preceed the exception information. cFrames can be used to display more
1294	stack.
1295
1296	This will add an error to the current test.
1297
1298	Always returns False for the convenience of methods returning boolean
1299	success indicators.
1300	"""
1301	logXcptWorker(0, True, "** fatal error: ", sText, cFrames);
1302	return False;
1303
1304	def addLogFile(sFilename, sKind, sDescription = '', sAltName = None):
1305	"""
1306	Adds the specified log file to the report if the file exists.
1307
1308	The sDescription is a free form description of the log file.
1309
1310	The sKind parameter is for adding some machine parsable hint what kind of
1311	log file this really is.
1312
1313	Returns True on success, False on failure (no ENOENT errors are logged).
1314	"""
1315	sTsPrf = utils.getTimePrefix();
1316	sCaller = utils.getCallerName();
1317	fRc = False;
1318	if sAltName is None:
1319	sAltName = sFilename;
1320
1321	try:
1322	oSrcFile = utils.openNoInherit(sFilename, 'rb');
1323	except IOError, oXcpt:
1324	if oXcpt.errno != errno.ENOENT:
1325	logXcpt('addLogFile(%s,%s,%s)' % (sFilename, sDescription, sKind));
1326	else:
1327	logXcpt('addLogFile(%s,%s,%s) IOError' % (sFilename, sDescription, sKind));
1328	except:
1329	logXcpt('addLogFile(%s,%s,%s)' % (sFilename, sDescription, sKind));
1330	else:
1331	g_oLock.acquire();
1332	fRc = g_oReporter.addLogFile(oSrcFile, sFilename, sAltName, sDescription, sKind, sCaller, sTsPrf);
1333	g_oLock.release();
1334	oSrcFile.close();
1335	return fRc;
1336
1337	def addLogString(sLog, sLogName, sKind, sDescription = ''):
1338	"""
1339	Adds the specified log string to the report.
1340
1341	The sLog parameter sets the name of the log file.
1342
1343	The sDescription is a free form description of the log file.
1344
1345	The sKind parameter is for adding some machine parsable hint what kind of
1346	log file this really is.
1347
1348	Returns True on success, False on failure (no ENOENT errors are logged).
1349	"""
1350	sTsPrf = utils.getTimePrefix();
1351	sCaller = utils.getCallerName();
1352	fRc = False;
1353
1354	g_oLock.acquire();
1355	fRc = g_oReporter.addLogString(sLog, sLogName, sDescription, sKind, sCaller, sTsPrf);
1356	g_oLock.release();
1357	return fRc;
1358
1359	def isLocal():
1360	"""Is this a local reporter?"""
1361	return g_oReporter.isLocal()
1362
1363	def incVerbosity():
1364	"""Increases the verbosity level."""
1365	return g_oReporter.incVerbosity()
1366
1367	def incDebug():
1368	"""Increases the debug level."""
1369	return g_oReporter.incDebug()
1370
1371	def getErrorCount():
1372	"""
1373	Get the current error count for the entire test run.
1374	"""
1375	g_oLock.acquire();
1376	cErrors = g_oReporter.cErrors;
1377	g_oLock.release();
1378	return cErrors;
1379
1380	def doPollWork():
1381	"""
1382	This can be called from wait loops and similar to make the reporter call
1383	home with pending XML and such.
1384	"""
1385	g_oReporter.doPollWork();
1386	return None;
1387
1388
1389	#
1390	# Test reporting, a bit similar to RTTestI*.
1391	#
1392
1393	def testStart(sName):
1394	"""
1395	Starts a new test (pushes it).
1396	"""
1397	g_oLock.acquire();
1398	rc = g_oReporter.testStart(sName, utils.getCallerName());
1399	g_oLock.release();
1400	return rc;
1401
1402	def testValue(sName, sValue, sUnit):
1403	"""
1404	Reports a benchmark value or something simiarlly useful.
1405	"""
1406	g_oLock.acquire();
1407	rc = g_oReporter.testValue(sName, str(sValue), sUnit, utils.getCallerName());
1408	g_oLock.release();
1409	return rc;
1410
1411	def testFailure(sDetails):
1412	"""
1413	Reports a failure.
1414	We count these calls and testDone will use them to report PASSED or FAILED.
1415
1416	Returns False so that a return False line can be saved.
1417	"""
1418	g_oLock.acquire();
1419	g_oReporter.testFailure(sDetails, utils.getCallerName());
1420	g_oLock.release();
1421	return False;
1422
1423	def testFailureXcpt(sDetails = ''):
1424	"""
1425	Reports a failure with exception.
1426	We count these calls and testDone will use them to report PASSED or FAILED.
1427
1428	Returns False so that a return False line can be saved.
1429	"""
1430	# Extract exception info.
1431	try:
1432	oType, oValue, oTraceback = sys.exc_info();
1433	except:
1434	oType = oValue, oTraceback = None;
1435	if oType is not None:
1436	sCaller = utils.getCallerName(oTraceback.tb_frame);
1437	sXcpt = ' '.join(traceback.format_exception_only(oType, oValue));
1438	else:
1439	sCaller = utils.getCallerName();
1440	sXcpt = 'No exception at %s' % (sCaller,);
1441
1442	# Use testFailure to do the work.
1443	g_oLock.acquire();
1444	if sDetails == '':
1445	g_oReporter.testFailure('Exception: %s' % (sXcpt,), sCaller);
1446	else:
1447	g_oReporter.testFailure('%s: %s' % (sDetails, sXcpt), sCaller);
1448	g_oLock.release();
1449	return False;
1450
1451	def testDone(fSkipped = False):
1452	"""
1453	Completes the current test (pops it), logging PASSED / FAILURE.
1454
1455	Returns a tuple with the name of the test and its error count.
1456	"""
1457	g_oLock.acquire();
1458	rc = g_oReporter.testDone(fSkipped, utils.getCallerName());
1459	g_oLock.release();
1460	return rc;
1461
1462	def testErrorCount():
1463	"""
1464	Gets the error count of the current test.
1465
1466	Returns the number of errors.
1467	"""
1468	g_oLock.acquire();
1469	cErrors = g_oReporter.testErrorCount();
1470	g_oLock.release();
1471	return cErrors;
1472
1473	def testCleanup():
1474	"""
1475	Closes all open tests with a generic error condition.
1476
1477	Returns True if no open tests, False if something had to be closed with failure.
1478	"""
1479	g_oLock.acquire();
1480	fRc = g_oReporter.testCleanup(utils.getCallerName());
1481	g_oReporter.xmlFlush(fRetry = False, fForce = True);
1482	g_oLock.release();
1483	return fRc;
1484
1485
1486	#
1487	# Sub XML stuff.
1488	#
1489
1490	def addSubXmlFile(sFilename):
1491	"""
1492	Adds a sub-xml result file to the party.
1493	"""
1494	fRc = False;
1495	try:
1496	oSrcFile = utils.openNoInherit(sFilename, 'r');
1497	except IOError, oXcpt:
1498	if oXcpt.errno != errno.ENOENT:
1499	logXcpt('addSubXmlFile(%s)' % (sFilename,));
1500	except:
1501	logXcpt('addSubXmlFile(%s)' % (sFilename,));
1502	else:
1503	try:
1504	oWrapper = FileWrapperTestPipe()
1505	oWrapper.write(oSrcFile.read());
1506	oWrapper.close();
1507	except:
1508	logXcpt('addSubXmlFile(%s)' % (sFilename,));
1509	oSrcFile.close();
1510
1511	return fRc;
1512
1513
1514	#
1515	# Other useful debugging tools.
1516	#
1517
1518	def logAllStacks(cFrames = None):
1519	"""
1520	Logs the stacks of all python threads.
1521	"""
1522	sTsPrf = utils.getTimePrefix();
1523	sCaller = utils.getCallerName();
1524	g_oLock.acquire();
1525
1526	cThread = 0;
1527	for idThread, oStack in sys._current_frames().items(): # >=2.5, a bit ugly - pylint: disable=W0212
1528	try:
1529	if cThread > 0:
1530	g_oReporter.log(1, '', sCaller, sTsPrf);
1531	g_oReporter.log(1, 'Thread %s (%#x)' % (idThread, idThread), sCaller, sTsPrf);
1532	try:
1533	asInfo = traceback.format_stack(oStack, cFrames);
1534	except:
1535	g_oReporter.log(1, ' Stack formatting failed w/ exception', sCaller, sTsPrf);
1536	else:
1537	for sInfo in asInfo:
1538	asLines = sInfo.splitlines();
1539	for sLine in asLines:
1540	g_oReporter.log(1, sLine, sCaller, sTsPrf);
1541	except:
1542	pass;
1543	cThread += 1;
1544
1545	g_oLock.release();
1546	return None;
1547
1548	def checkTestManagerConnection():
1549	"""
1550	Checks the connection to the test manager.
1551
1552	Returns True if the connection is fine, False if not, None if not remote
1553	reporter.
1554
1555	Note! This as the sideeffect of flushing XML.
1556	"""
1557	g_oLock.acquire();
1558	fRc = g_oReporter.xmlFlush(fRetry = False, fForce = True);
1559	g_oLock.release();
1560	return fRc;
1561
1562	def flushall():
1563	"""
1564	Flushes all output streams, both standard and logger related.
1565	"""
1566	try: sys.stdout.flush();
1567	except: pass;
1568	try: sys.stderr.flush();
1569	except: pass;
1570
1571	# Note! Current no logger specific streams to flush.
1572
1573	return True;
1574
1575
1576	#
1577	# Module initialization.
1578	#
1579
1580	def _InitReporterModule():
1581	"""
1582	Instantiate the test reporter.
1583	"""
1584	global g_oReporter, g_sReporterName
1585
1586	g_sReporterName = os.getenv("TESTBOX_REPORTER", "local");
1587	if g_sReporterName == "local":
1588	g_oReporter = LocalReporter();
1589	elif g_sReporterName == "remote":
1590	g_oReporter = RemoteReporter(); # Correct, but still plain stupid. pylint: disable=redefined-variable-type
1591	else:
1592	print >> sys.stderr, os.path.basename(__file__) + ": Unknown TESTBOX_REPORTER value: '" + g_sReporterName + "'";
1593	raise Exception("Unknown TESTBOX_REPORTER value '" + g_sReporterName + "'");
1594
1595	if __name__ != "checker": # pychecker avoidance.
1596	_InitReporterModule();
1597

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

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

Download in other formats: