VirtualBox

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

Last change on this file was 106061, checked in by vboxsync, 3 months ago

Copyright year updates by scm.

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

© 2024 Oracle Support Privacy / Do Not Sell My Info Terms of Use Trademark Policy Automated Access Etiquette