virtual_test_sheriff.py@ 65440

Last change on this file since 65440 was 65318, checked in by vboxsync, 8 years ago
vsheriff: Check for install/uninstall problems with unittests too.
Property svn:eol-style set to `LF` Property svn:executable set to ``* Property svn:keywords set to `Author Date Id Revision`
File size: 55.7 KB

Line
1	#!/usr/bin/env python
2	# -- coding: utf-8 --
3	# $Id: virtual_test_sheriff.py 65318 2017-01-16 11:53:50Z vboxsync $
4	# pylint: disable=C0301
5
6	"""
7	Virtual Test Sheriff.
8
9	Duties:
10	- Try to a assign failure reasons to recently failed tests.
11	- Reboot or disable bad test boxes.
12
13	"""
14
15	__copyright__ = \
16	"""
17	Copyright (C) 2012-2016 Oracle Corporation
18
19	This file is part of VirtualBox Open Source Edition (OSE), as
20	available from http://www.virtualbox.org. This file is free software;
21	you can redistribute it and/or modify it under the terms of the GNU
22	General Public License (GPL) as published by the Free Software
23	Foundation, in version 2 as it comes in the "COPYING" file of the
24	VirtualBox OSE distribution. VirtualBox OSE is distributed in the
25	hope that it will be useful, but WITHOUT ANY WARRANTY of any kind.
26
27	The contents of this file may alternatively be used under the terms
28	of the Common Development and Distribution License Version 1.0
29	(CDDL) only, as it comes in the "COPYING.CDDL" file of the
30	VirtualBox OSE distribution, in which case the provisions of the
31	CDDL are applicable instead of those of the GPL.
32
33	You may elect to license modified versions of this file under the
34	terms and conditions of either the GPL or the CDDL or both.
35	"""
36	__version__ = "$Revision: 65318 $"
37
38
39	# Standard python imports
40	import sys;
41	import os;
42	import hashlib;
43	import StringIO;
44	from optparse import OptionParser;
45	from PIL import Image; # pylint: disable=import-error
46
47	# Add Test Manager's modules path
48	g_ksTestManagerDir = os.path.dirname(os.path.dirname(os.path.dirname(os.path.abspath(__file__))));
49	sys.path.append(g_ksTestManagerDir);
50
51	# Test Manager imports
52	from testmanager.core.db import TMDatabaseConnection;
53	from testmanager.core.build import BuildDataEx;
54	from testmanager.core.failurereason import FailureReasonLogic;
55	from testmanager.core.testbox import TestBoxLogic, TestBoxData;
56	from testmanager.core.testcase import TestCaseDataEx;
57	from testmanager.core.testgroup import TestGroupData;
58	from testmanager.core.testset import TestSetLogic, TestSetData;
59	from testmanager.core.testresults import TestResultLogic, TestResultFileData;
60	from testmanager.core.testresultfailures import TestResultFailureLogic, TestResultFailureData;
61	from testmanager.core.useraccount import UserAccountLogic;
62
63
64	class VirtualTestSheriffCaseFile(object):
65	"""
66	A failure investigation case file.
67
68	"""
69
70
71	## Max log file we'll read into memory. (256 MB)
72	kcbMaxLogRead = 0x10000000;
73
74	def __init__(self, oSheriff, oTestSet, oTree, oBuild, oTestBox, oTestGroup, oTestCase):
75	self.oSheriff = oSheriff;
76	self.oTestSet = oTestSet; # TestSetData
77	self.oTree = oTree; # TestResultDataEx
78	self.oBuild = oBuild; # BuildDataEx
79	self.oTestBox = oTestBox; # TestBoxData
80	self.oTestGroup = oTestGroup; # TestGroupData
81	self.oTestCase = oTestCase; # TestCaseDataEx
82	self.sMainLog = ''; # The main log file. Empty string if not accessible.
83
84	# Generate a case file name.
85	self.sName = '#%u: %s' % (self.oTestSet.idTestSet, self.oTestCase.sName,)
86	self.sLongName = '#%u: "%s" on "%s" running %s %s (%s), "%s" by %s, using %s %s %s r%u' \
87	% ( self.oTestSet.idTestSet,
88	self.oTestCase.sName,
89	self.oTestBox.sName,
90	self.oTestBox.sOs,
91	self.oTestBox.sOsVersion,
92	self.oTestBox.sCpuArch,
93	self.oTestBox.sCpuName,
94	self.oTestBox.sCpuVendor,
95	self.oBuild.oCat.sProduct,
96	self.oBuild.oCat.sBranch,
97	self.oBuild.oCat.sType,
98	self.oBuild.iRevision, );
99
100	# Investigation notes.
101	self.tReason = None; # None or one of the ktReason_XXX constants.
102	self.dReasonForResultId = {}; # Reason assignments indexed by idTestResult.
103	self.dCommentForResultId = {}; # Comment assignments indexed by idTestResult.
104
105	#
106	# Reason.
107	#
108
109	def noteReason(self, tReason):
110	""" Notes down a possible reason. """
111	self.oSheriff.dprint(u'noteReason: %s -> %s' % (self.tReason, tReason,));
112	self.tReason = tReason;
113	return True;
114
115	def noteReasonForId(self, tReason, idTestResult, sComment = None):
116	""" Notes down a possible reason for a specific test result. """
117	self.oSheriff.dprint(u'noteReasonForId: %u: %s -> %s%s'
118	% (idTestResult, self.dReasonForResultId.get(idTestResult, None), tReason,
119	(u' (%s)' % (sComment,)) if sComment is not None else ''));
120	self.dReasonForResultId[idTestResult] = tReason;
121	if sComment is not None:
122	self.dCommentForResultId[idTestResult] = sComment;
123	return True;
124
125
126	#
127	# Test classification.
128	#
129
130	def isVBoxTest(self):
131	""" Test classification: VirtualBox (using the build) """
132	return self.oBuild.oCat.sProduct.lower() in [ 'virtualbox', 'vbox' ];
133
134	def isVBoxUnitTest(self):
135	""" Test case classification: The unit test doing all our testcase/*.cpp stuff. """
136	return self.isVBoxTest() \
137	and self.oTestCase.sName.lower() == 'unit tests';
138
139	def isVBoxInstallTest(self):
140	""" Test case classification: VirtualBox Guest installation test. """
141	return self.isVBoxTest() \
142	and self.oTestCase.sName.lower().startswith('install:');
143
144	def isVBoxUSBTest(self):
145	""" Test case classification: VirtualBox USB test. """
146	return self.isVBoxTest() \
147	and self.oTestCase.sName.lower().startswith('usb:');
148
149	def isVBoxStorageTest(self):
150	""" Test case classification: VirtualBox Storage test. """
151	return self.isVBoxTest() \
152	and self.oTestCase.sName.lower().startswith('storage:');
153
154	def isVBoxGAsTest(self):
155	""" Test case classification: VirtualBox Guest Additions test. """
156	return self.isVBoxTest() \
157	and self.oTestCase.sName.lower().startswith('ga\'s tests');
158
159	def isVBoxAPITest(self):
160	""" Test case classification: VirtualBox API test. """
161	return self.isVBoxTest() \
162	and self.oTestCase.sName.lower().startswith('api:');
163
164	def isVBoxBenchmarkTest(self):
165	""" Test case classification: VirtualBox Benchmark test. """
166	return self.isVBoxTest() \
167	and self.oTestCase.sName.lower().startswith('benchmark:');
168
169	def isVBoxSmokeTest(self):
170	""" Test case classification: Smoke test. """
171	return self.isVBoxTest() \
172	and self.oTestCase.sName.lower().startswith('smoketest');
173
174
175	#
176	# Utility methods.
177	#
178
179	def getMainLog(self):
180	"""
181	Tries to reads the main log file since this will be the first source of information.
182	"""
183	if len(self.sMainLog) > 0:
184	return self.sMainLog;
185	(oFile, oSizeOrError, _) = self.oTestSet.openFile('main.log', 'rb');
186	if oFile is not None:
187	try:
188	self.sMainLog = oFile.read(min(self.kcbMaxLogRead, oSizeOrError)).decode('utf-8', 'replace');
189	except Exception as oXcpt:
190	self.oSheriff.vprint(u'Error reading main log file: %s' % (oXcpt,))
191	self.sMainLog = '';
192	else:
193	self.oSheriff.vprint(u'Error opening main log file: %s' % (oSizeOrError,));
194	return self.sMainLog;
195
196	def getLogFile(self, oFile):
197	"""
198	Tries to reads the given file as a utf-8 log file.
199	oFile is a TestFileDataEx instance.
200	Returns empty string if problems opening or reading the file.
201	"""
202	sContent = '';
203	(oFile, oSizeOrError, _) = self.oTestSet.openFile(oFile.sFile, 'rb');
204	if oFile is not None:
205	try:
206	sContent = oFile.read(min(self.kcbMaxLogRead, oSizeOrError)).decode('utf-8', 'replace');
207	except Exception as oXcpt:
208	self.oSheriff.vprint(u'Error reading the "%s" log file: %s' % (oFile.sFile, oXcpt,))
209	else:
210	self.oSheriff.vprint(u'Error opening the "%s" log file: %s' % (oFile.sFile, oSizeOrError,));
211	return sContent;
212
213	def getScreenshotSha256(self, oFile):
214	"""
215	Tries to read the given screenshot file, uncompress it, and do SHA-2
216	on the raw pixels.
217	Returns SHA-2 digest string on success, None on failure.
218	"""
219	(oFile, _, _) = self.oTestSet.openFile(oFile.sFile, 'rb');
220	try:
221	abImageFile = oFile.read();
222	except Exception as oXcpt:
223	self.oSheriff.vprint(u'Error reading the "%s" image file: %s' % (oFile.sFile, oXcpt,))
224	else:
225	try:
226	oImage = Image.open(StringIO.StringIO(abImageFile));
227	except Exception as oXcpt:
228	self.oSheriff.vprint(u'Error opening the "%s" image bytes using PIL.Image.open: %s' % (oFile.sFile, oXcpt,))
229	else:
230	try:
231	oHash = hashlib.sha256();
232	oHash.update(oImage.tostring());
233	except Exception as oXcpt:
234	self.oSheriff.vprint(u'Error hashing the uncompressed image bytes for "%s": %s' % (oFile.sFile, oXcpt,))
235	else:
236	return oHash.hexdigest();
237	return None;
238
239
240
241	def isSingleTestFailure(self):
242	"""
243	Figure out if this is a single test failing or if it's one of the
244	more complicated ones.
245	"""
246	if self.oTree.cErrors == 1:
247	return True;
248	if self.oTree.deepCountErrorContributers() <= 1:
249	return True;
250	return False;
251
252
253
254	class VirtualTestSheriff(object): # pylint: disable=R0903
255	"""
256	Add build info into Test Manager database.
257	"""
258
259	## The user account for the virtual sheriff.
260	ksLoginName = 'vsheriff';
261
262	def __init__(self):
263	"""
264	Parse command line.
265	"""
266	self.oDb = None;
267	self.tsNow = None;
268	self.oTestResultLogic = None;
269	self.oTestSetLogic = None;
270	self.oFailureReasonLogic = None; # FailureReasonLogic;
271	self.oTestResultFailureLogic = None; # TestResultFailureLogic
272	self.oLogin = None;
273	self.uidSelf = -1;
274	self.oLogFile = None;
275	self.asBsodReasons = [];
276	self.asUnitTestReasons = [];
277
278	oParser = OptionParser();
279	oParser.add_option('--start-hours-ago', dest = 'cStartHoursAgo', metavar = '<hours>', default = 0, type = 'int',
280	help = 'When to start specified as hours relative to current time. Defauls is right now.', );
281	oParser.add_option('--hours-period', dest = 'cHoursBack', metavar = '<period-in-hours>', default = 2, type = 'int',
282	help = 'Work period specified in hours. Defauls is 2 hours.');
283	oParser.add_option('--real-run-back', dest = 'fRealRun', action = 'store_true', default = False,
284	help = 'Whether to commit the findings to the database. Default is a dry run.');
285	oParser.add_option('-q', '--quiet', dest = 'fQuiet', action = 'store_true', default = False,
286	help = 'Quiet execution');
287	oParser.add_option('-l', '--log', dest = 'sLogFile', metavar = '<logfile>', default = None,
288	help = 'Where to log messages.');
289	oParser.add_option('--debug', dest = 'fDebug', action = 'store_true', default = False,
290	help = 'Enables debug mode.');
291
292	(self.oConfig, _) = oParser.parse_args();
293
294	if self.oConfig.sLogFile is not None and len(self.oConfig.sLogFile) > 0:
295	self.oLogFile = open(self.oConfig.sLogFile, "a");
296	self.oLogFile.write('VirtualTestSheriff: $Revision: 65318 $ \n');
297
298
299	def eprint(self, sText):
300	"""
301	Prints error messages.
302	Returns 1 (for exit code usage.)
303	"""
304	print 'error: %s' % (sText,);
305	if self.oLogFile is not None:
306	self.oLogFile.write((u'error: %s\n' % (sText,)).encode('utf-8'));
307	return 1;
308
309	def dprint(self, sText):
310	"""
311	Prints debug info.
312	"""
313	if self.oConfig.fDebug:
314	if not self.oConfig.fQuiet:
315	print 'debug: %s' % (sText, );
316	if self.oLogFile is not None:
317	self.oLogFile.write((u'debug: %s\n' % (sText,)).encode('utf-8'));
318	return 0;
319
320	def vprint(self, sText):
321	"""
322	Prints verbose info.
323	"""
324	if not self.oConfig.fQuiet:
325	print 'info: %s' % (sText,);
326	if self.oLogFile is not None:
327	self.oLogFile.write((u'info: %s\n' % (sText,)).encode('utf-8'));
328	return 0;
329
330	def getFailureReason(self, tReason):
331	""" Gets the failure reason object for tReason. """
332	return self.oFailureReasonLogic.cachedLookupByNameAndCategory(tReason[1], tReason[0]);
333
334	def selfCheck(self):
335	""" Does some self checks, looking up things we expect to be in the database and such. """
336	rcExit = 0;
337	for sAttr in dir(self.__class__):
338	if sAttr.startswith('ktReason_'):
339	tReason = getattr(self.__class__, sAttr);
340	oFailureReason = self.getFailureReason(tReason);
341	if oFailureReason is None:
342	rcExit = self.eprint(u'Failed to find failure reason "%s" in category "%s" in the database!'
343	% (tReason[1], tReason[0],));
344
345	# Check the user account as well.
346	if self.oLogin is None:
347	oLogin = UserAccountLogic(self.oDb).tryFetchAccountByLoginName(VirtualTestSheriff.ksLoginName);
348	if oLogin is None:
349	rcExit = self.eprint(u'Cannot find my user account "%s"!' % (VirtualTestSheriff.ksLoginName,));
350	return rcExit;
351
352
353
354	def badTestBoxManagement(self):
355	"""
356	Looks for bad test boxes and first tries once to reboot them then disables them.
357	"""
358	rcExit = 0;
359
360	#
361	# We skip this entirely if we're running in the past and not in harmless debug mode.
362	#
363	if self.oConfig.cStartHoursAgo != 0 \
364	and (not self.oConfig.fDebug or self.oConfig.fRealRun):
365	return rcExit;
366	tsNow = self.tsNow if self.oConfig.fDebug else None;
367	cHoursBack = self.oConfig.cHoursBack if self.oConfig.fDebug else 2;
368	oTestBoxLogic = TestBoxLogic(self.oDb);
369
370	#
371	# Generate a list of failures reasons we consider bad-testbox behavior.
372	#
373	aidFailureReasons = [
374	self.getFailureReason(self.ktReason_Host_DriverNotUnloading).idFailureReason,
375	];
376
377	#
378	# Get list of bad test boxes for given period and check them out individually.
379	#
380	aidBadTestBoxes = self.oTestSetLogic.fetchBadTestBoxIds(cHoursBack = cHoursBack, tsNow = tsNow,
381	aidFailureReasons = aidFailureReasons);
382	for idTestBox in aidBadTestBoxes:
383	# Skip if the testbox is already disabled or has a pending reboot command.
384	try:
385	oTestBox = TestBoxData().initFromDbWithId(self.oDb, idTestBox);
386	except Exception as oXcpt:
387	rcExit = self.eprint('Failed to get data for test box #%u in badTestBoxManagement: %s' % (idTestBox, oXcpt,));
388	continue;
389	if not oTestBox.fEnabled:
390	self.dprint(u'badTestBoxManagement: Skipping test box #%u (%s) as it has been disabled already.'
391	% ( idTestBox, oTestBox.sName, ));
392	continue;
393	if oTestBox.enmPendingCmd != TestBoxData.ksTestBoxCmd_None:
394	self.dprint(u'badTestBoxManagement: Skipping test box #%u (%s) as it has a command pending: %s'
395	% ( idTestBox, oTestBox.sName, oTestBox.enmPendingCmd));
396	continue;
397
398	# Get the most recent testsets for this box (descending on tsDone) and see how bad it is.
399	aoSets = self.oTestSetLogic.fetchSetsForTestBox(idTestBox, cHoursBack = cHoursBack, tsNow = tsNow);
400	cOkay = 0;
401	cBad = 0;
402	iFirstOkay = len(aoSets);
403	for iSet, oSet in enumerate(aoSets):
404	if oSet.enmStatus == TestSetData.ksTestStatus_BadTestBox:
405	cBad += 1;
406	else:
407	# Check for bad failure reasons.
408	oFailure = None;
409	if oSet.enmStatus in TestSetData.kasBadTestStatuses:
410	oFailure = self.oTestResultFailureLogic.getById(oSet.idTestResult);
411	if oFailure is not None and oFailure.idFailureReason in aidFailureReasons:
412	cBad += 1;
413	else:
414	# This is an okay test result then.
415	## @todo maybe check the elapsed time here, it could still be a bad run?
416	cOkay += 1;
417	if iFirstOkay > iSet:
418	iFirstOkay = iSet;
419	if iSet > 10:
420	break;
421
422	# We react if there are two or more bad-testbox statuses at the head of the
423	# history and at least three in the last 10 results.
424	if iFirstOkay >= 2 and cBad > 2:
425	if oTestBoxLogic.hasTestBoxRecentlyBeenRebooted(idTestBox, cHoursBack = cHoursBack, tsNow = tsNow):
426	self.vprint(u'Disabling testbox #%u (%s) - iFirstOkay=%u cBad=%u cOkay=%u'
427	% ( idTestBox, oTestBox.sName, iFirstOkay, cBad, cOkay));
428	if self.oConfig.fRealRun is True:
429	try:
430	oTestBoxLogic.disableTestBox(idTestBox, self.uidSelf, fCommit = True,
431	sComment = 'Automatically disabled (iFirstOkay=%u cBad=%u cOkay=%u)'
432	% (iFirstOkay, cBad, cOkay),);
433	except Exception as oXcpt:
434	rcExit = self.eprint(u'Error disabling testbox #%u (%u): %s\n' % (idTestBox, oTestBox.sName, oXcpt,));
435	else:
436	self.vprint(u'Rebooting testbox #%u (%s) - iFirstOkay=%u cBad=%u cOkay=%u'
437	% ( idTestBox, oTestBox.sName, iFirstOkay, cBad, cOkay));
438	if self.oConfig.fRealRun is True:
439	try:
440	oTestBoxLogic.rebootTestBox(idTestBox, self.uidSelf, fCommit = True,
441	sComment = 'Automatically rebooted (iFirstOkay=%u cBad=%u cOkay=%u)'
442	% (iFirstOkay, cBad, cOkay),);
443	except Exception as oXcpt:
444	rcExit = self.eprint(u'Error rebooting testbox #%u (%u): %s\n' % (idTestBox, oTestBox.sName, oXcpt,));
445	else:
446	self.dprint(u'badTestBoxManagement: #%u (%s) looks ok: iFirstOkay=%u cBad=%u cOkay=%u'
447	% ( idTestBox, oTestBox.sName, iFirstOkay, cBad, cOkay));
448	return rcExit;
449
450
451	## @name Failure reasons we know.
452	## @{
453	ktReason_BSOD_Recovery = ( 'BSOD', 'Recovery' );
454	ktReason_BSOD_Automatic_Repair = ( 'BSOD', 'Automatic Repair' );
455	ktReason_BSOD_C0000225 = ( 'BSOD', '0xC0000225 (boot)' );
456	ktReason_Guru_Generic = ( 'Guru Meditations', 'Generic Guru Meditation' );
457	ktReason_Guru_VERR_IEM_INSTR_NOT_IMPLEMENTED = ( 'Guru Meditations', 'VERR_IEM_INSTR_NOT_IMPLEMENTED' );
458	ktReason_Guru_VERR_IEM_ASPECT_NOT_IMPLEMENTED = ( 'Guru Meditations', 'VERR_IEM_ASPECT_NOT_IMPLEMENTED' );
459	ktReason_Guru_VERR_TRPM_DONT_PANIC = ( 'Guru Meditations', 'VERR_TRPM_DONT_PANIC' );
460	ktReason_Guru_VERR_PGM_PHYS_PAGE_RESERVED = ( 'Guru Meditations', 'VERR_PGM_PHYS_PAGE_RESERVED' );
461	ktReason_Guru_VERR_VMX_INVALID_GUEST_STATE = ( 'Guru Meditations', 'VERR_VMX_INVALID_GUEST_STATE' );
462	ktReason_Guru_VINF_EM_TRIPLE_FAULT = ( 'Guru Meditations', 'VINF_EM_TRIPLE_FAULT' );
463	ktReason_Host_HostMemoryLow = ( 'Host', 'HostMemoryLow' );
464	ktReason_Host_DriverNotLoaded = ( 'Host', 'Driver not loaded' );
465	ktReason_Host_DriverNotUnloading = ( 'Host', 'Driver not unloading' );
466	ktReason_Host_NotSignedWithBuildCert = ( 'Host', 'Not signed with build cert' );
467	ktReason_Host_Reboot_OSX_Watchdog_Timeout = ( 'Host Reboot', 'OSX Watchdog Timeout' );
468	ktReason_Networking_Nonexistent_host_nic = ( 'Networking', 'Nonexistent host networking interface' );
469	ktReason_OSInstall_GRUB_hang = ( 'O/S Install', 'GRUB hang' );
470	ktReason_Panic_MP_BIOS_IO_APIC = ( 'Panic', 'MP-BIOS/IO-APIC' );
471	ktReason_XPCOM_Exit_Minus_11 = ( 'API / (XP)COM', 'exit -11' );
472	ktReason_XPCOM_VBoxSVC_Hang = ( 'API / (XP)COM', 'VBoxSVC hang' );
473	ktReason_XPCOM_VBoxSVC_Hang_Plus_Heap_Corruption = ( 'API / (XP)COM', 'VBoxSVC hang + heap corruption' );
474	ktReason_XPCOM_NS_ERROR_CALL_FAILED = ( 'API / (XP)COM', 'NS_ERROR_CALL_FAILED' );
475	ktReason_Unknown_Heap_Corruption = ( 'Unknown', 'Heap corruption' );
476	ktReason_Unknown_Reboot_Loop = ( 'Unknown', 'Reboot loop' );
477	ktReason_Unknown_File_Not_Found = ( 'Unknown', 'File not found' );
478	ktReason_Ignore_Buggy_Test_Driver = ( 'Ignore', 'Buggy test driver' );
479	ktReason_Ignore_Stale_Files = ( 'Ignore', 'Stale files' );
480	ktReason_Buggy_Build_Broken_Build = ( 'Broken Build', 'Buggy build' );
481	## @}
482
483	## BSOD category.
484	ksBsodCategory = 'BSOD';
485	## Special reason indicating that the flesh and blood sheriff has work to do.
486	ksBsodAddNew = 'Add new BSOD';
487
488	## Unit test category.
489	ksUnitTestCategory = 'Unit';
490	## Special reason indicating that the flesh and blood sheriff has work to do.
491	ksUnitTestAddNew = 'Add new';
492
493	## Used for indica that we shouldn't report anything for this test result ID and
494	## consider promoting the previous error to test set level if it's the only one.
495	ktHarmless = ( 'Probably', 'Caused by previous error' );
496
497
498	def caseClosed(self, oCaseFile):
499	"""
500	Reports the findings in the case and closes it.
501	"""
502	#
503	# Log it and create a dReasonForReasultId we can use below.
504	#
505	dCommentForResultId = oCaseFile.dCommentForResultId;
506	if len(oCaseFile.dReasonForResultId) > 0:
507	# Must weed out ktHarmless.
508	dReasonForResultId = {};
509	for idKey, tReason in oCaseFile.dReasonForResultId.items():
510	if tReason is not self.ktHarmless:
511	dReasonForResultId[idKey] = tReason;
512	if len(dReasonForResultId) == 0:
513	self.vprint(u'TODO: Closing %s without a real reason, only %s.'
514	% (oCaseFile.sName, oCaseFile.dReasonForResultId));
515	return False;
516
517	# Try promote to single reason.
518	atValues = dReasonForResultId.values();
519	fSingleReason = True;
520	if len(dReasonForResultId) == 1 and dReasonForResultId.keys()[0] != oCaseFile.oTestSet.idTestResult:
521	self.dprint(u'Promoting single reason to whole set: %s' % (atValues[0],));
522	elif len(dReasonForResultId) > 1 and len(atValues) == atValues.count(atValues[0]):
523	self.dprint(u'Merged %d reasons to a single one: %s' % (len(atValues), atValues[0]));
524	else:
525	fSingleReason = False;
526	if fSingleReason:
527	dReasonForResultId = { oCaseFile.oTestSet.idTestResult: atValues[0], };
528	if len(dCommentForResultId) > 0:
529	dCommentForResultId = { oCaseFile.oTestSet.idTestResult: dCommentForResultId.values()[0], };
530	elif oCaseFile.tReason is not None:
531	dReasonForResultId = { oCaseFile.oTestSet.idTestResult: oCaseFile.tReason, };
532	else:
533	self.vprint(u'Closing %s without a reason - this should not happen!' % (oCaseFile.sName,));
534	return False;
535
536	self.vprint(u'Closing %s with following reason%s: %s'
537	% ( oCaseFile.sName, 's' if dReasonForResultId > 0 else '', dReasonForResultId, ));
538
539	#
540	# Add the test failure reason record(s).
541	#
542	for idTestResult, tReason in dReasonForResultId.items():
543	oFailureReason = self.getFailureReason(tReason);
544	if oFailureReason is not None:
545	sComment = 'Set by $Revision: 65318 $' # Handy for reverting later.
546	if idTestResult in dCommentForResultId:
547	sComment += ': ' + dCommentForResultId[idTestResult];
548
549	oAdd = TestResultFailureData();
550	oAdd.initFromValues(idTestResult = idTestResult,
551	idFailureReason = oFailureReason.idFailureReason,
552	uidAuthor = self.uidSelf,
553	idTestSet = oCaseFile.oTestSet.idTestSet,
554	sComment = sComment,);
555	if self.oConfig.fRealRun:
556	try:
557	self.oTestResultFailureLogic.addEntry(oAdd, self.uidSelf, fCommit = True);
558	except Exception as oXcpt:
559	self.eprint(u'caseClosed: Exception "%s" while adding reason %s for %s'
560	% (oXcpt, oAdd, oCaseFile.sLongName,));
561	else:
562	self.eprint(u'caseClosed: Cannot locate failure reason: %s / %s' % ( tReason[0], tReason[1],));
563	return True;
564
565	#
566	# Tools for assiting log parsing.
567	#
568
569	@staticmethod
570	def matchFollowedByLines(sStr, off, asFollowingLines):
571	""" Worker for isThisFollowedByTheseLines. """
572
573	# Advance off to the end of the line.
574	off = sStr.find('\n', off);
575	if off < 0:
576	return False;
577	off += 1;
578
579	# Match each string with the subsequent lines.
580	for iLine, sLine in enumerate(asFollowingLines):
581	offEnd = sStr.find('\n', off);
582	if offEnd < 0:
583	return iLine + 1 == len(asFollowingLines) and sStr.find(sLine, off) < 0;
584	if len(sLine) > 0 and sStr.find(sLine, off, offEnd) < 0:
585	return False;
586
587	# next line.
588	off = offEnd + 1;
589
590	return True;
591
592	@staticmethod
593	def isThisFollowedByTheseLines(sStr, sFirst, asFollowingLines):
594	"""
595	Looks for a line contining sFirst which is then followed by lines
596	with the strings in asFollowingLines. (No newline chars anywhere!)
597	Returns True / False.
598	"""
599	off = sStr.find(sFirst, 0);
600	while off >= 0:
601	if VirtualTestSheriff.matchFollowedByLines(sStr, off, asFollowingLines):
602	return True;
603	off = sStr.find(sFirst, off + 1);
604	return False;
605
606	@staticmethod
607	def findAndReturnResetOfLine(sHaystack, sNeedle):
608	"""
609	Looks for sNeedle in sHaystack.
610	Returns The text following the needle up to the end of the line.
611	Returns None if not found.
612	"""
613	if sHaystack is None:
614	return None;
615	off = sHaystack.find(sNeedle);
616	if off < 0:
617	return None;
618	off += len(sNeedle)
619	offEol = sHaystack.find('\n', off);
620	if offEol < 0:
621	offEol = len(sHaystack);
622	return sHaystack[off:offEol]
623
624	@staticmethod
625	def findInAnyAndReturnResetOfLine(asHaystacks, sNeedle):
626	"""
627	Looks for sNeedle in zeroe or more haystacks (asHaystack).
628	Returns The text following the first needed found up to the end of the line.
629	Returns None if not found.
630	"""
631	for sHaystack in asHaystacks:
632	sRet = VirtualTestSheriff.findAndReturnResetOfLine(sHaystack, sNeedle);
633	if sRet is not None:
634	return sRet;
635	return None;
636
637
638	#
639	# The investigative units.
640	#
641
642	katSimpleInstallUninstallMainLogReasons = [
643	# ( Whether to stop on hit, reason tuple, needle text. )
644	];
645
646	kdatSimpleInstallUninstallMainLogReasonsPerOs = {
647	'darwin': [
648	# ( Whether to stop on hit, reason tuple, needle text. )
649	( True, ktReason_Host_DriverNotUnloading,
650	'Can\'t remove kext org.virtualbox.kext.VBoxDrv; services failed to terminate - 0xe00002c7' ),
651	],
652	};
653
654
655	def investigateInstallUninstallFailure(self, oCaseFile, oFailedResult, sResultLog, fInstall):
656	"""
657	Investigates an install or uninstall failure.
658
659	We lump the two together since the installation typically also performs
660	an uninstall first and will be seeing similar issues to the uninstall.
661	"""
662	_ = fInstall;
663
664	atSimple = self.katSimpleInstallUninstallMainLogReasons;
665	if oCaseFile.oTestBox.sOs in self.kdatSimpleInstallUninstallMainLogReasonsPerOs:
666	atSimple = self.kdatSimpleInstallUninstallMainLogReasonsPerOs[oCaseFile.oTestBox.sOs] + atSimple;
667
668	fFoundSomething = False;
669	for fStopOnHit, tReason, sNeedle in atSimple:
670	if sResultLog.find(sNeedle) > 0:
671	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
672	if fStopOnHit:
673	return True;
674	fFoundSomething = True;
675
676	return fFoundSomething if fFoundSomething else None;
677
678
679	def investigateBadTestBox(self, oCaseFile):
680	"""
681	Checks out bad-testbox statuses.
682	"""
683	_ = oCaseFile;
684	return False;
685
686
687	def investigateVBoxUnitTest(self, oCaseFile):
688	"""
689	Checks out a VBox unittest problem.
690	"""
691
692	#
693	# Process simple test case failures first, using their name as reason.
694	# We do the reason management just like for BSODs.
695	#
696	cRelevantOnes = 0;
697	sMainLog = oCaseFile.getMainLog();
698	aoFailedResults = oCaseFile.oTree.getListOfFailures();
699	for oFailedResult in aoFailedResults:
700	if oFailedResult is oCaseFile.oTree:
701	self.vprint('TODO: toplevel failure');
702	cRelevantOnes += 1
703
704	elif oFailedResult.sName == 'Installing VirtualBox':
705	sResultLog = TestSetData.extractLogSectionElapsed(sMainLog, oFailedResult.tsCreated, oFailedResult.tsElapsed);
706	self.investigateInstallUninstallFailure(oCaseFile, oFailedResult, sResultLog, fInstall = True)
707	cRelevantOnes += 1
708
709	elif oFailedResult.sName == 'Uninstalling VirtualBox':
710	sResultLog = TestSetData.extractLogSectionElapsed(sMainLog, oFailedResult.tsCreated, oFailedResult.tsElapsed);
711	self.investigateInstallUninstallFailure(oCaseFile, oFailedResult, sResultLog, fInstall = False)
712	cRelevantOnes += 1
713
714	elif oFailedResult.oParent is not None:
715	# Get the 2nd level node because that's where we'll find the unit test name.
716	while oFailedResult.oParent.oParent is not None:
717	oFailedResult = oFailedResult.oParent;
718
719	# Only report a failure once.
720	if oFailedResult.idTestResult not in oCaseFile.dReasonForResultId:
721	sKey = oFailedResult.sName;
722	if sKey.startswith('testcase/'):
723	sKey = sKey[9:];
724	if sKey in self.asUnitTestReasons:
725	tReason = ( self.ksUnitTestCategory, sKey );
726	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
727	else:
728	self.dprint(u'Unit test failure "%s" not found in %s;' % (sKey, self.asUnitTestReasons));
729	tReason = ( self.ksUnitTestCategory, self.ksUnitTestAddNew );
730	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult, sComment = sKey);
731	cRelevantOnes += 1
732	else:
733	self.vprint(u'Internal error: expected oParent to NOT be None for %s' % (oFailedResult,));
734
735	#
736	# If we've caught all the relevant ones by now, report the result.
737	#
738	if len(oCaseFile.dReasonForResultId) >= cRelevantOnes:
739	return self.caseClosed(oCaseFile);
740	return False;
741
742
743	## Things we search a main or VM log for to figure out why something went bust.
744	katSimpleMainAndVmLogReasons = [
745	# ( Whether to stop on hit, reason tuple, needle text. )
746	( False, ktReason_Guru_Generic, 'GuruMeditation' ),
747	( False, ktReason_Guru_Generic, 'Guru Meditation' ),
748	( True, ktReason_Guru_VERR_IEM_INSTR_NOT_IMPLEMENTED, 'VERR_IEM_INSTR_NOT_IMPLEMENTED' ),
749	( True, ktReason_Guru_VERR_IEM_ASPECT_NOT_IMPLEMENTED, 'VERR_IEM_ASPECT_NOT_IMPLEMENTED' ),
750	( True, ktReason_Guru_VERR_TRPM_DONT_PANIC, 'VERR_TRPM_DONT_PANIC' ),
751	( True, ktReason_Guru_VERR_PGM_PHYS_PAGE_RESERVED, 'VERR_PGM_PHYS_PAGE_RESERVED' ),
752	( True, ktReason_Guru_VERR_VMX_INVALID_GUEST_STATE, 'VERR_VMX_INVALID_GUEST_STATE' ),
753	( True, ktReason_Guru_VINF_EM_TRIPLE_FAULT, 'VINF_EM_TRIPLE_FAULT' ),
754	( True, ktReason_Networking_Nonexistent_host_nic,
755	'rc=E_FAIL text="Nonexistent host networking interface, name \'eth0\' (VERR_INTERNAL_ERROR)"' ),
756	( True, ktReason_Host_Reboot_OSX_Watchdog_Timeout, ': "OSX Watchdog Timeout: ' ),
757	( False, ktReason_XPCOM_NS_ERROR_CALL_FAILED,
758	'Exception: 0x800706be (Call to remote object failed (NS_ERROR_CALL_FAILED))' ),
759	( True, ktReason_Host_HostMemoryLow, 'HostMemoryLow' ),
760	( True, ktReason_Host_HostMemoryLow, 'Failed to procure handy pages; rc=VERR_NO_MEMORY' ),
761	( True, ktReason_Unknown_File_Not_Found,
762	'Error: failed to start machine. Error message: File not found. (VERR_FILE_NOT_FOUND)' ),
763	( True, ktReason_Unknown_File_Not_Found, # lump it in with file-not-found for now.
764	'Error: failed to start machine. Error message: Not supported. (VERR_NOT_SUPPORTED)' ),
765	];
766
767	## Things we search a VBoxHardening.log file for to figure out why something went bust.
768	katSimpleVBoxHardeningLogReasons = [
769	# ( Whether to stop on hit, reason tuple, needle text. )
770	( True, ktReason_Host_DriverNotLoaded, 'Error opening VBoxDrvStub: STATUS_OBJECT_NAME_NOT_FOUND' ),
771	( True, ktReason_Host_NotSignedWithBuildCert, 'Not signed with the build certificate' ),
772	];
773
774
775	## Things we search the _RIGHT_ _STRIPPED_ vgatext for.
776	katSimpleVgaTextReasons = [
777	# ( Whether to stop on hit, reason tuple, needle text. )
778	( True, ktReason_Panic_MP_BIOS_IO_APIC,
779	"..MP-BIOS bug: 8254 timer not connected to IO-APIC\n\n" ),
780	( True, ktReason_Panic_MP_BIOS_IO_APIC,
781	"..MP-BIOS bug: 8254 timer not connected to IO-APIC\n"
782	"...trying to set up timer (IRQ0) through the 8259A ... failed.\n"
783	"...trying to set up timer as Virtual Wire IRQ... failed.\n"
784	"...trying to set up timer as ExtINT IRQ... failed :(.\n"
785	"Kernel panic - not syncing: IO-APIC + timer doesn't work! Boot with apic=debug\n"
786	"and send a report. Then try booting with the 'noapic' option\n"
787	"\n" ),
788	( True, ktReason_OSInstall_GRUB_hang,
789	"-----\nGRUB Loading stage2..\n\n\n\n" ),
790	];
791
792	## Mapping screenshot/failure SHA-256 hashes to failure reasons.
793	katSimpleScreenshotHashReasons = [
794	# ( Whether to stop on hit, reason tuple, lowercased sha-256 of PIL.Image.tostring output )
795	( True, ktReason_BSOD_Recovery, '576f8e38d62b311cac7e3dc3436a0d0b9bd8cfd7fa9c43aafa95631520a45eac' ),
796	( True, ktReason_BSOD_Automatic_Repair, 'c6a72076cc619937a7a39cfe9915b36d94cee0d4e3ce5ce061485792dcee2749' ),
797	( True, ktReason_BSOD_Automatic_Repair, '26c4d8a724ff2c5e1051f3d5b650dbda7b5fdee0aa3e3c6059797f7484a515df' ),
798	( True, ktReason_BSOD_C0000225, 'bd13a144be9dcdfb16bc863ff4c8f02a86e263c174f2cd5ffd27ca5f3aa31789' ),
799	( True, ktReason_BSOD_C0000225, '8348b465e7ee9e59dd4e785880c57fd8677de05d11ac21e786bfde935307b42f' ),
800	( True, ktReason_BSOD_C0000225, '1316e1fc818a73348412788e6910b8c016f237d8b4e15b20caf4a866f7a7840e' ),
801	( True, ktReason_BSOD_C0000225, '54e0acbff365ce20a85abbe42bcd53647b8b9e80c68e45b2cd30e86bf177a0b5' ),
802	( True, ktReason_BSOD_C0000225, '50fec50b5199923fa48b3f3e782687cc381e1c8a788ebda14e6a355fbe3bb1b3' ),
803	];
804
805	def investigateVMResult(self, oCaseFile, oFailedResult, sResultLog):
806	"""
807	Investigates a failed VM run.
808	"""
809
810	def investigateLogSet():
811	"""
812	Investigates the current set of VM related logs.
813	"""
814	self.dprint('investigateLogSet: lengths: result log %u, VM log %u, kernel log %u, vga text %u, info text %u'
815	% ( len(sResultLog) if sResultLog is not None else 0,
816	len(sVMLog) if sVMLog is not None else 0,
817	len(sKrnlLog) if sKrnlLog is not None else 0,
818	len(sVgaText) if sVgaText is not None else 0,
819	len(sInfoText) if sInfoText is not None else 0, ));
820
821	#self.dprint(u'main.log<<<\n%s\n<<<\n' % (sResultLog,));
822	#self.dprint(u'vbox.log<<<\n%s\n<<<\n' % (sVMLog,));
823	#self.dprint(u'krnl.log<<<\n%s\n<<<\n' % (sKrnlLog,));
824	#self.dprint(u'vgatext.txt<<<\n%s\n<<<\n' % (sVgaText,));
825	#self.dprint(u'info.txt<<<\n%s\n<<<\n' % (sInfoText,));
826
827	# TODO: more
828
829	#
830	# Look for BSODs. Some stupid stupid inconsistencies in reason and log messages here, so don't try prettify this.
831	#
832	sDetails = self.findInAnyAndReturnResetOfLine([ sVMLog, sResultLog ],
833	'GIM: HyperV: Guest indicates a fatal condition! P0=');
834	if sDetails is not None:
835	# P0=%#RX64 P1=%#RX64 P2=%#RX64 P3=%#RX64 P4=%#RX64 "
836	sKey = sDetails.split(' ', 1)[0];
837	try: sKey = '0x%08X' % (int(sKey, 16),);
838	except: pass;
839	if sKey in self.asBsodReasons:
840	tReason = ( self.ksBsodCategory, sKey );
841	elif sKey.lower() in self.asBsodReasons: # just in case.
842	tReason = ( self.ksBsodCategory, sKey.lower() );
843	else:
844	self.dprint(u'BSOD "%s" not found in %s;' % (sKey, self.asBsodReasons));
845	tReason = ( self.ksBsodCategory, self.ksBsodAddNew );
846	return oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult, sComment = sDetails.strip());
847
848	#
849	# Look for linux panic.
850	#
851	if sKrnlLog is not None:
852	pass; ## @todo
853
854	#
855	# Loop thru the simple stuff.
856	#
857	fFoundSomething = False;
858	for fStopOnHit, tReason, sNeedle in self.katSimpleMainAndVmLogReasons:
859	if sResultLog.find(sNeedle) > 0 or (sVMLog is not None and sVMLog.find(sNeedle) > 0):
860	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
861	if fStopOnHit:
862	return True;
863	fFoundSomething = True;
864
865	# Continue with vga text.
866	if sVgaText is not None and len(sVgaText) > 0:
867	for fStopOnHit, tReason, sNeedle in self.katSimpleVgaTextReasons:
868	if sVgaText.find(sNeedle) > 0:
869	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
870	if fStopOnHit:
871	return True;
872	fFoundSomething = True;
873	_ = sInfoText;
874
875	# Continue with screen hashes.
876	if sScreenHash is not None:
877	for fStopOnHit, tReason, sHash in self.katSimpleScreenshotHashReasons:
878	if sScreenHash == sHash:
879	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
880	if fStopOnHit:
881	return True;
882	fFoundSomething = True;
883
884	# Check VBoxHardening.log.
885	if sNtHardLog is not None:
886	for fStopOnHit, tReason, sNeedle in self.katSimpleVBoxHardeningLogReasons:
887	if sNtHardLog.find(sNeedle) > 0:
888	oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
889	if fStopOnHit:
890	return True;
891	fFoundSomething = True;
892
893	#
894	# Check for repeated reboots...
895	#
896	if sVMLog is not None:
897	cResets = sVMLog.count('Changing the VM state from \'RUNNING\' to \'RESETTING\'');
898	if cResets > 10:
899	return oCaseFile.noteReasonForId(self.ktReason_Unknown_Reboot_Loop, oFailedResult.idTestResult,
900	sComment = 'Counted %s reboots' % (cResets,));
901
902	return fFoundSomething;
903
904	#
905	# Check if we got any VM or/and kernel logs. Treat them as sets in
906	# case we run multiple VMs here (this is of course ASSUMING they
907	# appear in the order that terminateVmBySession uploads them).
908	#
909	cTimes = 0;
910	sVMLog = None;
911	sNtHardLog = None;
912	sScreenHash = None;
913	sKrnlLog = None;
914	sVgaText = None;
915	sInfoText = None;
916	for oFile in oFailedResult.aoFiles:
917	if oFile.sKind == TestResultFileData.ksKind_LogReleaseVm:
918	if 'VBoxHardening.log' not in oFile.sFile:
919	if sVMLog is not None:
920	if investigateLogSet() is True:
921	return True;
922	cTimes += 1;
923	sInfoText = None;
924	sVgaText = None;
925	sKrnlLog = None;
926	sScreenHash = None;
927	sNtHardLog = None;
928	sVMLog = oCaseFile.getLogFile(oFile);
929	else:
930	sNtHardLog = oCaseFile.getLogFile(oFile);
931	elif oFile.sKind == TestResultFileData.ksKind_LogGuestKernel:
932	sKrnlLog = oCaseFile.getLogFile(oFile);
933	elif oFile.sKind == TestResultFileData.ksKind_InfoVgaText:
934	sVgaText = '\n'.join([sLine.rstrip() for sLine in oCaseFile.getLogFile(oFile).split('\n')]);
935	elif oFile.sKind == TestResultFileData.ksKind_InfoCollection:
936	sInfoText = oCaseFile.getLogFile(oFile);
937	elif oFile.sKind == TestResultFileData.ksKind_ScreenshotFailure:
938	sScreenHash = oCaseFile.getScreenshotSha256(oFile);
939	if sScreenHash is not None:
940	sScreenHash = sScreenHash.lower();
941	self.vprint(u'%s %s' % ( sScreenHash, oFile.sFile,));
942
943	if ( sVMLog is not None \
944	or sNtHardLog is not None \
945	or cTimes == 0) \
946	and investigateLogSet() is True:
947	return True;
948
949	return None;
950
951
952	def isResultFromVMRun(self, oFailedResult, sResultLog):
953	"""
954	Checks if this result and corresponding log snippet looks like a VM run.
955	"""
956
957	# Look for startVmEx/ startVmAndConnectToTxsViaTcp and similar output in the log.
958	if sResultLog.find(' startVm') > 0:
959	return True;
960
961	# Any other indicators? No?
962	_ = oFailedResult;
963	return False;
964
965	def investigateVBoxVMTest(self, oCaseFile, fSingleVM):
966	"""
967	Checks out a VBox VM test.
968
969	This is generic investigation of a test running one or more VMs, like
970	for example a smoke test or a guest installation test.
971
972	The fSingleVM parameter is a hint, which probably won't come in useful.
973	"""
974	_ = fSingleVM;
975
976	#
977	# Get a list of test result failures we should be looking into and the main log.
978	#
979	aoFailedResults = oCaseFile.oTree.getListOfFailures();
980	sMainLog = oCaseFile.getMainLog();
981
982	#
983	# There are a set of errors ending up on the top level result record.
984	# Should deal with these first.
985	#
986	if len(aoFailedResults) == 1 and aoFailedResults[0] == oCaseFile.oTree:
987	# Check if we've just got that XPCOM client smoke test shutdown issue. This will currently always
988	# be reported on the top result because vboxinstall.py doesn't add an error for it. It is easy to
989	# ignore other failures in the test if we're not a little bit careful here.
990	if sMainLog.find('vboxinstaller: Exit code: -11 (') > 0:
991	oCaseFile.noteReason(self.ktReason_XPCOM_Exit_Minus_11);
992	return self.caseClosed(oCaseFile);
993
994	# Hang after starting VBoxSVC (e.g. idTestSet=136307258)
995	if self.isThisFollowedByTheseLines(sMainLog, 'oVBoxMgr=<vboxapi.VirtualBoxManager object at',
996	(' Timeout: ', ' Attempting to abort child...',) ):
997	if sMainLog.find('* glibc detected * /') > 0:
998	oCaseFile.noteReason(self.ktReason_XPCOM_VBoxSVC_Hang_Plus_Heap_Corruption);
999	else:
1000	oCaseFile.noteReason(self.ktReason_XPCOM_VBoxSVC_Hang);
1001	return self.caseClosed(oCaseFile);
1002
1003	# Look for heap corruption without visible hang.
1004	if sMainLog.find('* glibc detected * /') > 0 \
1005	or sMainLog.find("-1073740940") > 0: # STATUS_HEAP_CORRUPTION / 0xc0000374
1006	oCaseFile.noteReason(self.ktReason_Unknown_Heap_Corruption);
1007	return self.caseClosed(oCaseFile);
1008
1009	# Out of memory w/ timeout.
1010	if sMainLog.find('sErrId=HostMemoryLow') > 0:
1011	oCaseFile.noteReason(self.ktReason_Host_HostMemoryLow);
1012	return self.caseClosed(oCaseFile);
1013
1014	# Stale files like vts_rm.exe (windows).
1015	offEnd = sMainLog.rfind('* The test driver exits successfully. *');
1016	if offEnd > 0 and sMainLog.find('[Error 145] The directory is not empty: ', offEnd) > 0:
1017	oCaseFile.noteReason(self.ktReason_Ignore_Stale_Files);
1018	return self.caseClosed(oCaseFile);
1019
1020	#
1021	# XPCOM screwup
1022	#
1023	if sMainLog.find('AttributeError: \'NoneType\' object has no attribute \'addObserver\'') > 0:
1024	oCaseFile.noteReason(self.ktReason_Buggy_Build_Broken_Build);
1025	return self.caseClosed(oCaseFile);
1026
1027	#
1028	# Go thru each failed result.
1029	#
1030	for oFailedResult in aoFailedResults:
1031	self.dprint(u'Looking at test result #%u - %s' % (oFailedResult.idTestResult, oFailedResult.getFullName(),));
1032	sResultLog = TestSetData.extractLogSectionElapsed(sMainLog, oFailedResult.tsCreated, oFailedResult.tsElapsed);
1033	if oFailedResult.sName == 'Installing VirtualBox':
1034	self.investigateInstallUninstallFailure(oCaseFile, oFailedResult, sResultLog, fInstall = True)
1035
1036	elif oFailedResult.sName == 'Uninstalling VirtualBox':
1037	self.investigateInstallUninstallFailure(oCaseFile, oFailedResult, sResultLog, fInstall = False)
1038
1039	elif self.isResultFromVMRun(oFailedResult, sResultLog):
1040	self.investigateVMResult(oCaseFile, oFailedResult, sResultLog);
1041
1042	elif sResultLog.find('Exception: 0x800706be (Call to remote object failed (NS_ERROR_CALL_FAILED))') > 0:
1043	oCaseFile.noteReasonForId(self.ktReason_XPCOM_NS_ERROR_CALL_FAILED, oFailedResult.idTestResult);
1044
1045	elif sResultLog.find('The machine is not mutable (state is ') > 0:
1046	self.vprint('Ignoring "machine not mutable" error as it is probably due to an earlier problem');
1047	oCaseFile.noteReasonForId(self.ktHarmless, oFailedResult.idTestResult);
1048
1049	elif sResultLog.find('** error: no action was specified') > 0 \
1050	or sResultLog.find('(len(self._asXml, asText))') > 0:
1051	oCaseFile.noteReasonForId(self.ktReason_Ignore_Buggy_Test_Driver, oFailedResult.idTestResult);
1052
1053	else:
1054	self.vprint(u'TODO: Cannot place idTestResult=%u - %s' % (oFailedResult.idTestResult, oFailedResult.sName,));
1055	self.dprint(u'%s + %s <<\n%s\n<<' % (oFailedResult.tsCreated, oFailedResult.tsElapsed, sResultLog,));
1056
1057	#
1058	# Report home and close the case if we got them all, otherwise log it.
1059	#
1060	if len(oCaseFile.dReasonForResultId) >= len(aoFailedResults):
1061	return self.caseClosed(oCaseFile);
1062
1063	if len(oCaseFile.dReasonForResultId) > 0:
1064	self.vprint(u'TODO: Got %u out of %u - close, but no cigar. :-/'
1065	% (len(oCaseFile.dReasonForResultId), len(aoFailedResults)));
1066	else:
1067	self.vprint(u'XXX: Could not figure out anything at all! :-(');
1068	return False;
1069
1070
1071	def reasoningFailures(self):
1072	"""
1073	Guess the reason for failures.
1074	"""
1075	#
1076	# Get a list of failed test sets without any assigned failure reason.
1077	#
1078	cGot = 0;
1079	aoTestSets = self.oTestSetLogic.fetchFailedSetsWithoutReason(cHoursBack = self.oConfig.cHoursBack, tsNow = self.tsNow);
1080	for oTestSet in aoTestSets:
1081	self.dprint(u'');
1082	self.dprint(u'reasoningFailures: Checking out test set #%u, status %s' % ( oTestSet.idTestSet, oTestSet.enmStatus,))
1083
1084	#
1085	# Open a case file and assign it to the right investigator.
1086	#
1087	(oTree, _ ) = self.oTestResultLogic.fetchResultTree(oTestSet.idTestSet);
1088	oBuild = BuildDataEx().initFromDbWithId( self.oDb, oTestSet.idBuild, oTestSet.tsCreated);
1089	oTestBox = TestBoxData().initFromDbWithGenId( self.oDb, oTestSet.idGenTestBox);
1090	oTestGroup = TestGroupData().initFromDbWithId( self.oDb, oTestSet.idTestGroup, oTestSet.tsCreated);
1091	oTestCase = TestCaseDataEx().initFromDbWithGenId( self.oDb, oTestSet.idGenTestCase, oTestSet.tsConfig);
1092
1093	oCaseFile = VirtualTestSheriffCaseFile(self, oTestSet, oTree, oBuild, oTestBox, oTestGroup, oTestCase);
1094
1095	if oTestSet.enmStatus == TestSetData.ksTestStatus_BadTestBox:
1096	self.dprint(u'investigateBadTestBox is taking over %s.' % (oCaseFile.sLongName,));
1097	fRc = self.investigateBadTestBox(oCaseFile);
1098
1099	elif oCaseFile.isVBoxUnitTest():
1100	self.dprint(u'investigateVBoxUnitTest is taking over %s.' % (oCaseFile.sLongName,));
1101	fRc = self.investigateVBoxUnitTest(oCaseFile);
1102
1103	elif oCaseFile.isVBoxInstallTest():
1104	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1105	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
1106
1107	elif oCaseFile.isVBoxUSBTest():
1108	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1109	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
1110
1111	elif oCaseFile.isVBoxStorageTest():
1112	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1113	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
1114
1115	elif oCaseFile.isVBoxGAsTest():
1116	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1117	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
1118
1119	elif oCaseFile.isVBoxAPITest():
1120	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1121	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
1122
1123	elif oCaseFile.isVBoxBenchmarkTest():
1124	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1125	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = False);
1126
1127	elif oCaseFile.isVBoxSmokeTest():
1128	self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
1129	fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = False);
1130
1131	else:
1132	self.vprint(u'reasoningFailures: Unable to classify test set: %s' % (oCaseFile.sLongName,));
1133	fRc = False;
1134	cGot += fRc is True;
1135
1136	self.vprint(u'reasoningFailures: Got %u out of %u' % (cGot, len(aoTestSets), ));
1137	return 0;
1138
1139
1140	def main(self):
1141	"""
1142	The 'main' function.
1143	Return exit code (0, 1, etc).
1144	"""
1145	# Database stuff.
1146	self.oDb = TMDatabaseConnection()
1147	self.oTestResultLogic = TestResultLogic(self.oDb);
1148	self.oTestSetLogic = TestSetLogic(self.oDb);
1149	self.oFailureReasonLogic = FailureReasonLogic(self.oDb);
1150	self.oTestResultFailureLogic = TestResultFailureLogic(self.oDb);
1151	self.asBsodReasons = self.oFailureReasonLogic.fetchForSheriffByNamedCategory(self.ksBsodCategory);
1152	self.asUnitTestReasons = self.oFailureReasonLogic.fetchForSheriffByNamedCategory(self.ksUnitTestCategory);
1153
1154	# Get a fix on our 'now' before we do anything..
1155	self.oDb.execute('SELECT CURRENT_TIMESTAMP - interval \'%s hours\'', (self.oConfig.cStartHoursAgo,));
1156	self.tsNow = self.oDb.fetchOne();
1157
1158	# If we're suppost to commit anything we need to get our user ID.
1159	rcExit = 0;
1160	if self.oConfig.fRealRun:
1161	self.oLogin = UserAccountLogic(self.oDb).tryFetchAccountByLoginName(VirtualTestSheriff.ksLoginName);
1162	if self.oLogin is None:
1163	rcExit = self.eprint('Cannot find my user account "%s"!' % (VirtualTestSheriff.ksLoginName,));
1164	else:
1165	self.uidSelf = self.oLogin.uid;
1166
1167	#
1168	# Do the stuff.
1169	#
1170	if rcExit == 0:
1171	rcExit = self.selfCheck();
1172	if rcExit == 0:
1173	rcExit = self.badTestBoxManagement();
1174	rcExit2 = self.reasoningFailures();
1175	if rcExit == 0:
1176	rcExit = rcExit2;
1177	# Redo the bad testbox management after failure reasons have been assigned (got timing issues).
1178	if rcExit == 0:
1179	rcExit = self.badTestBoxManagement();
1180
1181	# Cleanup.
1182	self.oFailureReasonLogic = None;
1183	self.oTestResultFailureLogic = None;
1184	self.oTestSetLogic = None;
1185	self.oTestResultLogic = None;
1186	self.oDb.close();
1187	self.oDb = None;
1188	if self.oLogFile is not None:
1189	self.oLogFile.close();
1190	self.oLogFile = None;
1191	return rcExit;
1192
1193	if __name__ == '__main__':
1194	sys.exit(VirtualTestSheriff().main());
1195

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

source: vbox/trunk/src/VBox/ValidationKit/testmanager/batch/virtual_test_sheriff.py@ 65440

Download in other formats: