reporter.py@ 70615

最後變更在這個檔案從70615是 70611,由 vboxsync 提交於 7 年前
testdriver: More python 3 adjustments.
屬性 svn:eol-style 設為 `native` 屬性 svn:keywords 設為 `Author Date Id Revision`
檔案大小: 60.4 KB

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

注意: 瀏覽 TracBrowser 來幫助您使用儲存庫瀏覽器

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

以其他格式下載: