testboxtasks.py@ 78314

Last change on this file since 78314 was 77165, checked in by vboxsync, 6 years ago
testboxscript: Save all the TESTBOX_xxxx variables in stat/environ.txt so external tools can fish out time outs and such.
Property svn:eol-style set to `native` Property svn:keywords set to `Author Date Id Revision`
File size: 34.2 KB

Line
1	# -- coding: utf-8 --
2	# $Id: testboxtasks.py 77165 2019-02-05 13:59:37Z vboxsync $
3
4	"""
5	TestBox Script - Async Tasks.
6	"""
7
8	__copyright__ = \
9	"""
10	Copyright (C) 2012-2019 Oracle Corporation
11
12	This file is part of VirtualBox Open Source Edition (OSE), as
13	available from http://www.virtualbox.org. This file is free software;
14	you can redistribute it and/or modify it under the terms of the GNU
15	General Public License (GPL) as published by the Free Software
16	Foundation, in version 2 as it comes in the "COPYING" file of the
17	VirtualBox OSE distribution. VirtualBox OSE is distributed in the
18	hope that it will be useful, but WITHOUT ANY WARRANTY of any kind.
19
20	The contents of this file may alternatively be used under the terms
21	of the Common Development and Distribution License Version 1.0
22	(CDDL) only, as it comes in the "COPYING.CDDL" file of the
23	VirtualBox OSE distribution, in which case the provisions of the
24	CDDL are applicable instead of those of the GPL.
25
26	You may elect to license modified versions of this file under the
27	terms and conditions of either the GPL or the CDDL or both.
28	"""
29	__version__ = "$Revision: 77165 $"
30
31
32	# Standard python imports.
33	from datetime import datetime
34	import os
35	import re
36	import signal;
37	import sys
38	import subprocess
39	import threading
40	import time
41
42	# Validation Kit imports.
43	from common import constants
44	from common import utils;
45	from common import webutils;
46	import testboxcommons
47
48	# Figure where we are.
49	try: __file__
50	except: __file__ = sys.argv[0];
51	g_ksTestScriptDir = os.path.dirname(os.path.abspath(__file__));
52
53
54
55	class TestBoxBaseTask(object):
56	"""
57	Asynchronous task employing a thread to do the actual work.
58	"""
59
60	## Time to wait for a task to terminate.
61	kcSecTerminateTimeout = 60
62
63	def __init__(self, oTestBoxScript, cSecTimeout, fnThreadProc):
64	self._oTestBoxScript = oTestBoxScript;
65	self._cSecTimeout = cSecTimeout;
66	self._tsSecStarted = utils.timestampSecond();
67	self.__oRLock = threading.RLock();
68	self._oCv = threading.Condition(self.__oRLock);
69	self._fRunning = True; # Protected by lock.
70	self._fShouldTerminate = False; # Protected by lock.
71
72	# Spawn the worker thread.
73	self._oThread = threading.Thread(target=fnThreadProc);
74	self._oThread.daemon = True;
75	self._oThread.start();
76
77	def _lock(self):
78	""" Take the CV lock. """
79	self._oCv.acquire();
80
81	def _unlock(self):
82	""" Release the CV lock. """
83	self._oCv.release();
84
85	def _complete(self):
86	"""
87	Indicate that the task is complete, waking up the main thread.
88	Usually called at the end of the thread procedure.
89	"""
90	self._lock();
91	self._fRunning = False;
92	self._oCv.notifyAll();
93	self._unlock();
94
95	def isRunning(self):
96	""" Check if the task is still running. """
97	self._lock();
98	fRunning = self._fRunning;
99	self._unlock();
100	return fRunning;
101
102	def wait(self, cSecTimeout):
103	""" Wait for the task to complete. """
104	self._lock();
105	fRunning = self._fRunning;
106	if fRunning is True and cSecTimeout > 0:
107	self._oCv.wait(cSecTimeout)
108	self._unlock();
109	return fRunning;
110
111	def terminate(self, cSecTimeout = kcSecTerminateTimeout):
112	""" Terminate the task. """
113	self._lock();
114	self._fShouldTerminate = True;
115	self._unlock();
116
117	return self.wait(cSecTimeout);
118
119	def _shouldTerminate(self):
120	"""
121	Returns True if we should terminate, False if not.
122	"""
123	self._lock();
124	fShouldTerminate = self._fShouldTerminate is True;
125	self._unlock();
126	return fShouldTerminate;
127
128
129	class TestBoxTestDriverTask(TestBoxBaseTask):
130	"""
131	Base class for tasks involving test drivers.
132	"""
133
134	## When to flush the backlog of log messages.
135	kcchMaxBackLog = 32768;
136
137	## The backlog sync time (seconds).
138	kcSecBackLogFlush = 30;
139
140	## The timeout for the cleanup job (5 mins).
141	kcSecCleanupTimeout = 300;
142	## The timeout to wait for the abort command before killing it.
143	kcSecAbortTimeout = 300;
144
145	## The timeout to wait for the final output to be processed.
146	kcSecFinalOutputTimeout = 180;
147	## The timeout to wait for the abort command output to be processed.
148	kcSecAbortCmdOutputTimeout = 30;
149	## The timeout to wait for the terminate output to be processed.
150	kcSecTerminateOutputTimeout = 30;
151	## The timeout to wait for the kill output to be processed.
152	kcSecKillOutputTimeout = 30;
153
154	## The timeout for talking to the test manager.
155	ksecTestManagerTimeout = 60;
156
157
158	def __init__(self, oTestBoxScript, fnThreadProc, cSecTimeout, idResult, sScriptCmdLine):
159	"""
160	Class instance init
161	"""
162	# Init our instance data.
163	self._idResult = idResult;
164	self._sScriptCmdLine = sScriptCmdLine;
165	self._oChild = None;
166	self._oBackLogLock = threading.RLock();
167	self._oBackLogFlushLock = threading.RLock();
168	self._asBackLog = [];
169	self._cchBackLog = 0;
170	self._secTsBackLogFlush = utils.timestampSecond();
171
172	# Init super.
173	TestBoxBaseTask.__init__(self, oTestBoxScript, cSecTimeout, fnThreadProc);
174
175	def terminate(self, cSecTimeout = kcSecCleanupTimeout):
176	""" Reimplement with higher default timeout. """
177	return TestBoxBaseTask.terminate(self, cSecTimeout);
178
179	def _logFlush(self, oGivenConnection = None):
180	"""
181	Flushes the log to the test manager.
182
183	No exceptions.
184	"""
185	fRc = True;
186	self._oBackLogFlushLock.acquire();
187
188	# Grab the current back log.
189	self._oBackLogLock.acquire();
190	asBackLog = self._asBackLog;
191	self._asBackLog = [];
192	self._cchBackLog = 0;
193	self._secTsBackLogFlush = utils.timestampSecond();
194	self._oBackLogLock.release();
195
196	# If there is anything to flush, flush it.
197	if asBackLog:
198	sBody = '';
199	for sLine in asBackLog:
200	sBody += sLine + '\n';
201
202	oConnection = None;
203	try:
204	if oGivenConnection is None:
205	oConnection = self._oTestBoxScript.openTestManagerConnection();
206	oConnection.postRequest(constants.tbreq.LOG_MAIN, {constants.tbreq.LOG_PARAM_BODY: sBody});
207	oConnection.close();
208	else:
209	oGivenConnection.postRequest(constants.tbreq.LOG_MAIN, {constants.tbreq.LOG_PARAM_BODY: sBody});
210	except Exception as oXcpt:
211	testboxcommons.log('_logFlush error: %s' % (oXcpt,));
212	if len(sBody) < self.kcchMaxBackLog * 4:
213	self._oBackLogLock.acquire();
214	asBackLog.extend(self._asBackLog);
215	self._asBackLog = asBackLog;
216	# Don't restore _cchBackLog as there is no point in retrying immediately.
217	self._oBackLogLock.release();
218	if oConnection is not None: # Be kind to apache.
219	try: oConnection.close();
220	except: pass;
221	fRc = False;
222
223	self._oBackLogFlushLock.release();
224	return fRc;
225
226	def flushLogOnConnection(self, oConnection):
227	"""
228	Attempts to flush the logon the given connection.
229
230	No exceptions.
231	"""
232	return self._logFlush(oConnection);
233
234	def _logInternal(self, sMessage, fPrefix = True, fFlushCheck = False):
235	"""
236	Internal logging.
237	Won't flush the backlog, returns a flush indicator so the caller can
238	do it instead.
239	"""
240	if fPrefix:
241	try:
242	oNow = datetime.utcnow();
243	sTs = '%02u:%02u:%02u.%06u ' % (oNow.hour, oNow.minute, oNow.second, oNow.microsecond);
244	except Exception as oXcpt:
245	sTs = 'oXcpt=%s ' % (oXcpt);
246	sFullMsg = sTs + sMessage;
247	else:
248	sFullMsg = sMessage;
249
250	self._oBackLogLock.acquire();
251	self._asBackLog.append(sFullMsg);
252	cchBackLog = self._cchBackLog + len(sFullMsg) + 1;
253	self._cchBackLog = cchBackLog;
254	secTsBackLogFlush = self._secTsBackLogFlush;
255	self._oBackLogLock.release();
256
257	testboxcommons.log(sFullMsg);
258	return fFlushCheck \
259	and ( cchBackLog >= self.kcchMaxBackLog \
260	or utils.timestampSecond() - secTsBackLogFlush >= self.kcSecBackLogFlush);
261
262	def _log(self, sMessage):
263	"""
264	General logging function, will flush.
265	"""
266	if self._logInternal(sMessage, fFlushCheck = True):
267	self._logFlush();
268	return True;
269
270	def _reportDone(self, sResult):
271	"""
272	Report EXEC job done to the test manager.
273
274	sResult is a value from constants.result.
275	"""
276	## @todo optimize this to use one server connection.
277
278	#
279	# Log it.
280	#
281	assert sResult in constants.result.g_kasValidResults;
282	self._log('Done %s' % (sResult,));
283
284	#
285	# Report it.
286	#
287	fRc = True;
288	secStart = utils.timestampSecond();
289	while True:
290	self._logFlush(); ## @todo Combine this with EXEC_COMPLETED.
291	oConnection = None;
292	try:
293	oConnection = self._oTestBoxScript.openTestManagerConnection();
294	oConnection.postRequest(constants.tbreq.EXEC_COMPLETED, {constants.tbreq.EXEC_COMPLETED_PARAM_RESULT: sResult});
295	oConnection.close();
296	except Exception as oXcpt:
297	if utils.timestampSecond() - secStart < self.ksecTestManagerTimeout:
298	self._log('_reportDone exception (%s) - retrying...' % (oXcpt,));
299	time.sleep(2);
300	continue;
301	self._log('_reportDone error: %s' % (oXcpt,));
302	if oConnection is not None: # Be kind to apache.
303	try: oConnection.close();
304	except: pass;
305	fRc = False;
306	break;
307
308	#
309	# Mark the task as completed.
310	#
311	self._complete();
312	return fRc;
313
314	def _assembleArguments(self, sAction, fWithInterpreter = True):
315	"""
316	Creates an argument array for subprocess.Popen, splitting the
317	sScriptCmdLine like bourne shell would.
318	fWithInterpreter is used (False) when checking that the script exists.
319
320	Returns None on bad input.
321	"""
322
323	#
324	# This is a good place to export the test set id to the environment.
325	#
326	os.environ['TESTBOX_TEST_SET_ID'] = str(self._idResult);
327	cTimeoutLeft = utils.timestampSecond() - self._tsSecStarted;
328	cTimeoutLeft = 0 if cTimeoutLeft >= self._cSecTimeout else self._cSecTimeout - cTimeoutLeft;
329	os.environ['TESTBOX_TIMEOUT'] = str(cTimeoutLeft);
330	os.environ['TESTBOX_TIMEOUT_ABS'] = str(self._tsSecStarted + self._cSecTimeout);
331
332	#
333	# Do replacements and split the command line into arguments.
334	#
335	if self._sScriptCmdLine.find('@ACTION@') >= 0:
336	sCmdLine = self._sScriptCmdLine.replace('@ACTION@', sAction);
337	else:
338	sCmdLine = self._sScriptCmdLine + ' ' + sAction;
339	for sVar in [ 'TESTBOX_PATH_BUILDS', 'TESTBOX_PATH_RESOURCES', 'TESTBOX_PATH_SCRATCH', 'TESTBOX_PATH_SCRIPTS',
340	'TESTBOX_PATH_UPLOAD', 'TESTBOX_UUID', 'TESTBOX_REPORTER', 'TESTBOX_ID', 'TESTBOX_TEST_SET_ID',
341	'TESTBOX_TIMEOUT', 'TESTBOX_TIMEOUT_ABS' ]:
342	if sCmdLine.find('${' + sVar + '}') >= 0:
343	sCmdLine = sCmdLine.replace('${' + sVar + '}', os.environ[sVar]);
344
345	asArgs = utils.argsSplit(sCmdLine);
346
347	#
348	# Massage argv[0]:
349	# - Convert portable slashes ('/') to the flavor preferred by the
350	# OS we're currently running on.
351	# - Run python script thru the current python interpreter (important
352	# on systems that doesn't sport native hash-bang script execution).
353	#
354	asArgs[0] = asArgs[0].replace('/', os.path.sep);
355	if not os.path.isabs(asArgs[0]):
356	asArgs[0] = os.path.join(self._oTestBoxScript.getPathScripts(), asArgs[0]);
357
358	if asArgs[0].endswith('.py') and fWithInterpreter:
359	if sys.executable:
360	asArgs.insert(0, sys.executable);
361	else:
362	asArgs.insert(0, 'python');
363
364	return asArgs;
365
366	def _outputThreadProc(self, oChild, oStdOut, sAction):
367	"""
368	Thread procedure for the thread that reads the output of the child
369	process. We use a dedicated thread for this purpose since non-blocking
370	I/O may be hard to keep portable according to hints around the web...
371	"""
372	oThread = oChild.oOutputThread;
373	while not oThread.fPleaseQuit:
374	# Get a line.
375	try:
376	sLine = oStdOut.readline();
377	except Exception as oXcpt:
378	self._log('child (%s) pipe I/O error: %s' % (sAction, oXcpt,));
379	break;
380
381	# EOF?
382	if not sLine:
383	break;
384
385	# Strip trailing new line (DOS and UNIX).
386	if sLine.endswith("\r\n"):
387	sLine = sLine[0:-2];
388	elif sLine.endswith("\n"):
389	sLine = sLine[0:-1];
390
391	# Log it.
392	if self._logInternal(sLine, fPrefix = False, fFlushCheck = True):
393	self._logFlush();
394
395	# Close the stdout pipe in case we were told to get lost.
396	try:
397	oStdOut.close();
398	except Exception as oXcpt:
399	self._log('warning: Exception closing stdout pipe of "%s" child: %s' % (sAction, oXcpt,));
400
401	# This is a bit hacky, but try reap the child so it won't hang as
402	# defunkt during abort/timeout.
403	if oChild.poll() is None:
404	for _ in range(15):
405	time.sleep(0.2);
406	if oChild.poll() is not None:
407	break;
408
409	oChild = None;
410	return None;
411
412	def _spawnChild(self, sAction):
413	"""
414	Spawns the child process, returning success indicator + child object.
415	"""
416
417	# Argument list.
418	asArgs = self._assembleArguments(sAction)
419	if asArgs is None:
420	self._log('Malformed command line: "%s"' % (self._sScriptCmdLine,));
421	return (False, None);
422
423	# Spawn child.
424	try:
425	oChild = utils.processPopenSafe(asArgs,
426	shell = False,
427	bufsize = -1,
428	stdout = subprocess.PIPE,
429	stderr = subprocess.STDOUT,
430	cwd = self._oTestBoxScript.getPathSpill(),
431	universal_newlines = True,
432	close_fds = (False if utils.getHostOs() == 'win' else True),
433	preexec_fn = (None if utils.getHostOs() in ['win', 'os2']
434	else os.setsid)); # pylint: disable=E1101
435	except Exception as oXcpt:
436	self._log('Error creating child process %s: %s' % (asArgs, oXcpt));
437	return (False, None);
438
439	oChild.sTestBoxScriptAction = sAction;
440
441	# Start output thread, extending the child object to keep track of it.
442	oChild.oOutputThread = threading.Thread(target=self._outputThreadProc, args=(oChild, oChild.stdout, sAction))
443	oChild.oOutputThread.daemon = True;
444	oChild.oOutputThread.fPleaseQuit = False; # Our extension.
445	oChild.oOutputThread.start();
446
447	return (True, oChild);
448
449	def _monitorChild(self, cSecTimeout, fTryKillCommand = True, oChild = None):
450	"""
451	Monitors the child process. If the child executes longer that
452	cSecTimeout allows, we'll terminate it.
453	Returns Success indicator and constants.result value.
454	"""
455
456	if oChild is None:
457	oChild = self._oChild;
458
459	iProcGroup = oChild.pid;
460	if utils.getHostOs() in ['win', 'os2'] or iProcGroup <= 0:
461	iProcGroup = -2;
462
463	#
464	# Do timeout processing and check the health of the child.
465	#
466	sResult = constants.result.PASSED;
467	seStarted = utils.timestampSecond();
468	while True:
469	# Check status.
470	iRc = oChild.poll();
471	if iRc is not None:
472	self._log('Child doing "%s" completed with exit code %d' % (oChild.sTestBoxScriptAction, iRc));
473	oChild.oOutputThread.join(self.kcSecFinalOutputTimeout);
474
475	if oChild is self._oChild:
476	self._oChild = None;
477
478	if iRc == constants.rtexitcode.SKIPPED:
479	return (True, constants.result.SKIPPED);
480	if iRc != constants.rtexitcode.SUCCESS:
481	return (False, constants.result.FAILED);
482	return (True, constants.result.PASSED);
483
484	# Check for abort first, since that has less of a stigma.
485	if self._shouldTerminate() is True:
486	sResult = constants.result.ABORTED;
487	break;
488
489	# Check timeout.
490	cSecElapsed = utils.timestampSecond() - seStarted;
491	if cSecElapsed > cSecTimeout:
492	self._log('Timeout: %u secs (limit %u secs)' % (cSecElapsed, cSecTimeout));
493	sResult = constants.result.TIMED_OUT;
494	break;
495
496	# Wait.
497	cSecLeft = cSecTimeout - cSecElapsed;
498	oChild.oOutputThread.join(15 if cSecLeft > 15 else (cSecLeft + 1));
499
500	#
501	# If the child is still alive, try use the abort command to stop it
502	# very gently. This let's the testdriver clean up daemon processes
503	# and such that our code below won't catch.
504	#
505	if fTryKillCommand and oChild.poll() is None:
506	self._log('Attempting to abort child...');
507	(fRc2, oAbortChild) = self._spawnChild('abort');
508	if oAbortChild is not None and fRc2 is True:
509	self._monitorChild(self.kcSecAbortTimeout, False, oAbortChild);
510	oAbortChild = None;
511
512	#
513	# If the child is still alive, try the polite way.
514	#
515	if oChild.poll() is None:
516	self._log('Attempting to terminate child doing "%s"...' % (oChild.sTestBoxScriptAction,));
517
518	if iProcGroup > 0:
519	try:
520	os.killpg(iProcGroup, signal.SIGTERM); # pylint: disable=E1101
521	except Exception as oXcpt:
522	self._log('killpg() failed: %s' % (oXcpt,));
523
524	try:
525	self._oChild.terminate();
526	oChild.oOutputThread.join(self.kcSecTerminateOutputTimeout);
527	except Exception as oXcpt:
528	self._log('terminate() failed: %s' % (oXcpt,));
529
530	#
531	# If the child doesn't respond to polite, kill it. Always do a killpg
532	# should there be any processes left in the group.
533	#
534	if iProcGroup > 0:
535	try:
536	os.killpg(iProcGroup, signal.SIGKILL); # pylint: disable=E1101
537	except Exception as oXcpt:
538	self._log('killpg() failed: %s' % (oXcpt,));
539
540	if oChild.poll() is None:
541	self._log('Attemting to kill child doing "%s"...' % (oChild.sTestBoxScriptAction,));
542	try:
543	self._oChild.kill();
544	oChild.oOutputThread.join(self.kcSecKillOutputTimeout);
545	except Exception as oXcpt:
546	self._log('kill() failed: %s' % (oXcpt,));
547
548	#
549	# Give the whole mess a couple of more seconds to respond in case the
550	# output thread exitted prematurely for some weird reason.
551	#
552	if oChild.poll() is None:
553	time.sleep(2);
554	time.sleep(2);
555	time.sleep(2);
556
557	iRc = oChild.poll();
558	if iRc is not None:
559	self._log('Child doing "%s" aborted with exit code %d' % (oChild.sTestBoxScriptAction, iRc));
560	else:
561	self._log('Child doing "%s" is still running, giving up...' % (oChild.sTestBoxScriptAction,));
562	## @todo in this case we should probably try reboot the testbox...
563	oChild.oOutputThread.fPleaseQuit = True;
564
565	if oChild is self._oChild:
566	self._oChild = None;
567	return (False, sResult);
568
569	def _terminateChild(self):
570	"""
571	Terminates the child forcefully.
572	"""
573	if self._oChild is not None:
574	pass;
575
576	def _cleanupAfter(self):
577	"""
578	Cleans up after a test failure. (On success, cleanup is implicit.)
579	"""
580	assert self._oChild is None;
581
582	#
583	# Tell the script to clean up.
584	#
585	if self._sScriptCmdLine: # can be empty if cleanup crashed.
586	(fRc, self._oChild) = self._spawnChild('cleanup-after');
587	if fRc is True:
588	(fRc, _) = self._monitorChild(self.kcSecCleanupTimeout, False);
589	self._terminateChild();
590	else:
591	fRc = False;
592
593	#
594	# Wipe the stuff clean.
595	#
596	fRc2 = self._oTestBoxScript.reinitScratch(fnLog = self._log, cRetries = 6);
597
598	return fRc and fRc2;
599
600
601
602	class TestBoxCleanupTask(TestBoxTestDriverTask):
603	"""
604	Special asynchronous task for cleaning up a stale test when starting the
605	testbox script. It's assumed that the reason for the stale test lies in
606	it causing a panic, reboot, or similar, so we'll also try collect some
607	info about recent system crashes and reboots.
608	"""
609
610	def __init__(self, oTestBoxScript):
611	# Read the old state, throwing a fit if it's invalid.
612	sScriptState = oTestBoxScript.getPathState();
613	sScriptCmdLine = self._readStateFile(os.path.join(sScriptState, 'script-cmdline.txt'));
614	sResultId = self._readStateFile(os.path.join(sScriptState, 'result-id.txt'));
615	try:
616	idResult = int(sResultId);
617	if idResult <= 0 or idResult >= 0x7fffffff:
618	raise Exception('');
619	except:
620	raise Exception('Invalid id value "%s" found in %s' % (sResultId, os.path.join(sScriptState, 'result-id.txt')));
621
622	sTestBoxId = self._readStateFile(os.path.join(sScriptState, 'testbox-id.txt'));
623	try:
624	self.idTestBox = int(sTestBoxId);
625	if self.idTestBox <= 0 or self.idTestBox >= 0x7fffffff:
626	raise Exception('');
627	except:
628	raise Exception('Invalid id value "%s" found in %s' % (sTestBoxId, os.path.join(sScriptState, 'testbox-id.txt')));
629	self.sTestBoxName = self._readStateFile(os.path.join(sScriptState, 'testbox-name.txt'));
630
631	# Init super.
632	TestBoxTestDriverTask.__init__(self, oTestBoxScript, self._threadProc, self.kcSecCleanupTimeout,
633	idResult, sScriptCmdLine);
634
635	@staticmethod
636	def _readStateFile(sPath):
637	"""
638	Reads a state file, returning a string on success and otherwise raising
639	an exception.
640	"""
641	try:
642	oFile = open(sPath, "rb");
643	sStr = oFile.read();
644	sStr = sStr.decode('utf-8');
645	oFile.close();
646	return sStr.strip();
647	except Exception as oXcpt:
648	raise Exception('Failed to read "%s": %s' % (sPath, oXcpt));
649
650	def _threadProc(self):
651	"""
652	Perform the actual clean up on script startup.
653	"""
654
655	#
656	# First make sure we won't repeat this exercise should it turn out to
657	# trigger another reboot/panic/whatever.
658	#
659	sScriptCmdLine = os.path.join(self._oTestBoxScript.getPathState(), 'script-cmdline.txt');
660	try:
661	os.remove(sScriptCmdLine);
662	oFile = open(sScriptCmdLine, 'wb');
663	oFile.close();
664	except Exception as oXcpt:
665	self._log('Error truncating "%s": %s' % (sScriptCmdLine, oXcpt));
666
667	#
668	# Report the incident.
669	#
670	self._log('Seems we rebooted!');
671	self._log('script-cmdline="%s"' % (self._sScriptCmdLine));
672	self._log('result-id=%d' % (self._idResult));
673	self._log('testbox-id=%d' % (self.idTestBox));
674	self._log('testbox-name=%s' % (self.sTestBoxName));
675	self._logFlush();
676
677	# System specific info.
678	sOs = utils.getHostOs();
679	if sOs == 'darwin':
680	self._log('NVRAM Panic Info:\n%s\n' % (self.darwinGetPanicInfo(),));
681
682	self._logFlush();
683	## @todo Add some special command for reporting this situation so we get something
684	# useful in the event log.
685
686	#
687	# Do the cleaning up.
688	#
689	self._cleanupAfter();
690
691	self._reportDone(constants.result.REBOOTED);
692	return False;
693
694	def darwinGetPanicInfo(self):
695	"""
696	Returns a string with the aapl,panic-info content.
697	"""
698	# Retriev the info.
699	try:
700	sRawInfo = utils.processOutputChecked(['nvram', 'aapl,panic-info']);
701	except Exception as oXcpt:
702	return 'exception running nvram: %s' % (oXcpt,);
703
704	# Decode (%xx) and decompact it (7-bit -> 8-bit).
705	ahDigits = \
706	{
707	'0': 0, '1': 1, '2': 2, '3': 3, '4': 4, '5': 5, '6': 6, '7': 7,
708	'8': 8, '9': 9, 'a': 10, 'b': 11, 'c': 12, 'd': 13, 'e': 14, 'f': 15,
709	};
710	sInfo = '';
711	off = len('aapl,panic-info') + 1;
712	iBit = 0;
713	bLow = 0;
714
715	while off < len(sRawInfo):
716	# isprint is used to determine whether to %xx or %c it, so we have to
717	# be a little careful before assuming % sequences are hex bytes.
718	if sRawInfo[off] == '%' \
719	and off + 3 <= len(sRawInfo) \
720	and sRawInfo[off + 1] in ahDigits \
721	and sRawInfo[off + 2] in ahDigits:
722	bCur = ahDigits[sRawInfo[off + 1]] * 0x10 + ahDigits[sRawInfo[off + 2]];
723	off += 3;
724	else:
725	bCur = ord(sRawInfo[off]);
726	off += 1;
727
728	sInfo += chr(((bCur & (0x7f >> iBit)) << iBit) \| bLow);
729	bLow = bCur >> (7 - iBit);
730
731	if iBit < 6:
732	iBit += 1;
733	else:
734	# Final bit in sequence.
735	sInfo += chr(bLow);
736	bLow = 0;
737	iBit = 0;
738
739	# Expand shorthand.
740	sInfo = sInfo.replace('@', 'com.apple.');
741	sInfo = sInfo.replace('>', 'com.apple.driver.');
742	sInfo = sInfo.replace('\|', 'com.apple.iokit.');
743	sInfo = sInfo.replace('$', 'com.apple.security.');
744	sInfo = sInfo.replace('!A', 'Apple');
745	sInfo = sInfo.replace('!a', 'Action');
746	sInfo = sInfo.replace('!B', 'Bluetooth');
747	sInfo = sInfo.replace('!C', 'Controller');
748	sInfo = sInfo.replace('!F', 'Family');
749	sInfo = sInfo.replace('!I', 'Intel');
750	sInfo = sInfo.replace('!U', 'AppleUSB');
751	sInfo = sInfo.replace('!P', 'Profile');
752
753	# Done.
754	return sInfo
755
756
757	class TestBoxExecTask(TestBoxTestDriverTask):
758	"""
759	Implementation of a asynchronous EXEC task.
760
761	This uses a thread for doing the actual work, i.e. starting and monitoring
762	the child process, processing its output, and more.
763	"""
764
765	def __init__(self, oTestBoxScript, idResult, sScriptZips, sScriptCmdLine, cSecTimeout):
766	"""
767	Class instance init
768	"""
769	# Init our instance data.
770	self._sScriptZips = sScriptZips;
771
772	# Init super.
773	TestBoxTestDriverTask.__init__(self, oTestBoxScript, self._threadProc, cSecTimeout, idResult, sScriptCmdLine);
774
775	@staticmethod
776	def _writeStateFile(sPath, sContent):
777	"""
778	Writes a state file, raising an exception on failure.
779	"""
780	try:
781	oFile = open(sPath, "wb");
782	oFile.write(sContent.encode('utf-8'));
783	oFile.flush();
784	try: os.fsync(oFile.fileno());
785	except: pass;
786	oFile.close();
787	except Exception as oXcpt:
788	raise Exception('Failed to write "%s": %s' % (sPath, oXcpt));
789	return True;
790
791	@staticmethod
792	def _environTxtContent():
793	"""
794	Collects environment variables and values for the environ.txt stat file
795	(for external monitoring tool).
796	"""
797	sText = '';
798	for sVar in [ 'TESTBOX_PATH_BUILDS', 'TESTBOX_PATH_RESOURCES', 'TESTBOX_PATH_SCRATCH', 'TESTBOX_PATH_SCRIPTS',
799	'TESTBOX_PATH_UPLOAD', 'TESTBOX_HAS_HW_VIRT', 'TESTBOX_HAS_NESTED_PAGING', 'TESTBOX_HAS_IOMMU',
800	'TESTBOX_SCRIPT_REV', 'TESTBOX_CPU_COUNT', 'TESTBOX_MEM_SIZE', 'TESTBOX_SCRATCH_SIZE',
801	'TESTBOX_WITH_RAW_MODE', 'TESTBOX_WITH_RAW_MODE', 'TESTBOX_MANAGER_URL', 'TESTBOX_UUID',
802	'TESTBOX_REPORTER', 'TESTBOX_NAME', 'TESTBOX_ID', 'TESTBOX_TEST_SET_ID',
803	'TESTBOX_TIMEOUT', 'TESTBOX_TIMEOUT_ABS', ]:
804	sValue = os.environ.get(sVar);
805	if sValue:
806	sText += sVar + '=' + sValue + '\n';
807	return sText;
808
809	def _saveState(self):
810	"""
811	Saves the task state on disk so we can launch a TestBoxCleanupTask job
812	if the test should cause system panic or similar.
813
814	Note! May later be extended to support tests that reboots the host.
815	"""
816	sScriptState = self._oTestBoxScript.getPathState();
817	try:
818	self._writeStateFile(os.path.join(sScriptState, 'script-cmdline.txt'), self._sScriptCmdLine);
819	self._writeStateFile(os.path.join(sScriptState, 'result-id.txt'), str(self._idResult));
820	self._writeStateFile(os.path.join(sScriptState, 'testbox-id.txt'), str(self._oTestBoxScript.getTestBoxId()));
821	self._writeStateFile(os.path.join(sScriptState, 'testbox-name.txt'), self._oTestBoxScript.getTestBoxName());
822	self._writeStateFile(os.path.join(sScriptState, 'environ.txt'), self._environTxtContent());
823	except Exception as oXcpt:
824	self._log('Failed to write state: %s' % (oXcpt,));
825	return False;
826	return True;
827
828	def _downloadAndUnpackScriptZips(self):
829	"""
830	Downloads/copies the script ZIPs into TESTBOX_SCRIPT and unzips them to
831	the same directory.
832
833	Raises no exceptions, returns log + success indicator instead.
834	"""
835	sPathScript = self._oTestBoxScript.getPathScripts();
836	asArchives = self._sScriptZips.split(',');
837	for sArchive in asArchives:
838	sArchive = sArchive.strip();
839	if not sArchive:
840	continue;
841
842	# Figure the destination name (in scripts).
843	sDstFile = webutils.getFilename(sArchive);
844	if len(sDstFile) < 1 \
845	or re.search('[^a-zA-Z0-9 !#$%&\'()@^_`{}~.-]', sDstFile) is not None: # FAT charset sans 128-255 + '.'.
846	self._log('Malformed script zip filename: %s' % (sArchive,));
847	return False;
848	sDstFile = os.path.join(sPathScript, sDstFile);
849
850	# Do the work.
851	if webutils.downloadFile(sArchive, sDstFile, self._oTestBoxScript.getPathBuilds(), self._log, self._log) is not True:
852	return False;
853	asFiles = utils.unpackFile(sDstFile, sPathScript, self._log, self._log);
854	if asFiles is None:
855	return False;
856
857	# Since zip files doesn't always include mode masks, set the X bit
858	# of all of them so we can execute binaries and hash-bang scripts.
859	for sFile in asFiles:
860	utils.chmodPlusX(sFile);
861
862	return True;
863
864	def _threadProc(self):
865	"""
866	Do the work of an EXEC command.
867	"""
868
869	sResult = constants.result.PASSED;
870
871	#
872	# Start by preparing the scratch directories.
873	#
874	# Note! Failures at this stage are not treated as real errors since
875	# they may be caused by the previous test and other circumstances
876	# so we don't want to go fail a build because of this.
877	#
878	fRc = self._oTestBoxScript.reinitScratch(self._logInternal);
879	fNeedCleanUp = fRc;
880	if fRc is True:
881	fRc = self._downloadAndUnpackScriptZips();
882	testboxcommons.log2('_threadProc: _downloadAndUnpackScriptZips -> %s' % (fRc,));
883	if fRc is not True:
884	sResult = constants.result.BAD_TESTBOX;
885
886	#
887	# Make sure the script exists.
888	#
889	if fRc is True:
890	sScript = self._assembleArguments('none', fWithInterpreter = False)[0];
891	if not os.path.exists(sScript):
892	self._log('The test driver script "%s" cannot be found.' % (sScript,));
893	sDir = sScript;
894	while len(sDir) > 3:
895	sDir = os.path.dirname(sDir);
896	if os.path.exists(sDir):
897	self._log('First existing parent directory is "%s".' % (sDir,));
898	break;
899	fRc = False;
900
901	if fRc is True:
902	#
903	# Start testdriver script.
904	#
905	fRc = self._saveState();
906	if fRc:
907	(fRc, self._oChild) = self._spawnChild('all');
908	testboxcommons.log2('_threadProc: _spawnChild -> %s, %s' % (fRc, self._oChild));
909	if fRc:
910	(fRc, sResult) = self._monitorChild(self._cSecTimeout);
911	testboxcommons.log2('_threadProc: _monitorChild -> %s' % (fRc,));
912
913	# If the run failed, do explicit cleanup.
914	if fRc is not True:
915	testboxcommons.log2('_threadProc: explicit cleanups...');
916	self._terminateChild();
917	self._cleanupAfter();
918	fNeedCleanUp = False;
919	assert self._oChild is None;
920
921	#
922	# Clean up scratch.
923	#
924	if fNeedCleanUp:
925	if self._oTestBoxScript.reinitScratch(self._logInternal, cRetries = 6) is not True:
926	self._log('post run reinitScratch failed.');
927	fRc = False;
928
929	#
930	# Report status and everything back to the test manager.
931	#
932	if fRc is False and sResult == constants.result.PASSED:
933	sResult = constants.result.FAILED;
934	self._reportDone(sResult);
935	return fRc;
936

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

source: vbox/trunk/src/VBox/ValidationKit/testboxscript/testboxtasks.py@ 78314

Download in other formats: