1 | #!/usr/bin/env python
|
---|
2 | # -*- coding: utf-8 -*-
|
---|
3 | # $Id: virtual_test_sheriff.py 62275 2016-07-15 11:46:26Z 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: 62275 $"
|
---|
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: 62275 $ \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 |
|
---|
331 | def selfCheck(self):
|
---|
332 | """ Does some self checks, looking up things we expect to be in the database and such. """
|
---|
333 | rcExit = 0;
|
---|
334 | for sAttr in dir(self.__class__):
|
---|
335 | if sAttr.startswith('ktReason_'):
|
---|
336 | tReason = getattr(self.__class__, sAttr);
|
---|
337 | oFailureReason = self.oFailureReasonLogic.cachedLookupByNameAndCategory(tReason[1], tReason[0]);
|
---|
338 | if oFailureReason is None:
|
---|
339 | rcExit = self.eprint(u'Failed to find failure reason "%s" in category "%s" in the database!'
|
---|
340 | % (tReason[1], tReason[0],));
|
---|
341 |
|
---|
342 | # Check the user account as well.
|
---|
343 | if self.oLogin is None:
|
---|
344 | oLogin = UserAccountLogic(self.oDb).tryFetchAccountByLoginName(VirtualTestSheriff.ksLoginName);
|
---|
345 | if oLogin is None:
|
---|
346 | rcExit = self.eprint(u'Cannot find my user account "%s"!' % (VirtualTestSheriff.ksLoginName,));
|
---|
347 | return rcExit;
|
---|
348 |
|
---|
349 |
|
---|
350 |
|
---|
351 | def badTestBoxManagement(self):
|
---|
352 | """
|
---|
353 | Looks for bad test boxes and first tries once to reboot them then disables them.
|
---|
354 | """
|
---|
355 | rcExit = 0;
|
---|
356 |
|
---|
357 | #
|
---|
358 | # We skip this entirely if we're running in the past and not in harmless debug mode.
|
---|
359 | #
|
---|
360 | if self.oConfig.cStartHoursAgo != 0 \
|
---|
361 | and (not self.oConfig.fDebug or self.oConfig.fRealRun):
|
---|
362 | return rcExit;
|
---|
363 | tsNow = self.tsNow if self.oConfig.fDebug else None;
|
---|
364 | cHoursBack = self.oConfig.cHoursBack if self.oConfig.fDebug else 2;
|
---|
365 | oTestBoxLogic = TestBoxLogic(self.oDb);
|
---|
366 |
|
---|
367 | #
|
---|
368 | # Get list of bad test boxes for given period and check them out individually.
|
---|
369 | #
|
---|
370 | aidBadTestBoxes = self.oTestSetLogic.fetchBadTestBoxIds(cHoursBack = cHoursBack, tsNow = tsNow);
|
---|
371 | for idTestBox in aidBadTestBoxes:
|
---|
372 | # Skip if the testbox is already disabled or has a pending reboot command.
|
---|
373 | try:
|
---|
374 | oTestBox = TestBoxData().initFromDbWithId(self.oDb, idTestBox);
|
---|
375 | except Exception as oXcpt:
|
---|
376 | rcExit = self.eprint('Failed to get data for test box #%u in badTestBoxManagement: %s' % (idTestBox, oXcpt,));
|
---|
377 | continue;
|
---|
378 | if not oTestBox.fEnabled:
|
---|
379 | self.dprint(u'badTestBoxManagement: Skipping test box #%u (%s) as it has been disabled already.'
|
---|
380 | % ( idTestBox, oTestBox.sName, ));
|
---|
381 | continue;
|
---|
382 | if oTestBox.enmPendingCmd != TestBoxData.ksTestBoxCmd_None:
|
---|
383 | self.dprint(u'badTestBoxManagement: Skipping test box #%u (%s) as it has a command pending: %s'
|
---|
384 | % ( idTestBox, oTestBox.sName, oTestBox.enmPendingCmd));
|
---|
385 | continue;
|
---|
386 |
|
---|
387 | # Get the most recent testsets for this box (descending on tsDone) and see how bad it is.
|
---|
388 | aoSets = self.oTestSetLogic.fetchSetsForTestBox(idTestBox, cHoursBack = cHoursBack, tsNow = tsNow);
|
---|
389 | cOkay = 0;
|
---|
390 | cBad = 0;
|
---|
391 | iFirstOkay = len(aoSets);
|
---|
392 | for iSet, oSet in enumerate(aoSets):
|
---|
393 | if oSet.enmStatus == TestSetData.ksTestStatus_BadTestBox:
|
---|
394 | cBad += 1;
|
---|
395 | else:
|
---|
396 | ## @todo maybe check the elapsed time here, it could still be a bad run.
|
---|
397 | cOkay += 1;
|
---|
398 | if iFirstOkay > iSet:
|
---|
399 | iFirstOkay = iSet;
|
---|
400 | if iSet > 10:
|
---|
401 | break;
|
---|
402 |
|
---|
403 | # We react if there are two or more bad-testbox statuses at the head of the
|
---|
404 | # history and at least three in the last 10 results.
|
---|
405 | if iFirstOkay >= 2 and cBad > 2:
|
---|
406 | if oTestBoxLogic.hasTestBoxRecentlyBeenRebooted(idTestBox, cHoursBack = cHoursBack, tsNow = tsNow):
|
---|
407 | self.vprint(u'Disabling testbox #%u (%s) - iFirstOkay=%u cBad=%u cOkay=%u'
|
---|
408 | % ( idTestBox, oTestBox.sName, iFirstOkay, cBad, cOkay));
|
---|
409 | if self.oConfig.fRealRun is True:
|
---|
410 | try:
|
---|
411 | oTestBoxLogic.disableTestBox(idTestBox, self.uidSelf, fCommit = True,
|
---|
412 | sComment = 'Automatically disabled (iFirstOkay=%u cBad=%u cOkay=%u)'
|
---|
413 | % (iFirstOkay, cBad, cOkay),);
|
---|
414 | except Exception as oXcpt:
|
---|
415 | rcExit = self.eprint(u'Error disabling testbox #%u (%u): %s\n' % (idTestBox, oTestBox.sName, oXcpt,));
|
---|
416 | else:
|
---|
417 | self.vprint(u'Rebooting testbox #%u (%s) - iFirstOkay=%u cBad=%u cOkay=%u'
|
---|
418 | % ( idTestBox, oTestBox.sName, iFirstOkay, cBad, cOkay));
|
---|
419 | if self.oConfig.fRealRun is True:
|
---|
420 | try:
|
---|
421 | oTestBoxLogic.rebootTestBox(idTestBox, self.uidSelf, fCommit = True,
|
---|
422 | sComment = 'Automatically rebooted (iFirstOkay=%u cBad=%u cOkay=%u)'
|
---|
423 | % (iFirstOkay, cBad, cOkay),);
|
---|
424 | except Exception as oXcpt:
|
---|
425 | rcExit = self.eprint(u'Error rebooting testbox #%u (%u): %s\n' % (idTestBox, oTestBox.sName, oXcpt,));
|
---|
426 | else:
|
---|
427 | self.dprint(u'badTestBoxManagement: #%u (%s) looks ok: iFirstOkay=%u cBad=%u cOkay=%u'
|
---|
428 | % ( idTestBox, oTestBox.sName, iFirstOkay, cBad, cOkay));
|
---|
429 | return rcExit;
|
---|
430 |
|
---|
431 |
|
---|
432 | ## @name Failure reasons we know.
|
---|
433 | ## @{
|
---|
434 | ktReason_BSOD_Recovery = ( 'BSOD', 'Recovery' );
|
---|
435 | ktReason_BSOD_Automatic_Repair = ( 'BSOD', 'Automatic Repair' );
|
---|
436 | ktReason_BSOD_C0000225 = ( 'BSOD', '0xC0000225 (boot)' );
|
---|
437 | ktReason_Guru_Generic = ( 'Guru Meditations', 'Generic Guru Meditation' );
|
---|
438 | ktReason_Guru_VERR_IEM_INSTR_NOT_IMPLEMENTED = ( 'Guru Meditations', 'VERR_IEM_INSTR_NOT_IMPLEMENTED' );
|
---|
439 | ktReason_Guru_VERR_IEM_ASPECT_NOT_IMPLEMENTED = ( 'Guru Meditations', 'VERR_IEM_ASPECT_NOT_IMPLEMENTED' );
|
---|
440 | ktReason_Guru_VERR_TRPM_DONT_PANIC = ( 'Guru Meditations', 'VERR_TRPM_DONT_PANIC' );
|
---|
441 | ktReason_Guru_VERR_PGM_PHYS_PAGE_RESERVED = ( 'Guru Meditations', 'VERR_PGM_PHYS_PAGE_RESERVED' );
|
---|
442 | ktReason_Guru_VERR_VMX_INVALID_GUEST_STATE = ( 'Guru Meditations', 'VERR_VMX_INVALID_GUEST_STATE' );
|
---|
443 | ktReason_Guru_VINF_EM_TRIPLE_FAULT = ( 'Guru Meditations', 'VINF_EM_TRIPLE_FAULT' );
|
---|
444 | ktReason_Host_HostMemoryLow = ( 'Host', 'HostMemoryLow' );
|
---|
445 | ktReason_Host_Reboot_OSX_Watchdog_Timeout = ( 'Host Reboot', 'OSX Watchdog Timeout' );
|
---|
446 | ktReason_Networking_Nonexistent_host_nic = ( 'Networking', 'Nonexistent host networking interface' );
|
---|
447 | ktReason_OSInstall_GRUB_hang = ( 'O/S Install', 'GRUB hang' );
|
---|
448 | ktReason_Panic_MP_BIOS_IO_APIC = ( 'Panic', 'MP-BIOS/IO-APIC' );
|
---|
449 | ktReason_XPCOM_Exit_Minus_11 = ( 'API / (XP)COM', 'exit -11' );
|
---|
450 | ktReason_XPCOM_VBoxSVC_Hang = ( 'API / (XP)COM', 'VBoxSVC hang' );
|
---|
451 | ktReason_XPCOM_VBoxSVC_Hang_Plus_Heap_Corruption = ( 'API / (XP)COM', 'VBoxSVC hang + heap corruption' );
|
---|
452 | ktReason_XPCOM_NS_ERROR_CALL_FAILED = ( 'API / (XP)COM', 'NS_ERROR_CALL_FAILED' );
|
---|
453 | ktReason_Unknown_Heap_Corruption = ( 'Unknown', 'Heap corruption' );
|
---|
454 | ktReason_Unknown_Reboot_Loop = ( 'Unknown', 'Reboot loop' );
|
---|
455 | ktReason_Ignore_Buggy_Test_Driver = ( 'Ignore', 'Buggy test driver' );
|
---|
456 | ktReason_Ignore_Stale_Files = ( 'Ignore', 'Stale files' );
|
---|
457 | ktReason_Buggy_Build_Broken_Build = ( 'Broken Build', 'Buggy build' );
|
---|
458 | ## @}
|
---|
459 |
|
---|
460 | ## BSOD category.
|
---|
461 | ksBsodCategory = 'BSOD';
|
---|
462 | ## Special reason indicating that the flesh and blood sheriff has work to do.
|
---|
463 | ksBsodAddNew = 'Add new BSOD';
|
---|
464 |
|
---|
465 | ## Unit test category.
|
---|
466 | ksUnitTestCategory = 'Unit';
|
---|
467 | ## Special reason indicating that the flesh and blood sheriff has work to do.
|
---|
468 | ksUnitTestAddNew = 'Add new';
|
---|
469 |
|
---|
470 | ## Used for indica that we shouldn't report anything for this test result ID and
|
---|
471 | ## consider promoting the previous error to test set level if it's the only one.
|
---|
472 | ktHarmless = ( 'Probably', 'Caused by previous error' );
|
---|
473 |
|
---|
474 |
|
---|
475 | def caseClosed(self, oCaseFile):
|
---|
476 | """
|
---|
477 | Reports the findings in the case and closes it.
|
---|
478 | """
|
---|
479 | #
|
---|
480 | # Log it and create a dReasonForReasultId we can use below.
|
---|
481 | #
|
---|
482 | dCommentForResultId = oCaseFile.dCommentForResultId;
|
---|
483 | if len(oCaseFile.dReasonForResultId) > 0:
|
---|
484 | # Must weed out ktHarmless.
|
---|
485 | dReasonForResultId = {};
|
---|
486 | for idKey, tReason in oCaseFile.dReasonForResultId.items():
|
---|
487 | if tReason is not self.ktHarmless:
|
---|
488 | dReasonForResultId[idKey] = tReason;
|
---|
489 | if len(dReasonForResultId) == 0:
|
---|
490 | self.vprint(u'TODO: Closing %s without a real reason, only %s.'
|
---|
491 | % (oCaseFile.sName, oCaseFile.dReasonForResultId));
|
---|
492 | return False;
|
---|
493 |
|
---|
494 | # Try promote to single reason.
|
---|
495 | atValues = dReasonForResultId.values();
|
---|
496 | fSingleReason = True;
|
---|
497 | if len(dReasonForResultId) == 1 and dReasonForResultId.keys()[0] != oCaseFile.oTestSet.idTestResult:
|
---|
498 | self.dprint(u'Promoting single reason to whole set: %s' % (atValues[0],));
|
---|
499 | elif len(dReasonForResultId) > 1 and len(atValues) == atValues.count(atValues[0]):
|
---|
500 | self.dprint(u'Merged %d reasons to a single one: %s' % (len(atValues), atValues[0]));
|
---|
501 | else:
|
---|
502 | fSingleReason = False;
|
---|
503 | if fSingleReason:
|
---|
504 | dReasonForResultId = { oCaseFile.oTestSet.idTestResult: atValues[0], };
|
---|
505 | if len(dCommentForResultId) > 0:
|
---|
506 | dCommentForResultId = { oCaseFile.oTestSet.idTestResult: dCommentForResultId.values()[0], };
|
---|
507 | elif oCaseFile.tReason is not None:
|
---|
508 | dReasonForResultId = { oCaseFile.oTestSet.idTestResult: oCaseFile.tReason, };
|
---|
509 | else:
|
---|
510 | self.vprint(u'Closing %s without a reason - this should not happen!' % (oCaseFile.sName,));
|
---|
511 | return False;
|
---|
512 |
|
---|
513 | self.vprint(u'Closing %s with following reason%s: %s'
|
---|
514 | % ( oCaseFile.sName, 's' if dReasonForResultId > 0 else '', dReasonForResultId, ));
|
---|
515 |
|
---|
516 | #
|
---|
517 | # Add the test failure reason record(s).
|
---|
518 | #
|
---|
519 | for idTestResult, tReason in dReasonForResultId.items():
|
---|
520 | oFailureReason = self.oFailureReasonLogic.cachedLookupByNameAndCategory(tReason[1], tReason[0]);
|
---|
521 | if oFailureReason is not None:
|
---|
522 | sComment = 'Set by $Revision: 62275 $' # Handy for reverting later.
|
---|
523 | if idTestResult in dCommentForResultId:
|
---|
524 | sComment += ': ' + dCommentForResultId[idTestResult];
|
---|
525 |
|
---|
526 | oAdd = TestResultFailureData();
|
---|
527 | oAdd.initFromValues(idTestResult = idTestResult,
|
---|
528 | idFailureReason = oFailureReason.idFailureReason,
|
---|
529 | uidAuthor = self.uidSelf,
|
---|
530 | idTestSet = oCaseFile.oTestSet.idTestSet,
|
---|
531 | sComment = sComment,);
|
---|
532 | if self.oConfig.fRealRun:
|
---|
533 | try:
|
---|
534 | self.oTestResultFailureLogic.addEntry(oAdd, self.uidSelf, fCommit = True);
|
---|
535 | except Exception as oXcpt:
|
---|
536 | self.eprint(u'caseClosed: Exception "%s" while adding reason %s for %s'
|
---|
537 | % (oXcpt, oAdd, oCaseFile.sLongName,));
|
---|
538 | else:
|
---|
539 | self.eprint(u'caseClosed: Cannot locate failure reason: %s / %s' % ( tReason[0], tReason[1],));
|
---|
540 | return True;
|
---|
541 |
|
---|
542 | #
|
---|
543 | # Tools for assiting log parsing.
|
---|
544 | #
|
---|
545 |
|
---|
546 | @staticmethod
|
---|
547 | def matchFollowedByLines(sStr, off, asFollowingLines):
|
---|
548 | """ Worker for isThisFollowedByTheseLines. """
|
---|
549 |
|
---|
550 | # Advance off to the end of the line.
|
---|
551 | off = sStr.find('\n', off);
|
---|
552 | if off < 0:
|
---|
553 | return False;
|
---|
554 | off += 1;
|
---|
555 |
|
---|
556 | # Match each string with the subsequent lines.
|
---|
557 | for iLine, sLine in enumerate(asFollowingLines):
|
---|
558 | offEnd = sStr.find('\n', off);
|
---|
559 | if offEnd < 0:
|
---|
560 | return iLine + 1 == len(asFollowingLines) and sStr.find(sLine, off) < 0;
|
---|
561 | if len(sLine) > 0 and sStr.find(sLine, off, offEnd) < 0:
|
---|
562 | return False;
|
---|
563 |
|
---|
564 | # next line.
|
---|
565 | off = offEnd + 1;
|
---|
566 |
|
---|
567 | return True;
|
---|
568 |
|
---|
569 | @staticmethod
|
---|
570 | def isThisFollowedByTheseLines(sStr, sFirst, asFollowingLines):
|
---|
571 | """
|
---|
572 | Looks for a line contining sFirst which is then followed by lines
|
---|
573 | with the strings in asFollowingLines. (No newline chars anywhere!)
|
---|
574 | Returns True / False.
|
---|
575 | """
|
---|
576 | off = sStr.find(sFirst, 0);
|
---|
577 | while off >= 0:
|
---|
578 | if VirtualTestSheriff.matchFollowedByLines(sStr, off, asFollowingLines):
|
---|
579 | return True;
|
---|
580 | off = sStr.find(sFirst, off + 1);
|
---|
581 | return False;
|
---|
582 |
|
---|
583 | @staticmethod
|
---|
584 | def findAndReturnResetOfLine(sHaystack, sNeedle):
|
---|
585 | """
|
---|
586 | Looks for sNeedle in sHaystack.
|
---|
587 | Returns The text following the needle up to the end of the line.
|
---|
588 | Returns None if not found.
|
---|
589 | """
|
---|
590 | off = sHaystack.find(sNeedle);
|
---|
591 | if off < 0:
|
---|
592 | return None;
|
---|
593 | off += len(sNeedle)
|
---|
594 | offEol = sHaystack.find('\n', off);
|
---|
595 | if offEol < 0:
|
---|
596 | offEol = len(sHaystack);
|
---|
597 | return sHaystack[off:offEol]
|
---|
598 |
|
---|
599 | @staticmethod
|
---|
600 | def findInAnyAndReturnResetOfLine(asHaystacks, sNeedle):
|
---|
601 | """
|
---|
602 | Looks for sNeedle in zeroe or more haystacks (asHaystack).
|
---|
603 | Returns The text following the first needed found up to the end of the line.
|
---|
604 | Returns None if not found.
|
---|
605 | """
|
---|
606 | for sHaystack in asHaystacks:
|
---|
607 | sRet = VirtualTestSheriff.findAndReturnResetOfLine(sHaystack, sNeedle);
|
---|
608 | if sRet is not None:
|
---|
609 | return sRet;
|
---|
610 | return None;
|
---|
611 |
|
---|
612 |
|
---|
613 | #
|
---|
614 | # The investigative units.
|
---|
615 | #
|
---|
616 |
|
---|
617 | def investigateBadTestBox(self, oCaseFile):
|
---|
618 | """
|
---|
619 | Checks out bad-testbox statuses.
|
---|
620 | """
|
---|
621 | _ = oCaseFile;
|
---|
622 | return False;
|
---|
623 |
|
---|
624 |
|
---|
625 | def investigateVBoxUnitTest(self, oCaseFile):
|
---|
626 | """
|
---|
627 | Checks out a VBox unittest problem.
|
---|
628 | """
|
---|
629 |
|
---|
630 | #
|
---|
631 | # Process simple test case failures first, using their name as reason.
|
---|
632 | # We do the reason management just like for BSODs.
|
---|
633 | #
|
---|
634 | cRelevantOnes = 0;
|
---|
635 | aoFailedResults = oCaseFile.oTree.getListOfFailures();
|
---|
636 | for oFailedResult in aoFailedResults:
|
---|
637 | if oFailedResult is oCaseFile.oTree:
|
---|
638 | self.vprint('TODO: toplevel failure');
|
---|
639 | cRelevantOnes += 1
|
---|
640 | elif oFailedResult.sName == 'Installing VirtualBox':
|
---|
641 | self.vprint('TODO: Installation failure');
|
---|
642 | cRelevantOnes += 1
|
---|
643 | elif oFailedResult.sName == 'Uninstalling VirtualBox':
|
---|
644 | self.vprint('TODO: Uninstallation failure');
|
---|
645 | cRelevantOnes += 1
|
---|
646 | elif oFailedResult.oParent is not None:
|
---|
647 | # Get the 2nd level node because that's where we'll find the unit test name.
|
---|
648 | while oFailedResult.oParent.oParent is not None:
|
---|
649 | oFailedResult = oFailedResult.oParent;
|
---|
650 |
|
---|
651 | # Only report a failure once.
|
---|
652 | if oFailedResult.idTestResult not in oCaseFile.dReasonForResultId:
|
---|
653 | sKey = oFailedResult.sName;
|
---|
654 | if sKey.startswith('testcase/'):
|
---|
655 | sKey = sKey[9:];
|
---|
656 | if sKey in self.asUnitTestReasons:
|
---|
657 | tReason = ( self.ksUnitTestCategory, sKey );
|
---|
658 | oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
|
---|
659 | else:
|
---|
660 | self.dprint(u'Unit test failure "%s" not found in %s;' % (sKey, self.asUnitTestReasons));
|
---|
661 | tReason = ( self.ksUnitTestCategory, self.ksUnitTestAddNew );
|
---|
662 | oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult, sComment = sKey);
|
---|
663 | cRelevantOnes += 1
|
---|
664 | else:
|
---|
665 | self.vprint(u'Internal error: expected oParent to NOT be None for %s' % (oFailedResult,));
|
---|
666 |
|
---|
667 | #
|
---|
668 | # If we've caught all the relevant ones by now, report the result.
|
---|
669 | #
|
---|
670 | if len(oCaseFile.dReasonForResultId) >= cRelevantOnes:
|
---|
671 | return self.caseClosed(oCaseFile);
|
---|
672 | return False;
|
---|
673 |
|
---|
674 |
|
---|
675 | ## Things we search a main or VM log for to figure out why something went bust.
|
---|
676 | katSimpleMainAndVmLogReasons = [
|
---|
677 | # ( Whether to stop on hit, reason tuple, needle text. )
|
---|
678 | ( False, ktReason_Guru_Generic, 'GuruMeditation' ),
|
---|
679 | ( False, ktReason_Guru_Generic, 'Guru Meditation' ),
|
---|
680 | ( True, ktReason_Guru_VERR_IEM_INSTR_NOT_IMPLEMENTED, 'VERR_IEM_INSTR_NOT_IMPLEMENTED' ),
|
---|
681 | ( True, ktReason_Guru_VERR_IEM_ASPECT_NOT_IMPLEMENTED, 'VERR_IEM_ASPECT_NOT_IMPLEMENTED' ),
|
---|
682 | ( True, ktReason_Guru_VERR_TRPM_DONT_PANIC, 'VERR_TRPM_DONT_PANIC' ),
|
---|
683 | ( True, ktReason_Guru_VERR_PGM_PHYS_PAGE_RESERVED, 'VERR_PGM_PHYS_PAGE_RESERVED' ),
|
---|
684 | ( True, ktReason_Guru_VERR_VMX_INVALID_GUEST_STATE, 'VERR_VMX_INVALID_GUEST_STATE' ),
|
---|
685 | ( True, ktReason_Guru_VINF_EM_TRIPLE_FAULT, 'VINF_EM_TRIPLE_FAULT' ),
|
---|
686 | ( True, ktReason_Networking_Nonexistent_host_nic,
|
---|
687 | 'rc=E_FAIL text="Nonexistent host networking interface, name \'eth0\' (VERR_INTERNAL_ERROR)"' ),
|
---|
688 | ( True, ktReason_Host_Reboot_OSX_Watchdog_Timeout, ': "OSX Watchdog Timeout: ' ),
|
---|
689 | ( False, ktReason_XPCOM_NS_ERROR_CALL_FAILED,
|
---|
690 | 'Exception: 0x800706be (Call to remote object failed (NS_ERROR_CALL_FAILED))' ),
|
---|
691 | ( True, ktReason_Host_HostMemoryLow, 'HostMemoryLow' ),
|
---|
692 | ( True, ktReason_Host_HostMemoryLow, 'Failed to procure handy pages; rc=VERR_NO_MEMORY' ),
|
---|
693 | ];
|
---|
694 |
|
---|
695 | ## Things we search the _RIGHT_ _STRIPPED_ vgatext for.
|
---|
696 | katSimpleVgaTextReasons = [
|
---|
697 | # ( Whether to stop on hit, reason tuple, needle text. )
|
---|
698 | ( True, ktReason_Panic_MP_BIOS_IO_APIC,
|
---|
699 | "..MP-BIOS bug: 8254 timer not connected to IO-APIC\n\n" ),
|
---|
700 | ( True, ktReason_Panic_MP_BIOS_IO_APIC,
|
---|
701 | "..MP-BIOS bug: 8254 timer not connected to IO-APIC\n"
|
---|
702 | "...trying to set up timer (IRQ0) through the 8259A ... failed.\n"
|
---|
703 | "...trying to set up timer as Virtual Wire IRQ... failed.\n"
|
---|
704 | "...trying to set up timer as ExtINT IRQ... failed :(.\n"
|
---|
705 | "Kernel panic - not syncing: IO-APIC + timer doesn't work! Boot with apic=debug\n"
|
---|
706 | "and send a report. Then try booting with the 'noapic' option\n"
|
---|
707 | "\n" ),
|
---|
708 | ( True, ktReason_OSInstall_GRUB_hang,
|
---|
709 | "-----\nGRUB Loading stage2..\n\n\n\n" ),
|
---|
710 | ];
|
---|
711 |
|
---|
712 | ## Mapping screenshot/failure SHA-256 hashes to failure reasons.
|
---|
713 | katSimpleScreenshotHashReasons = [
|
---|
714 | # ( Whether to stop on hit, reason tuple, lowercased sha-256 of PIL.Image.tostring output )
|
---|
715 | ( True, ktReason_BSOD_Recovery, '576f8e38d62b311cac7e3dc3436a0d0b9bd8cfd7fa9c43aafa95631520a45eac' ),
|
---|
716 | ( True, ktReason_BSOD_Automatic_Repair, 'c6a72076cc619937a7a39cfe9915b36d94cee0d4e3ce5ce061485792dcee2749' ),
|
---|
717 | ( True, ktReason_BSOD_Automatic_Repair, '26c4d8a724ff2c5e1051f3d5b650dbda7b5fdee0aa3e3c6059797f7484a515df' ),
|
---|
718 | ( True, ktReason_BSOD_C0000225, 'bd13a144be9dcdfb16bc863ff4c8f02a86e263c174f2cd5ffd27ca5f3aa31789' ),
|
---|
719 | ( True, ktReason_BSOD_C0000225, '8348b465e7ee9e59dd4e785880c57fd8677de05d11ac21e786bfde935307b42f' ),
|
---|
720 | ( True, ktReason_BSOD_C0000225, '1316e1fc818a73348412788e6910b8c016f237d8b4e15b20caf4a866f7a7840e' ),
|
---|
721 | ( True, ktReason_BSOD_C0000225, '54e0acbff365ce20a85abbe42bcd53647b8b9e80c68e45b2cd30e86bf177a0b5' ),
|
---|
722 | ( True, ktReason_BSOD_C0000225, '50fec50b5199923fa48b3f3e782687cc381e1c8a788ebda14e6a355fbe3bb1b3' ),
|
---|
723 | ];
|
---|
724 |
|
---|
725 | def investigateVMResult(self, oCaseFile, oFailedResult, sResultLog):
|
---|
726 | """
|
---|
727 | Investigates a failed VM run.
|
---|
728 | """
|
---|
729 |
|
---|
730 | def investigateLogSet():
|
---|
731 | """
|
---|
732 | Investigates the current set of VM related logs.
|
---|
733 | """
|
---|
734 | self.dprint('investigateLogSet: lengths: result log %u, VM log %u, kernel log %u, vga text %u, info text %u'
|
---|
735 | % ( len(sResultLog) if sResultLog is not None else 0,
|
---|
736 | len(sVMLog) if sVMLog is not None else 0,
|
---|
737 | len(sKrnlLog) if sKrnlLog is not None else 0,
|
---|
738 | len(sVgaText) if sVgaText is not None else 0,
|
---|
739 | len(sInfoText) if sInfoText is not None else 0, ));
|
---|
740 | #self.dprint(u'main.log<<<\n%s\n<<<\n' % (sResultLog,));
|
---|
741 | #self.dprint(u'vbox.log<<<\n%s\n<<<\n' % (sVMLog,));
|
---|
742 | #self.dprint(u'krnl.log<<<\n%s\n<<<\n' % (sKrnlLog,));
|
---|
743 | #self.dprint(u'vgatext.txt<<<\n%s\n<<<\n' % (sVgaText,));
|
---|
744 | #self.dprint(u'info.txt<<<\n%s\n<<<\n' % (sInfoText,));
|
---|
745 |
|
---|
746 | # TODO: more
|
---|
747 |
|
---|
748 | #
|
---|
749 | # Look for BSODs. Some stupid stupid inconsistencies in reason and log messages here, so don't try prettify this.
|
---|
750 | #
|
---|
751 | sDetails = self.findInAnyAndReturnResetOfLine([ sVMLog, sResultLog ],
|
---|
752 | 'GIM: HyperV: Guest indicates a fatal condition! P0=');
|
---|
753 | if sDetails is not None:
|
---|
754 | # P0=%#RX64 P1=%#RX64 P2=%#RX64 P3=%#RX64 P4=%#RX64 "
|
---|
755 | sKey = sDetails.split(' ', 1)[0];
|
---|
756 | try: sKey = '0x%08X' % (int(sKey, 16),);
|
---|
757 | except: pass;
|
---|
758 | if sKey in self.asBsodReasons:
|
---|
759 | tReason = ( self.ksBsodCategory, sKey );
|
---|
760 | elif sKey.lower() in self.asBsodReasons: # just in case.
|
---|
761 | tReason = ( self.ksBsodCategory, sKey.lower() );
|
---|
762 | else:
|
---|
763 | self.dprint(u'BSOD "%s" not found in %s;' % (sKey, self.asBsodReasons));
|
---|
764 | tReason = ( self.ksBsodCategory, self.ksBsodAddNew );
|
---|
765 | return oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult, sComment = sDetails.strip());
|
---|
766 |
|
---|
767 | #
|
---|
768 | # Look for linux panic.
|
---|
769 | #
|
---|
770 | if sKrnlLog is not None:
|
---|
771 | pass; ## @todo
|
---|
772 |
|
---|
773 | #
|
---|
774 | # Loop thru the simple stuff.
|
---|
775 | #
|
---|
776 | fFoundSomething = False;
|
---|
777 | for fStopOnHit, tReason, sNeedle in self.katSimpleMainAndVmLogReasons:
|
---|
778 | if sResultLog.find(sNeedle) > 0 or sVMLog.find(sNeedle) > 0:
|
---|
779 | oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
|
---|
780 | if fStopOnHit:
|
---|
781 | return True;
|
---|
782 | fFoundSomething = True;
|
---|
783 |
|
---|
784 | # Continue with vga text.
|
---|
785 | if sVgaText is not None and len(sVgaText) > 0:
|
---|
786 | for fStopOnHit, tReason, sNeedle in self.katSimpleVgaTextReasons:
|
---|
787 | if sVgaText.find(sNeedle) > 0:
|
---|
788 | oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
|
---|
789 | if fStopOnHit:
|
---|
790 | return True;
|
---|
791 | fFoundSomething = True;
|
---|
792 | _ = sInfoText;
|
---|
793 |
|
---|
794 | # Continue with screen hashes.
|
---|
795 | if sScreenHash is not None:
|
---|
796 | for fStopOnHit, tReason, sHash in self.katSimpleScreenshotHashReasons:
|
---|
797 | if sScreenHash == sHash:
|
---|
798 | oCaseFile.noteReasonForId(tReason, oFailedResult.idTestResult);
|
---|
799 | if fStopOnHit:
|
---|
800 | return True;
|
---|
801 | fFoundSomething = True;
|
---|
802 |
|
---|
803 | #
|
---|
804 | # Check for repeated reboots...
|
---|
805 | #
|
---|
806 | cResets = sVMLog.count('Changing the VM state from \'RUNNING\' to \'RESETTING\'');
|
---|
807 | if cResets > 10:
|
---|
808 | return oCaseFile.noteReasonForId(self.ktReason_Unknown_Reboot_Loop, oFailedResult.idTestResult,
|
---|
809 | sComment = 'Counted %s reboots' % (cResets,));
|
---|
810 |
|
---|
811 | return fFoundSomething;
|
---|
812 |
|
---|
813 | #
|
---|
814 | # Check if we got any VM or/and kernel logs. Treat them as sets in
|
---|
815 | # case we run multiple VMs here (this is of course ASSUMING they
|
---|
816 | # appear in the order that terminateVmBySession uploads them).
|
---|
817 | #
|
---|
818 | sVMLog = None;
|
---|
819 | sScreenHash = None;
|
---|
820 | sKrnlLog = None;
|
---|
821 | sVgaText = None;
|
---|
822 | sInfoText = None;
|
---|
823 | for oFile in oFailedResult.aoFiles:
|
---|
824 | if oFile.sKind == TestResultFileData.ksKind_LogReleaseVm:
|
---|
825 | if sVMLog is not None:
|
---|
826 | if investigateLogSet() is True:
|
---|
827 | return True;
|
---|
828 | sKrnlLog = None;
|
---|
829 | sScreenHash = None;
|
---|
830 | sVgaText = None;
|
---|
831 | sInfoText = None;
|
---|
832 | sVMLog = oCaseFile.getLogFile(oFile);
|
---|
833 | elif oFile.sKind == TestResultFileData.ksKind_LogGuestKernel:
|
---|
834 | sKrnlLog = oCaseFile.getLogFile(oFile);
|
---|
835 | elif oFile.sKind == TestResultFileData.ksKind_InfoVgaText:
|
---|
836 | sVgaText = '\n'.join([sLine.rstrip() for sLine in oCaseFile.getLogFile(oFile).split('\n')]);
|
---|
837 | elif oFile.sKind == TestResultFileData.ksKind_InfoCollection:
|
---|
838 | sInfoText = oCaseFile.getLogFile(oFile);
|
---|
839 | elif oFile.sKind == TestResultFileData.ksKind_ScreenshotFailure:
|
---|
840 | sScreenHash = oCaseFile.getScreenshotSha256(oFile);
|
---|
841 | if sScreenHash is not None:
|
---|
842 | sScreenHash = sScreenHash.lower();
|
---|
843 | self.vprint(u'%s %s' % ( sScreenHash, oFile.sFile,));
|
---|
844 | if sVMLog is not None and investigateLogSet() is True:
|
---|
845 | return True;
|
---|
846 |
|
---|
847 | return None;
|
---|
848 |
|
---|
849 |
|
---|
850 | def isResultFromVMRun(self, oFailedResult, sResultLog):
|
---|
851 | """
|
---|
852 | Checks if this result and corresponding log snippet looks like a VM run.
|
---|
853 | """
|
---|
854 |
|
---|
855 | # Look for startVmEx/ startVmAndConnectToTxsViaTcp and similar output in the log.
|
---|
856 | if sResultLog.find(' startVm') > 0:
|
---|
857 | return True;
|
---|
858 |
|
---|
859 | # Any other indicators? No?
|
---|
860 | _ = oFailedResult;
|
---|
861 | return False;
|
---|
862 |
|
---|
863 |
|
---|
864 | def investigateVBoxVMTest(self, oCaseFile, fSingleVM):
|
---|
865 | """
|
---|
866 | Checks out a VBox VM test.
|
---|
867 |
|
---|
868 | This is generic investigation of a test running one or more VMs, like
|
---|
869 | for example a smoke test or a guest installation test.
|
---|
870 |
|
---|
871 | The fSingleVM parameter is a hint, which probably won't come in useful.
|
---|
872 | """
|
---|
873 | _ = fSingleVM;
|
---|
874 |
|
---|
875 | #
|
---|
876 | # Get a list of test result failures we should be looking into and the main log.
|
---|
877 | #
|
---|
878 | aoFailedResults = oCaseFile.oTree.getListOfFailures();
|
---|
879 | sMainLog = oCaseFile.getMainLog();
|
---|
880 |
|
---|
881 | #
|
---|
882 | # There are a set of errors ending up on the top level result record.
|
---|
883 | # Should deal with these first.
|
---|
884 | #
|
---|
885 | if len(aoFailedResults) == 1 and aoFailedResults[0] == oCaseFile.oTree:
|
---|
886 | # Check if we've just got that XPCOM client smoke test shutdown issue. This will currently always
|
---|
887 | # be reported on the top result because vboxinstall.py doesn't add an error for it. It is easy to
|
---|
888 | # ignore other failures in the test if we're not a little bit careful here.
|
---|
889 | if sMainLog.find('vboxinstaller: Exit code: -11 (') > 0:
|
---|
890 | oCaseFile.noteReason(self.ktReason_XPCOM_Exit_Minus_11);
|
---|
891 | return self.caseClosed(oCaseFile);
|
---|
892 |
|
---|
893 | # Hang after starting VBoxSVC (e.g. idTestSet=136307258)
|
---|
894 | if self.isThisFollowedByTheseLines(sMainLog, 'oVBoxMgr=<vboxapi.VirtualBoxManager object at',
|
---|
895 | (' Timeout: ', ' Attempting to abort child...',) ):
|
---|
896 | if sMainLog.find('*** glibc detected *** /') > 0:
|
---|
897 | oCaseFile.noteReason(self.ktReason_XPCOM_VBoxSVC_Hang_Plus_Heap_Corruption);
|
---|
898 | else:
|
---|
899 | oCaseFile.noteReason(self.ktReason_XPCOM_VBoxSVC_Hang);
|
---|
900 | return self.caseClosed(oCaseFile);
|
---|
901 |
|
---|
902 | # Look for heap corruption without visible hang.
|
---|
903 | if sMainLog.find('*** glibc detected *** /') > 0 \
|
---|
904 | or sMainLog.find("-1073740940") > 0: # STATUS_HEAP_CORRUPTION / 0xc0000374
|
---|
905 | oCaseFile.noteReason(self.ktReason_Unknown_Heap_Corruption);
|
---|
906 | return self.caseClosed(oCaseFile);
|
---|
907 |
|
---|
908 | # Out of memory w/ timeout.
|
---|
909 | if sMainLog.find('sErrId=HostMemoryLow') > 0:
|
---|
910 | oCaseFile.noteReason(self.ktReason_Host_HostMemoryLow);
|
---|
911 | return self.caseClosed(oCaseFile);
|
---|
912 |
|
---|
913 | # Stale files like vts_rm.exe (windows).
|
---|
914 | offEnd = sMainLog.rfind('*** The test driver exits successfully. ***');
|
---|
915 | if offEnd > 0 and sMainLog.find('[Error 145] The directory is not empty: ', offEnd) > 0:
|
---|
916 | oCaseFile.noteReason(self.ktReason_Ignore_Stale_Files);
|
---|
917 | return self.caseClosed(oCaseFile);
|
---|
918 |
|
---|
919 | #
|
---|
920 | # XPCOM screwup
|
---|
921 | #
|
---|
922 | if sMainLog.find('AttributeError: \'NoneType\' object has no attribute \'addObserver\'') > 0:
|
---|
923 | oCaseFile.noteReason(self.ktReason_Buggy_Build_Broken_Build);
|
---|
924 | return self.caseClosed(oCaseFile);
|
---|
925 |
|
---|
926 | #
|
---|
927 | # Go thru each failed result.
|
---|
928 | #
|
---|
929 | for oFailedResult in aoFailedResults:
|
---|
930 | self.dprint(u'Looking at test result #%u - %s' % (oFailedResult.idTestResult, oFailedResult.getFullName(),));
|
---|
931 | sResultLog = TestSetData.extractLogSectionElapsed(sMainLog, oFailedResult.tsCreated, oFailedResult.tsElapsed);
|
---|
932 | if oFailedResult.sName == 'Installing VirtualBox':
|
---|
933 | self.vprint('TODO: Installation failure');
|
---|
934 |
|
---|
935 | elif oFailedResult.sName == 'Uninstalling VirtualBox':
|
---|
936 | self.vprint('TODO: Uninstallation failure');
|
---|
937 |
|
---|
938 | elif self.isResultFromVMRun(oFailedResult, sResultLog):
|
---|
939 | self.investigateVMResult(oCaseFile, oFailedResult, sResultLog);
|
---|
940 |
|
---|
941 | elif sResultLog.find('Exception: 0x800706be (Call to remote object failed (NS_ERROR_CALL_FAILED))') > 0:
|
---|
942 | oCaseFile.noteReasonForId(self.ktReason_XPCOM_NS_ERROR_CALL_FAILED, oFailedResult.idTestResult);
|
---|
943 |
|
---|
944 | elif sResultLog.find('The machine is not mutable (state is ') > 0:
|
---|
945 | self.vprint('Ignoring "machine not mutable" error as it is probably due to an earlier problem');
|
---|
946 | oCaseFile.noteReasonForId(self.ktHarmless, oFailedResult.idTestResult);
|
---|
947 |
|
---|
948 | elif sResultLog.find('** error: no action was specified') > 0 \
|
---|
949 | or sResultLog.find('(len(self._asXml, asText))') > 0:
|
---|
950 | oCaseFile.noteReasonForId(self.ktReason_Ignore_Buggy_Test_Driver, oFailedResult.idTestResult);
|
---|
951 |
|
---|
952 | else:
|
---|
953 | self.vprint(u'TODO: Cannot place idTestResult=%u - %s' % (oFailedResult.idTestResult, oFailedResult.sName,));
|
---|
954 | self.dprint(u'%s + %s <<\n%s\n<<' % (oFailedResult.tsCreated, oFailedResult.tsElapsed, sResultLog,));
|
---|
955 |
|
---|
956 | #
|
---|
957 | # Report home and close the case if we got them all, otherwise log it.
|
---|
958 | #
|
---|
959 | if len(oCaseFile.dReasonForResultId) >= len(aoFailedResults):
|
---|
960 | return self.caseClosed(oCaseFile);
|
---|
961 |
|
---|
962 | if len(oCaseFile.dReasonForResultId) > 0:
|
---|
963 | self.vprint(u'TODO: Got %u out of %u - close, but no cigar. :-/'
|
---|
964 | % (len(oCaseFile.dReasonForResultId), len(aoFailedResults)));
|
---|
965 | else:
|
---|
966 | self.vprint(u'XXX: Could not figure out anything at all! :-(');
|
---|
967 | return False;
|
---|
968 |
|
---|
969 |
|
---|
970 | def reasoningFailures(self):
|
---|
971 | """
|
---|
972 | Guess the reason for failures.
|
---|
973 | """
|
---|
974 | #
|
---|
975 | # Get a list of failed test sets without any assigned failure reason.
|
---|
976 | #
|
---|
977 | cGot = 0;
|
---|
978 | aoTestSets = self.oTestSetLogic.fetchFailedSetsWithoutReason(cHoursBack = self.oConfig.cHoursBack, tsNow = self.tsNow);
|
---|
979 | for oTestSet in aoTestSets:
|
---|
980 | self.dprint(u'');
|
---|
981 | self.dprint(u'reasoningFailures: Checking out test set #%u, status %s' % ( oTestSet.idTestSet, oTestSet.enmStatus,))
|
---|
982 |
|
---|
983 | #
|
---|
984 | # Open a case file and assign it to the right investigator.
|
---|
985 | #
|
---|
986 | (oTree, _ ) = self.oTestResultLogic.fetchResultTree(oTestSet.idTestSet);
|
---|
987 | oBuild = BuildDataEx().initFromDbWithId( self.oDb, oTestSet.idBuild, oTestSet.tsCreated);
|
---|
988 | oTestBox = TestBoxData().initFromDbWithGenId( self.oDb, oTestSet.idGenTestBox);
|
---|
989 | oTestGroup = TestGroupData().initFromDbWithId( self.oDb, oTestSet.idTestGroup, oTestSet.tsCreated);
|
---|
990 | oTestCase = TestCaseDataEx().initFromDbWithGenId( self.oDb, oTestSet.idGenTestCase, oTestSet.tsConfig);
|
---|
991 |
|
---|
992 | oCaseFile = VirtualTestSheriffCaseFile(self, oTestSet, oTree, oBuild, oTestBox, oTestGroup, oTestCase);
|
---|
993 |
|
---|
994 | if oTestSet.enmStatus == TestSetData.ksTestStatus_BadTestBox:
|
---|
995 | self.dprint(u'investigateBadTestBox is taking over %s.' % (oCaseFile.sLongName,));
|
---|
996 | fRc = self.investigateBadTestBox(oCaseFile);
|
---|
997 |
|
---|
998 | elif oCaseFile.isVBoxUnitTest():
|
---|
999 | self.dprint(u'investigateVBoxUnitTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1000 | fRc = self.investigateVBoxUnitTest(oCaseFile);
|
---|
1001 |
|
---|
1002 | elif oCaseFile.isVBoxInstallTest():
|
---|
1003 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1004 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
|
---|
1005 |
|
---|
1006 | elif oCaseFile.isVBoxUSBTest():
|
---|
1007 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1008 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
|
---|
1009 |
|
---|
1010 | elif oCaseFile.isVBoxStorageTest():
|
---|
1011 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1012 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
|
---|
1013 |
|
---|
1014 | elif oCaseFile.isVBoxGAsTest():
|
---|
1015 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1016 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
|
---|
1017 |
|
---|
1018 | elif oCaseFile.isVBoxAPITest():
|
---|
1019 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1020 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = True);
|
---|
1021 |
|
---|
1022 | elif oCaseFile.isVBoxBenchmarkTest():
|
---|
1023 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1024 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = False);
|
---|
1025 |
|
---|
1026 | elif oCaseFile.isVBoxSmokeTest():
|
---|
1027 | self.dprint(u'investigateVBoxVMTest is taking over %s.' % (oCaseFile.sLongName,));
|
---|
1028 | fRc = self.investigateVBoxVMTest(oCaseFile, fSingleVM = False);
|
---|
1029 |
|
---|
1030 | else:
|
---|
1031 | self.vprint(u'reasoningFailures: Unable to classify test set: %s' % (oCaseFile.sLongName,));
|
---|
1032 | fRc = False;
|
---|
1033 | cGot += fRc is True;
|
---|
1034 |
|
---|
1035 | self.vprint(u'reasoningFailures: Got %u out of %u' % (cGot, len(aoTestSets), ));
|
---|
1036 | return 0;
|
---|
1037 |
|
---|
1038 |
|
---|
1039 | def main(self):
|
---|
1040 | """
|
---|
1041 | The 'main' function.
|
---|
1042 | Return exit code (0, 1, etc).
|
---|
1043 | """
|
---|
1044 | # Database stuff.
|
---|
1045 | self.oDb = TMDatabaseConnection()
|
---|
1046 | self.oTestResultLogic = TestResultLogic(self.oDb);
|
---|
1047 | self.oTestSetLogic = TestSetLogic(self.oDb);
|
---|
1048 | self.oFailureReasonLogic = FailureReasonLogic(self.oDb);
|
---|
1049 | self.oTestResultFailureLogic = TestResultFailureLogic(self.oDb);
|
---|
1050 | self.asBsodReasons = self.oFailureReasonLogic.fetchForSheriffByNamedCategory(self.ksBsodCategory);
|
---|
1051 | self.asUnitTestReasons = self.oFailureReasonLogic.fetchForSheriffByNamedCategory(self.ksUnitTestCategory);
|
---|
1052 |
|
---|
1053 | # Get a fix on our 'now' before we do anything..
|
---|
1054 | self.oDb.execute('SELECT CURRENT_TIMESTAMP - interval \'%s hours\'', (self.oConfig.cStartHoursAgo,));
|
---|
1055 | self.tsNow = self.oDb.fetchOne();
|
---|
1056 |
|
---|
1057 | # If we're suppost to commit anything we need to get our user ID.
|
---|
1058 | rcExit = 0;
|
---|
1059 | if self.oConfig.fRealRun:
|
---|
1060 | self.oLogin = UserAccountLogic(self.oDb).tryFetchAccountByLoginName(VirtualTestSheriff.ksLoginName);
|
---|
1061 | if self.oLogin is None:
|
---|
1062 | rcExit = self.eprint('Cannot find my user account "%s"!' % (VirtualTestSheriff.ksLoginName,));
|
---|
1063 | else:
|
---|
1064 | self.uidSelf = self.oLogin.uid;
|
---|
1065 |
|
---|
1066 | # Do the stuff.
|
---|
1067 | if rcExit == 0:
|
---|
1068 | rcExit = self.selfCheck();
|
---|
1069 | if rcExit == 0:
|
---|
1070 | rcExit = self.badTestBoxManagement();
|
---|
1071 | rcExit2 = self.reasoningFailures();
|
---|
1072 | if rcExit == 0:
|
---|
1073 | rcExit = rcExit2;
|
---|
1074 |
|
---|
1075 | # Cleanup.
|
---|
1076 | self.oFailureReasonLogic = None;
|
---|
1077 | self.oTestResultFailureLogic = None;
|
---|
1078 | self.oTestSetLogic = None;
|
---|
1079 | self.oTestResultLogic = None;
|
---|
1080 | self.oDb.close();
|
---|
1081 | self.oDb = None;
|
---|
1082 | if self.oLogFile is not None:
|
---|
1083 | self.oLogFile.close();
|
---|
1084 | self.oLogFile = None;
|
---|
1085 | return rcExit;
|
---|
1086 |
|
---|
1087 | if __name__ == '__main__':
|
---|
1088 | sys.exit(VirtualTestSheriff().main());
|
---|
1089 |
|
---|