reporter.py@ 62099

Last change on this file since 62099 was 62099, checked in by vboxsync, 8 years ago
reporter.py: count polling as idle.
Property svn:eol-style set to `native` Property svn:keywords set to `Author Date Id Revision`
File size: 55.0 KB

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

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

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

Download in other formats: