Master.py

Go to the documentation of this file.

#
# Copyright 2007, MeVis Medical Solutions AG
#
# The user may use this file in accordance with the license agreement provided with
# the Software or, alternatively, in accordance with the terms contained in a
# written agreement between the user and MeVis Medical Solutions AG.
#
# For further information use the contact form at https://www.mevislab.de/contact
#
 
 
 
import copy
import datetime
import logging
import os
import re
import shutil
import subprocess
import tempfile
import threading
import time
import traceback
import xml.etree.cElementTree as etree
from html.parser import HTMLParser
from html import unescape
from copy import deepcopy
 
try:
    import TestSupport
except ImportError:
    pass
 
from . import Config
from . import IPC
from . import Utils
 
from .LogHandler import LogHandler
 
 
class HTMLStripper(HTMLParser):
    def __init__(self):
        super().__init__()
        self.fed = []
 
    def handle_data(self, data):
        self.fed.append(data)
 
    def get_data(self):
        return "".join(self.fed)
 
 
class TestCaseTimer:
    def __init__(self, seconds):
        self.start = time.monotonic()
        self.availableSeconds = seconds
 
    def extendTimeout(self, seconds):
        self.availableSeconds += seconds
 
    def getSecondsRemaining(self):
        passedSeconds = time.monotonic() - self.start
        return self.availableSeconds - passedSeconds
 
    def isExpired(self):
        return self.getSecondsRemaining() <= 0.0
 
 
class SlaveProcess:
    nextSlaveId = 0
 
    def __init__(self, config, logfileDir, env, isInsideTestCaseManager):
        self.__id = SlaveProcess.nextSlaveId
        SlaveProcess.nextSlaveId += 1
        self.__wasKilled = False
        self.__hasStarted = False
        self.__logFileFD = None
        self.__logFile = None
        self.__slaveLogFile = None
        self.__logger = logging.getLogger("TestCenter")
        self.__workDir = os.path.join(config.getResultDir(), "work")
 
        cmd = self.__getCommandLine(config, logfileDir, isInsideTestCaseManager)
        if cmd:
            self.__startProcess(cmd, config, env)
 
    def hasStarted(self):
        return self.__hasStarted
 
    def __getCommandLine(self, config, logfileDir, isInsideTestCaseManager):
        try:
            cmd = config.getMLABTestCenterCommand(macroName="TestCenter")
            if cmd:
                self.__slaveLogFile = os.path.join(logfileDir, f"slaveLogfile_{self.getID()}.log")
                cmd.insert(1, "-logfile")
                cmd.insert(2, self.__slaveLogFile)
                if isInsideTestCaseManager:
                    cmd.append("--started-from-test-case-manager")
        except Config.MLABExecutableNotFoundException:
            cmd = None
 
        if not cmd:
            self.__logger.error(
                "Failed to start slave as no MeVisLab executable was found. "
                + "Please verify your configuration (see TestCase Manager's "
                + "Configuration tab or check the file %s)!" % config.getConfigFilePath()
            )
        return cmd
 
    def __startProcess(self, cmd, _, env):
        self.__logFileFD, self.__logFile = tempfile.mkstemp()
        self.__logger.debug("Starting slave with command line %s" % " ".join(cmd))
        try:
            preexec_fn = os.setpgrp if Utils.isUnix else None
            self.__process = subprocess.Popen(
                cmd,
                cwd=self.__workDir,
                preexec_fn=preexec_fn,
                env=env,
                stdout=self.__logFileFD,
                stderr=self.__logFileFD,
            )
            self.__hasStarted = True
        except OSError:
            self.__logger.error("Failed to start slave (%s)\n%s" % (cmd, traceback.format_exc()))
 
    def getID(self):
        return self.__id
 
    def getPID(self):
        return self.__process.pid
 
    def isRunning(self):
        return self.getExitCode() is None
 
    def getExitCode(self):
        return self.__process.poll()
 
    def kill(self):
        self.__wasKilled = Utils.kill(self.__process)
        return self.__wasKilled
 
    def wasKilled(self):
        return self.__wasKilled
 
    def __printLogsAfterError(self):
        try:
            output = ""
            if self.__slaveLogFile is not None and os.path.exists(self.__slaveLogFile):
                with open(self.__slaveLogFile, "r", errors="replace") as fh:
                    output = fh.read()
            if os.path.exists(self.__logFile):
                with open(self.__logFile, "r", errors="replace") as fh:
                    output += fh.read()
            if not output:
                output = "none"
            self.logErrorWithPID("Slave output: %s" % output)
        except IOError as e:
            self.logErrorWithPID(f"Could not read log file: {e}")
 
    def finish(self, printLog):
        try:
            os.fsync(self.__logFileFD)
            os.close(self.__logFileFD)
        except IOError as e:
            self.logErrorWithPID("Could not close log file: %s" % str(e))
        if printLog:
            self.__printLogsAfterError()
        if os.path.exists(self.__logFile):
            try:
                Utils.removeFile(self.__logFile)
            except IOError as e:
                self.logErrorWithPID("Could not remove log file: %s" % str(e))
        else:
            self.logMessageWithPID("Log file does not exist: %s" % self.__logFile)
 
    def logMessageWithPID(self, message):
        return "%s (PID: %s)" % (message, str(self.getPID()))
 
    def logDebugWithPID(self, message):
        self.__logger.debug(self.logMessageWithPID(message))
 
    def logErrorWithPID(self, message):
        self.__logger.error(self.logMessageWithPID(message))
 
 
class ProgressTestCase:
    def __init__(self, name, status, errorCount, warningCount, duration):
        self.duration = duration
        self.name = name
        self.status = status
        self.errorCount = errorCount
        self.warningCount = warningCount
 
 
class TestProgress:
    def __init__(self):
        self.activeTestCase = None
        self.finishedTestCases = []
        self.testCaseCount = 0
 
    def reset(self, testCaseCount):
        self.activeTestCase = None
        self.finishedTestCases = []
        self.testCaseCount = testCaseCount
 
 
class Master:
    """The coordinator of test execution.
    The master can be used in two ways: either with tests executed in another
    MeVisLab instance or in the same. In the first scenario a new MeVisLab
    instance is started, the TestCenter module loaded via the runMacro parameter
    and communication handled using socket based interprocess communication. In
    the second one the slave is instantiated directly in the master.
    """
 
    def __init__(self, cfgFile=None, verbose=False, slave=None, slaveEnvironment=None, isInsideTestCaseManager=False):
        """Initialize the master process.
 
        @param cfgFile The configuration file to load (defaults to tc_cfg_<platform>.xml)
        @param verbose Unused
        @param slave Run the tests in the same MeVisLab instance using the given slave instance.
        @param slaveEnvironment Environment to use for the MeVisLab slave instance.
        """
        self.__logger = logging.getLogger("TestCenter")
 
        self.__config = Config.Configuration(cfgFile)
 
        # The communication device to talk to slave
        self.__com = (
            None if slave is not None else IPC.ComMaster(connectTimeout=self.__config.getIPCConnectionTimeout())
        )
        # Slave instance to use if offline testing is used
        self.__slave = slave
        self.__slaveProc = None
        self.__slaveEnvironment = slaveEnvironment
 
        self.__testProgress = TestProgress()
        self.__shouldStop = False
        self.__lock = threading.Lock()
 
        self.__testCaseListener = None
 
        self.__testedPkgList = []
        # Slave processes that could not be killed.
        self.__hangingSlaves = []
        # The result tree
        self.__xmlRoot = None
        self.__testCasesToIgnoreList = []
 
        # Clean up existing result directory or create it.
        resultDir = self.__config.getResultDir()
        imgDir = os.path.join(resultDir, "images")
        fileDir = os.path.join(resultDir, "files")
        workDir = os.path.join(resultDir, "work")
        self.logfileDir = os.path.join(resultDir, "logfiles")
 
        os.makedirs(resultDir, exist_ok=True)
 
        def logRemoveError(_func, path, excinfo):
            self.__logger.warning(f"Failed to remove {path}: {excinfo[1]}")
 
        for subdir in [imgDir, fileDir, workDir, self.logfileDir]:
            if os.path.exists(subdir):
                shutil.rmtree(subdir, onerror=logRemoveError)
            os.makedirs(subdir, exist_ok=True)
 
        # Path of a file to receive the stack trace in case of a crash
        self.__stackTraceFile = None
        if Utils.isLinux and "NO_MEVISLAB_DEBUGGER" not in os.environ:
            self.__stackTraceFile = os.path.join(self.logfileDir, "lastCrashStackTrace.txt")
            self.__slaveEnvironment = Utils.setStackTraceFile(self.__slaveEnvironment, self.__stackTraceFile)
 
        self.__isInsideTestCaseManager = isInsideTestCaseManager
 
        # The configuration of the current test run
        self.__testCfg = self.__testConfigSkeleton()
 
        self.__testTimeoutFactor = Master.defaultTestTimeoutFactor()
 
        self.__updateProgressFunc = None
 
        # If not running offline start a second MeVisLab instance.
        if self.__slave is None:
            if not self.__startSlave():
                raise Exception("Failed to start slave")
 
    def onExit(self):
        for slaveProc in self.__hangingSlaves:
            slaveProc.finish(printLog=True)
            if not slaveProc.kill():
                self.__logger.error("Finally killing process %s failed." % slaveProc.getPID())
        self.__hangingSlaves.clear()
 
    def __enter__(self):
        return self
 
    def __exit__(self, *_):
        self.onExit()
 
    def __del__(self):
        self.onExit()
 
    def stop(self):
        self.__lock.acquire()
        self.__shouldStop = True
        self.__lock.release()
 
    def shouldStop(self):
        self.__lock.acquire()
        result = self.__shouldStop
        self.__lock.release()
        return result
 
    def getTestProgress(self):
        self.__lock.acquire()
        result = copy.deepcopy(self.__testProgress)
        self.__lock.release()
        return result
 
    def resetTestProgress(self, testCaseCount):
        self.__lock.acquire()
        self.__testProgress.reset(testCaseCount)
        self.__lock.release()
 
    def updateTestProgress(self, finishedTestCase=None, additionalTestCaseCount=None):
        progressTestCase = None
        if finishedTestCase is not None:
            errorCount = 0
            warningCount = 0
            for function in finishedTestCase.findall("Function"):
                status = int(function.get("status", str(Utils.TEST_STATUS_DISABLED)))
                if status in (
                    Utils.TEST_STATUS_ERROR,
                    Utils.TEST_STATUS_LOAD_ERROR,
                    Utils.TEST_STATUS_CRASHED,
                    Utils.TEST_STATUS_FUNCTION_NOT_FOUND,
                    Utils.TEST_STATUS_TIMEOUT,
                ):
                    errorCount += 1
                elif status == Utils.TEST_STATUS_WARNING:
                    warningCount += 1
            progressTestCase = ProgressTestCase(
                finishedTestCase.get("name"),
                int(finishedTestCase.get("status", str(Utils.TEST_STATUS_CANCELLED))),
                errorCount,
                warningCount,
                float(finishedTestCase.get("duration", "0")),
            )
 
        self.__lock.acquire()
        if progressTestCase is not None:
            self.__testProgress.finishedTestCases.append(progressTestCase)
        if additionalTestCaseCount is not None:
            self.__testProgress.testCaseCount += additionalTestCaseCount
        self.__lock.release()
 
    def setUpdateProgressFunc(self, updateProgressFunc):
        self.__updateProgressFunc = updateProgressFunc
 
    def setActiveTestCase(self, testCase):
        self.__lock.acquire()
        self.__testProgress.activeTestCase = testCase
        self.__lock.release()
 
    @staticmethod
    def __testConfigSkeleton():
        """Returns an empty configuration filled with the required information."""
        return etree.fromstring(
            """
      <Configuration>
        <TestGroups />
        <TestCases />
        <TestSuites />
        <Modules />
        <Packages>
          <Tested />
          <Available />
          <Ignored />
        </Packages>
        <TestOptions />
      </Configuration>"""
        )
 
    def setTestCaseListener(self, listener):
        self.__testCaseListener = listener
 
    def setTestCases(self, testCaseList):
        """Set the list of test cases to execute.
 
        @param testCaseList List of names of test cases to execute.
        """
        assert self.__xmlRoot is None
 
        xmlNode = self.__testCfg.find("TestCases")
        for testCaseName in testCaseList:
            etree.SubElement(xmlNode, "TestCase", name=testCaseName)
 
    def setTestCasesToIgnore(self, testCaseToIgnoreList):
        """Set the list of test cases to ignore."""
        self.__testCasesToIgnoreList = testCaseToIgnoreList
 
    def setTestGroups(self, testGroupList):
        """Set the list of test groups to take into account."""
        assert self.__xmlRoot is None
 
        xmlNode = self.__testCfg.find("TestGroups")
        for testGroupName in testGroupList:
            etree.SubElement(xmlNode, "TestGroup", name=testGroupName)
 
    def setTestSuites(self, testSuiteList):
        assert self.__xmlRoot is None
 
        xmlNode = self.__testCfg.find("TestSuites")
        for testSuiteName in testSuiteList:
            etree.SubElement(xmlNode, "TestSuite", name=testSuiteName)
 
    def setModules(self, moduleList=None, filterList=None):
        """Specify the list of modules to test.
        The filters can be used to specify a larger list of modules, for example
        all the modules of a certain author ("author:Jon Doe").
 
        @param moduleList List of names of modules to take into account.
        @param filterList List of filters to select modules.
        """
        assert self.__xmlRoot is None
        moduleList = moduleList or []
        filterList = filterList or []
 
        xmlNode = self.__testCfg.find("Modules")
        for moduleName in moduleList:
            etree.SubElement(xmlNode, "Module", name=moduleName)
        for filter in filterList:
            etree.SubElement(xmlNode, "Filter").text = filter
 
    def setPackages(self, testedPkgList=None, availablePkgList=None, ignoredPkgList=None):
        """Specify the packages that should be tested and thought available.
        The packages tested are those that test cases are taken from. The available packages are those
        that should be expected to be there. This is important for checking the meta information like
        the seeAlso tags. In released installers all seeAlso links should only point to modules being
        the public packages.
 
        @param testedPkgList The list of packages tests are taken from.
        @param availablePkgList List of packages that should be available.
        @param ignoredPkgList List of package that should be ignored when using wildcard.
        """
        assert self.__xmlRoot is None
 
        testedPkgList = testedPkgList or []
        availablePkgList = availablePkgList or []
        ignoredPkgList = ignoredPkgList or []
 
        self.__testedPkgList = testedPkgList
        xmlNode = self.__testCfg.find("Packages/Tested")
        for packageID in testedPkgList:
            etree.SubElement(xmlNode, "Package", name=packageID)
 
        xmlNode = self.__testCfg.find("Packages/Available")
        for packageID in availablePkgList:
            etree.SubElement(xmlNode, "Package", name=packageID)
 
        xmlNode = self.__testCfg.find("Packages/Ignored")
        for packageID in ignoredPkgList:
            etree.SubElement(xmlNode, "Package", name=packageID)
 
    @staticmethod
    def defaultTestTimeoutFactor():
        envTimeout = os.environ.get("MLAB_TEST_TIMEOUT_FACTOR", "")
        if envTimeout:
            try:
                return float(envTimeout)
            except ValueError:
                pass
        return 1.0
 
    def setTestTimeoutFactor(self, factor: float):
        self.__testTimeoutFactor = factor
 
    def __sortNodes(self, nodes):
        nodeList = []
        testAgendas = {}
        invalidNodes = []
        invalidAgendas = {}
        for testCaseNode in nodes:
            testCaseAgenda, success = self.__buildTestCaseAgenda(testCaseNode)
            if success:
                testAgendas[testCaseNode] = testCaseAgenda
            else:
                invalidAgendas[testCaseNode] = testCaseAgenda
                invalidNodes.append(testCaseNode)
        for prefRendererSetting in ["", "hardware", "software"]:
            for testCaseNode in nodes:
                if testCaseNode in invalidNodes:
                    continue
                testCaseAgenda = testAgendas[testCaseNode]
                testCaseInfoNodes = testCaseAgenda.findall("TestCase")
                testCaseInfoNode = testCaseInfoNodes[0]
                preferredRendererNode = testCaseInfoNode.find("preferredRenderer")
                if (
                    preferredRendererNode is None
                    and prefRendererSetting == ""
                    or preferredRendererNode is not None
                    and preferredRendererNode.text.lower() == prefRendererSetting
                ):
                    nodeList.append(testCaseNode)
        assert len(testAgendas) == len(nodeList)
        return nodeList, testAgendas, invalidAgendas
 
    @staticmethod
    def __testTypeAndName(xmlNode):
        # Just print anything if we are in verbose mode.
        testType = xmlNode.get("type")
        testName = (
            xmlNode.get("name")
            if testType == "FunctionalTestCase"
            else "%s::%s" % (xmlNode.get("name"), xmlNode.get("module"))
        )
 
        return testType, testName
 
    def __statusMessage(self, xmlNode, status):
        """Sets status messages with the results of the given test.
        The message is built from the test type, the test name and the status.
 
        @param xmlNode The XML node that contains the results.
        @param status The status of the test case.
        """
        assert type(status) == int
        assert xmlNode.tag == "TestCase"
 
        statusStr = Utils.getStatusString(status)
        testType, testName = self.__testTypeAndName(xmlNode)
        fillIn = "." * (80 - len(testType + testName + statusStr) - 2)
        msg = "%s::%s%s%s" % (testType, testName, fillIn, statusStr)
        if status == Utils.TEST_STATUS_OK or status == Utils.TEST_STATUS_DO_NOT_TEST_MODULE:
            self.__logger.debug(msg)
        elif status == Utils.TEST_STATUS_WARNING:
            self.__logger.warning(msg)
        else:
            self.__logger.error(msg)
 
    def __testFailed(self, xmlNode, comError):
        """Handle failed tests.
        There are two reasons for a test to fail: either the slave crashed or the
        slave did not respond within the timeout (which might be an indicator for
        an infinite loop). In either case there must be some sort of handling of
        the situation to represent the situation within the XML data structure.
        This method will load the log files and try to figure out what happened in
        the last test run. This is possible as all action is surrounded by guards
        in the logfile. The extracted information is added to the given XML node.
 
        @param xmlNode Node to add the found information.
        @param comError The last communication error.
        """
        assert xmlNode.tag == "TestCase"
 
        testType = xmlNode.get("type")
        if testType == "GenericTestCase":
            testName = "%s::%s" % (xmlNode.get("name"), xmlNode.get("module"))
        else:
            testName = xmlNode.get("name")
 
        # Build a mapping from function names to result nodes.
        funcDict = {}
        for funcNode in xmlNode.findall("Function"):
            funcDict.setdefault(funcNode.get("name"), funcNode)
 
        # With the previously gathered error status the reason can be determined.
        status = Utils.TEST_STATUS_ERROR
        if comError in (IPC.Error.EMPTY_MESSAGE, IPC.Error.ON_RECEIVING_2):
            status = Utils.TEST_STATUS_CRASHED
        elif comError == IPC.Error.ON_RECEIVING_TIMEOUT:
            status = Utils.TEST_STATUS_TIMEOUT
 
        stackTraceMsg = None
        if self.__stackTraceFile and os.path.exists(self.__stackTraceFile):
            with open(self.__stackTraceFile, encoding="utf8", errors="surrogateescape") as f:
                stacktrace = f.read().splitlines()
                # filter out information lines about encountered threads (which there are a lot of):
                new_lwp_re = re.compile(r"\[New LWP \d+\]", flags=re.IGNORECASE)
                stacktrace = [x for x in stacktrace if not new_lwp_re.fullmatch(x)]
                # remove the stack frames from the signal handler itself:
                lastSignalHandlerFrame = -1
                for i in range(len(stacktrace)):
                    if "/mlabLinuxSignalHandler.cpp:" in stacktrace[i]:
                        lastSignalHandlerFrame = i
                        # the last one counts, therefore no break here
                if lastSignalHandlerFrame != -1:
                    stacktrace = stacktrace[lastSignalHandlerFrame + 1 :]
                if stacktrace:
                    stackTraceMsg = "MeVisLab crashed with the following stacktrace:\n" + "\n".join(stacktrace)
            os.unlink(self.__stackTraceFile)
 
        # Read the slave's logfile and parse it to get as much results as possible.
        logHandler = LogHandler(self.__config.getSlaveLogFilePath())
        logHandler.parseLogFile(testType, testName, status, funcDict, stackTraceMsg=stackTraceMsg)
 
        return status
 
    def __buildTestAgenda(self):
        """Build up the basic XML structure with information what tests have to be run.
        Please note that the methods setPackages, setModules, setTestCases
        and setTestGroups must be called prior to this method.
        """
        resultNode = self.__sendRequest("BuildTestAgenda", self.__testCfg)
        if resultNode.get("errorCode") != "Ok":
            self.__logger.critical(
                "Error (%s) in generating the test agenda!\n%s"
                % (resultNode.get("errorCode"), resultNode.find("Error").text)
            )
            return False
        self.__xmlRoot = resultNode.find("TestRun")
        self.__testCfg = self.__verifyConfiguration(resultNode.find("Configuration"))
 
        # Set package list as testing is started afterwards.
        self.__sendRequest("SetPackageList", self.__testCfg.find("Packages"), 5, restart=True)
        return True
 
    def __buildTestCaseAgenda(self, testCaseNode):
        def _stripHTML(html):
            stripper = HTMLStripper()
            unescaped = unescape(html)
            stripper.feed(unescaped)
            return stripper.get_data()
 
        parameterNode = etree.Element("Parameters")
        genericTestCase = True  # is it possible to determine the testcase type here?
        if genericTestCase:
            moduleList = []
            for module in self.__xmlRoot.findall("Information/Modules/Module"):
                moduleList.append(module.attrib["name"])
            parameterNode.attrib["modules"] = ",".join(moduleList)
            if len(self.__testedPkgList) > 0:
                parameterNode.attrib["packages"] = ",".join(self.__testedPkgList)
            else:
                # test every package
                parameterNode.attrib["packages"] = "*/*"
        parameterNode.append(testCaseNode)
        resultNode = self.__sendRequest("BuildTestCaseAgenda", parameterNode, restart=True)
        if resultNode.get("errorCode") != "Ok":
            self.__logger.critical(
                f'Error {resultNode.get("errorCode")} in generating the test case agenda!\n{resultNode.find("Error").text}'
            )
            functionResultNode = self.__xmlRoot.find("Results")
            testCaseResultNode = etree.SubElement(functionResultNode, "TestCase")
            testCaseResultNode.set("name", testCaseNode.get("name"))
            testCaseResultNode.set("status", "5")
            testCaseResultNode.set("retries", "0")
            testCaseResultNode.set("duration", "0")
            testCaseResultNode.set("slave_id", "0")
            testCaseResultNode.set("type", testCaseNode.get("type"))
            tempTestcase = resultNode.find("TestCase")
            if tempTestcase is None:
                self.__logger.critical(f'Invalid response: {etree.tostring(resultNode, encoding="unicode")}')
            else:
                errorLog = resultNode.find("Events")
                testFunctions = tempTestcase.find("TestFunctions")
                for testFunction in testFunctions.findall("Function"):
                    if testFunction.get("basename") == "LoadTestCase":
                        testFunction.append(errorLog)
                        functionXMLNode = etree.SubElement(testCaseResultNode, "Function")
                        functionXMLNode.set("name", testFunction.get("name"))
                        functionXMLNode.set("is_disabled", "False")
                        functionXMLNode.set("status", "5")
                        functionXMLNode.set("duration", "0")
                        functionXMLNode.set("try", "1")
                        functionXMLNode.append(errorLog)
                for event in errorLog.findall("Event"):
                    messageText = _stripHTML(event.find("Message").text)
                    self.__logger.error(f"{event.get('type')}: {messageText}")
            return tempTestcase, False
 
        return resultNode, True
 
    def __verifyConfiguration(self, testCfg):
        """Verify the settings made by the slave.
        The slave returns the modified test configuration that contains status information for the entities set.
        These are parsed right here and failure is reported.
        The test configuration is set to the value that is returned.
 
        @param testCfg The test configuration returned by the slave.
        @return The verified test configuration.
        """
        # Verify package settings.
        packageRoot = testCfg.find("Packages")
 
        tPkgNode = packageRoot.find("Tested")
        for packageNode in tPkgNode.findall("Package"):
            if packageNode.get("status") not in ("Ok", "Added", "Substituted"):
                self.__logger.error(
                    "Failed to verify package (%s with status '%s')!"
                    % (packageNode.get("name"), packageNode.get("status"))
                )
 
        aPkgNode = packageRoot.find("Available")
        for packageNode in aPkgNode.findall("Package"):
            if packageNode.get("status") not in ("Ok", "Added", "Substituted"):
                self.__logger.error(
                    "Failed to verify package (%s with status '%s')!"
                    % (packageNode.get("name"), packageNode.get("status"))
                )
            else:
                if packageNode.get("status") not in ("Substituted"):
                    packageRoot.append(packageNode)
 
        packageRoot.remove(tPkgNode)
        packageRoot.remove(aPkgNode)
 
        iPkgNode = packageRoot.find("Ignored")
        packageRoot.remove(iPkgNode)
 
        # Verify the module settings.
        for moduleNode in testCfg.findall("Modules/Module"):
            isModuleFiltered = moduleNode.get("isModuleFiltered") == str(True)
            if not isModuleFiltered and moduleNode.get("status") != str(Utils.TEST_STATUS_OK):
                self.__logger.error(
                    "Failed to verify module (%s with status '%s')" % (moduleNode.get("name"), moduleNode.get("status"))
                )
        testCfg.find("Modules").clear()
 
        # Verify the test case settings.
        for testCaseNode in testCfg.findall("TestCases/TestCase"):
            isNotInTestGroups = testCaseNode.get("isNotInTestGroups") == str(True)
            if not isNotInTestGroups and testCaseNode.get("status") != str(Utils.TEST_STATUS_OK):
                self.__logger.error(
                    "Failed to verify test case (%s with status '%s')"
                    % (testCaseNode.get("name"), testCaseNode.get("status"))
                )
        testCfg.find("TestCases").clear()
 
        return testCfg
 
    def __createTimeoutTooHighErrorFunction(self, testCaseInfoNode, testResultNode, timeout):
        functionName = "TEST001_VerifyTestCaseTimeout"
        testFunctions = testCaseInfoNode.find("TestFunctions")
        testFunction = etree.SubElement(testFunctions, "Function")
        testFunction.attrib = {"basename": "VerifyTestCaseTimeout", "is_disabled": "False", "name": functionName}
        etree.SubElement(testFunction, "Documentation").text = "Verifies if the TestCase timeout."
        timeoutTooHighTestFunction = etree.SubElement(testResultNode, "Function")
        timeoutTooHighTestFunction.attrib = {
            "duration": "0",
            "name": functionName,
            "status": "2",
            "is_disabled": "False",
            "try": "1",
        }
        events = etree.SubElement(timeoutTooHighTestFunction, "Events")
        filename = testCaseInfoNode.find("File").text
        line = testCaseInfoNode.find("Line").text
        event = etree.SubElement(events, "Event")
        event.attrib = {
            "file": filename,
            "internal": "true",
            "line": line,
            "origin": "",
            "type": "Error",
            "timestamp": datetime.datetime.now().strftime("%Y-%m-%d %H:%M:%S"),
        }
        error = "The TestCase timeout (%ss) exceeds the maximum allowed timeout (%ss)" % (
            timeout,
            self.__config.getMaxTestTimeoutSeconds(),
        )
        etree.SubElement(event, "Message").text = error
 
    def __buildListOfTestFunctionsToExecute(self, testCaseInfoNode, testCaseNode, funcList=None):
        # Build up list of test functions that must be executed.
        testFuncList = []
        for funcNode in testCaseInfoNode.findall(".//Function"):
            funcName = funcNode.get("name")
            # If user selected to process only specific functions ignore the rest.
            if funcList and funcName not in funcList and not Utils.isInternalTestCaseFunction(funcName):
                continue
 
            isDisabled = funcNode.get("is_disabled", str(False)) == str(True)
            if testCaseInfoNode.get("name") in self.__testCasesToIgnoreList:
                isDisabled = True
            if isDisabled and funcList:
                # If a user selected the function, then it should be executed
                isDisabled = False
                funcNode.set("is_disabled", str(False))
            funcResultNode = etree.SubElement(testCaseNode, "Function", name=funcName, is_disabled=str(isDisabled))
            testFuncList.append(funcName)
        return testFuncList
 
    def __doTest(self, testCaseInfoNode, testResultNode, funcList=None):
        """Do the actual test.
        This method sends a copy of a test case node with all required test
        functions to the slave. Failing functions will be requested one more time
        such that a wasted environment can't spoil the results of a test.
 
        @param testResultNode The test case that should be executed.
        @param funcList The list of test functions to execute.
        """
        assert testResultNode.tag == "TestCase"
 
        testCaseNode = deepcopy(testResultNode)
 
        # Build up list of test functions that must be executed.
        testFuncList = self.__buildListOfTestFunctionsToExecute(testCaseInfoNode, testCaseNode, funcList)
 
        testCaseName = testCaseInfoNode.get("name")
        if self.__testCaseListener:
            self.__testCaseListener.startTestCase(testCaseName, testFuncList)
 
        # Gather time till timeout.
        hasValidTimeout = True
        timeout = int(testCaseInfoNode.get("timeout"))
        if timeout == 0:
            timeout = self.__config.getDefaultTestTimeoutSeconds()
        if self.__config.getMaxTestTimeoutSeconds():
            if timeout > self.__config.getMaxTestTimeoutSeconds():
                self.__createTimeoutTooHighErrorFunction(testCaseInfoNode, testResultNode, timeout)
                hasValidTimeout = False
 
        # Use a bigger timeout if coverage or bullseye are enabled
        if self.__config.isPythonCoverageEnabled():
            timeout = timeout * 4.0
        if self.__config.isBullseyeCoverageEnabled():
            timeout = timeout * 4.0
        # Overall timeout factor given on the command line:
        timeout = timeout * self.__testTimeoutFactor
 
        if hasValidTimeout:
            retries, status = self.__executeTestFunctions(
                testCaseInfoNode, testResultNode, testCaseNode, testFuncList, timeout
            )
        else:
            retries = 0
            status = Utils.TEST_STATUS_ERROR
 
        # Set status and number of retries for the given test case.
        testResultNode.set("status", str(status))
        testResultNode.set("retries", str(retries))
        # Print status message.
        self.__statusMessage(testResultNode, status)
        if self.__testCaseListener:
            self.__testCaseListener.endTestCase()
 
    @staticmethod
    def transferNodeFromExecutionToResultXML(nodeName, executionNode, testResultNode):
        coverageFile = executionNode.get(nodeName)
        if executionNode.get(nodeName) is not None:
            testResultNode.set(nodeName, coverageFile)
 
    def __executeTestFunctions(self, testCaseInfoNode, testResultNode, testCaseNode, testFuncList, timeout):
        if testCaseNode.get("status") == str(Utils.TEST_STATUS_DO_NOT_TEST_MODULE):
            return 0, Utils.TEST_STATUS_DO_NOT_TEST_MODULE
 
        retries = 0
        failedFuncList = []
        timer = TestCaseTimer(timeout)
 
        status = Utils.TEST_STATUS_OK
        maxFuncStatus = Utils.TEST_STATUS_OK
        cancelled = False
        while testFuncList and not timer.isExpired() and not cancelled:
            # If not set status to timeout and stop execution of remaining test functions.
 
            if self.shouldStop():
                cancelled = True
                status = Utils.TEST_STATUS_CANCELLED
                break
 
            # if we have a test case listener, we request progress calls from the slave:
            if self.__testCaseListener:
                testCaseNode.set("requestProgress", "1")
 
            testCaseNode.set(
                "maxErrorMessagesPerTestFunction", str(self.__config.getReportOptions().maxErrorMessagesPerTestFunction)
            )
            testCaseNode.set(
                "maxInfoMessagesPerTestFunction", str(self.__config.getReportOptions().maxInfoMessagesPerTestFunction)
            )
 
            # Initiate the processing of the remaining test functions.
            executionNode = self.__sendRequest("DoTest", testCaseNode, timeout=timer, tries=1)
            if executionNode.get("errorCode") != "Ok":
                self.__logger.debug("Restarting due to error in test execution.\n%s" % executionNode.find("Error").text)
 
                # Try to determine what was the reason for the test to fail.
                comError = self.__com.getLastError() if self.__com else 0
 
                # Delete slave process.
                self.stopSlave()
 
                # Handle logfile to get gathered results.
                status = self.__testFailed(testCaseNode, comError)
                # Restart slave.
                if not self.__startSlave():
                    self.__logger.debug("Failed to re-start slave.")
            else:
                testCaseNode = executionNode.find("TestCase")
 
                self.transferNodeFromExecutionToResultXML("pythonCoverage", executionNode, testResultNode)
                self.transferNodeFromExecutionToResultXML("bullseyeCoverage", executionNode, testResultNode)
 
            extraTestCasesResults = testCaseNode.find("ExtraTestCasesResults")
            if extraTestCasesResults != None:
                testResultNode.append(deepcopy(extraTestCasesResults))
 
            # functions to test.
            for funcResultNode in testCaseNode.findall("Function"):
                funcName = funcResultNode.get("name")
 
                # If status is not set, the function has not been executed yet.
                funcStatus = funcResultNode.get("status")
                if not funcStatus:
                    # Function not processed yet.
                    continue
                else:
                    funcStatus = int(funcStatus)
                    if maxFuncStatus < funcStatus:
                        maxFuncStatus = funcStatus
 
                if funcName not in failedFuncList:
                    funcResultNode.set("try", "1")
 
                    if funcStatus in (
                        Utils.TEST_STATUS_CRASHED,
                        Utils.TEST_STATUS_TIMEOUT,
                    ):
                        failedFuncList.append(funcName)
                        retries += 1
                        # Create copy of node as it will be overwritten in the next iteration.
                        testResultNode.append(deepcopy(funcResultNode))
                        funcResultNode.remove(funcResultNode.find("Events"))
                else:
                    funcResultNode.set("try", "2")
                    failedFuncList.remove(funcName)
 
                # Remove all processed but not failed for the first time functions from
                # the temporary node.
                if funcName not in failedFuncList:
                    testFuncList.remove(funcName)
                    # Move the processed function to the result node.
                    testResultNode.append(funcResultNode)
                    testCaseNode.remove(funcResultNode)
                if funcStatus == Utils.TEST_STATUS_CANCELLED or funcStatus == Utils.TEST_STATUS_FUNCTION_NOT_FOUND:
                    cancelled = True
                    break
 
        if timer.isExpired():
            status = Utils.TEST_STATUS_TIMEOUT
 
        # The status variable is used for status > 2 to handle situations where:
        #  - all test functions worked but the slave crashed or timed out.
        #  - the test case timed out but had crashes, too (global status should be
        #    timeout).
        # Otherwise the maximum function status found in the reports is used.
        status = status if status > Utils.TEST_STATUS_ERROR else maxFuncStatus
        return retries, status
 
    @staticmethod
    def __handleExtraTestCaseResults(testCaseInfos, resultNode, testResultNode):
        """This method looks for the node "ExtraTestCasesResults" to support that a test case can created
        additional virtual test cases and their results. For example, this is used for the web tests,
        where the web application generates an xml report.
        """
        node = testResultNode.find("ExtraTestCasesResults")
        if node is not None:
            testResultNode.remove(node)
            for node in node.findall("ExtraTestCaseResult"):
                testCaseInfos.append(node.find("Information/TestCase"))
                extraTestCaseResult = node.find("Result/TestCase")
                extraTestCaseResult.set("slave_id", testResultNode.get("slave_id"))
                resultNode.append(extraTestCaseResult)
 
    def shouldMeasurePythonCoverageGlobally(self):
        return self.__config.isPythonCoverageEnabled() and self.__config.isGlobalPythonCoverageEnabled()
 
    def run(self, funcDict=None, stopSlaveAfterTestRun=True):
        """The main method which handles all the request from the master.
        The master asks the slave to serve some request. This is divided into two
        major blocks; on the first hand verifying whether the given information is
        valid and what tests to execute and on the second hand to process the
        given tests.
 
        @param funcDict A dictionary with information which test functions for
                        which test cases should be executed.
        @param stopSlaveAfterTestRun If False, then the slave can be re-used for
                                     another test run after resetting the master.
        """
        if not self.__buildTestAgenda():
            self.__logger.error("Failed to build test agenda.")
            return None
 
        # Start the timer.
        timeStarted = time.time()
 
        testCaseInfos = self.__xmlRoot.find("Information/TestCases")
 
        # Fetch counters which control after what number of testCases MLAB
        # should be restarted.
        freshCounterValue = self.__config.getRestartInterval()
        restartCounter = freshCounterValue
        restartDisabled = restartCounter == 0
 
        testCaseInfosTestCases = testCaseInfos.findall("TestCase")
        testCaseInfosTestCases, testAgendas, invalidAgendas = self.__sortNodes(testCaseInfosTestCases)
 
        if self.__testCaseListener:
            testNames = []
            for node in testCaseInfosTestCases:
                testNames.append(node.get("name"))
            self.__testCaseListener.startTestRun(testNames)
 
        self.resetTestProgress(len(testCaseInfosTestCases))
 
        failedTestCases = 0
        finishedTestCases = 0
        totalTestCases = len(testCaseInfosTestCases)
 
        resultNode = self.__xmlRoot.find("Results")
        for invalidNode in invalidAgendas.keys():
            if invalidAgendas[invalidNode] is not None:
                testCaseInfos.remove(invalidNode)
                testCaseInfos.append(invalidAgendas[invalidNode])
 
        cancelled = False
        previousRenderer = ""
        for testCaseNode in testCaseInfosTestCases:
            if cancelled:
                testCaseInfos.remove(testCaseNode)
                self.updateTestProgress(finishedTestCase=testCaseNode)
                continue
            try:
                testCaseAgenda = testAgendas[testCaseNode]
                if testCaseAgenda != None:
 
                    testCaseInfoNodes = testCaseAgenda.findall("TestCase")
                    assert len(testCaseInfoNodes) == 1
 
                    testCaseInfoNode = testCaseInfoNodes[0]
 
                    testCaseInfos.remove(testCaseNode)
                    testCaseInfos.append(testCaseInfoNode)
 
                    preferredRendererNode = testCaseInfoNode.find("preferredRenderer")
                    preferredRenderer = "" if preferredRendererNode is None else preferredRendererNode.text.lower()
                    if preferredRenderer == "hardware" and Utils.isMesaForced():
                        self.__logger.warning(
                            'preferredRenderer settings "hardware" detected but use of software driver is enforced.'
                        )
                    restartNeeded = previousRenderer != preferredRenderer and (
                        preferredRenderer == "software" or previousRenderer == "software"
                    )
                    previousRenderer = preferredRenderer
 
                    testResultNodes = testCaseAgenda.find("Results").findall("TestCase")
                    if len(testResultNodes) > 1:
                        self.updateTestProgress(additionalTestCaseCount=len(testResultNodes) - 1)
                        totalTestCases += len(testResultNodes) - 1
                    for testResultNode in testResultNodes:
                        if cancelled:
                            break
                        try:
                            testCaseName = testCaseInfoNode.get("name")
                            debugType, debugName = self.__testTypeAndName(testResultNode)
 
                            if not restartDisabled or restartNeeded:
                                shouldRestart = restartCounter == 0
                                if shouldRestart or restartNeeded:
                                    self.__logger.info("Restart slave for test case %s::%s" % (debugType, debugName))
                                    if not self.__startSlave(forceSoftwareRendering=(preferredRenderer == "software")):
                                        resultNode.append(testResultNode)
                                        raise Exception("Failed to start slave.")
 
                                    restartNeeded = False
                                    restartCounter = freshCounterValue
 
                                # decrement counter on each pass
                                restartCounter -= 1
 
                            self.setActiveTestCase(testCaseName)
 
                            if self.__updateProgressFunc is not None:
                                self.__updateProgressFunc(
                                    testCaseName, failedTestCases, finishedTestCases, totalTestCases
                                )
 
                            timeFunctionStarted = time.time()
                            funcList = funcDict[testCaseName] if (funcDict and testCaseName in funcDict) else None
                            self.__doTest(testCaseInfoNode, testResultNode, funcList)
                            timeFunctionStopped = time.time()
                            if int(testResultNode.get("status")) == Utils.TEST_STATUS_CANCELLED:
                                cancelled = True
 
                            if int(testResultNode.get("status")) in (
                                Utils.TEST_STATUS_CRASHED,
                                Utils.TEST_STATUS_ERROR,
                                Utils.TEST_STATUS_LOAD_ERROR,
                                Utils.TEST_STATUS_FUNCTION_NOT_FOUND,
                                Utils.TEST_STATUS_TIMEOUT,
                            ):
                                failedTestCases += 1
                            finishedTestCases += 1
 
                            testResultNode.set("duration", str(timeFunctionStopped - timeFunctionStarted))
 
                            testResultNode.set("slave_id", "0" if self.__slave else str(self.__slaveProc.getID()))
 
                            resultNode.append(testResultNode)
 
                            self.__handleExtraTestCaseResults(testCaseInfos, resultNode, testResultNode)
 
                        except Exception as e:
                            traceback.print_exc()
                            self.__logger.error("Error executing test case %s::%s\n%s" % (debugType, debugName, e))
                            testResultNode.set("status", str(Utils.TEST_STATUS_ERROR))
                        self.updateTestProgress(finishedTestCase=testResultNode)
                else:
                    self.__logger.error(
                        "Failed to build the test agenda for test case %s." % testCaseNode.get("name", "unknown")
                    )
            except Exception as e:
                self.__logger.error("Error executing test case %s" % e)
 
        if self.shouldMeasurePythonCoverageGlobally():
            resultNode.set("combinePythonCoverage", "True")
 
        # Stop the timer.
        timeStopped = time.time()
 
        self.__xmlRoot.set("timestamp", str(timeStarted))
        self.__xmlRoot.set("duration", str(timeStopped - timeStarted))
 
        if stopSlaveAfterTestRun:
            self.stopSlave()
 
        xml = Utils.saveXMLTree(self.__xmlRoot, self.__config.getResultFile())
 
        if self.__testCaseListener:
            self.__testCaseListener.endTestRun()
 
        return xml
 
    def reset(self):
        """Resets the master to the state after instantiation.
        In particular, it removes the configuration and the results of the last test run.
        After resetting the master you can start another test run with other tests.
        """
        self.__xmlRoot = None
        self.__testCfg = self.__testConfigSkeleton()
 
    def getConfig(self):
        return self.__config
 
    def __isSlaveRunning(self):
        return self.__slaveProc and self.__slaveProc.isRunning()
 
    def __isSlaveStopped(self):
        return not self.__isSlaveRunning()
 
    def logMessageWithPID(self, message):
        pidString = str(self.__slaveProc.getPID()) if self.__slaveProc is not None else str(None)
 
        return "%s (PID: %s)" % (message, pidString)
 
    def logDebugWithPID(self, message):
        self.__logger.debug(self.logMessageWithPID(message))
 
    def logErrorWithPID(self, message):
        self.__logger.error(self.logMessageWithPID(message))
 
    def logMessageWithLastError(self, message):
        errorCode, errorMessage = self.__com.getLastErrorWithMessage()
        return "%s ([%d] %s)" % (message, errorCode, errorMessage)
 
    def __startSlave(self, forceSoftwareRendering=False):
        """Start the slave process.
        If the slave is still running it will be stopped.
 
        @return True if the slave could be started and the connection could be established.
        """
        if self.__slave:
            return True
 
        if self.__isSlaveRunning():
            if not self.stopSlave():
                self.__logger.error("Failed to stop the slave before restart.")
 
        env = Utils.setForceMesa(self.__slaveEnvironment) if forceSoftwareRendering else self.__slaveEnvironment
        if self.__com:
            # server port is given through environment variable
            env = Utils.setTestCenterPort(env, self.__com.getPort())
        slaveProc = SlaveProcess(self.__config, self.logfileDir, env, self.__isInsideTestCaseManager)
        if slaveProc.hasStarted():
            self.__slaveProc = slaveProc
        else:
            return False
 
        return self.__connectToSlave()
 
    def __connectToSlave(self):
        retries = 0
        timerSleep = 1
        maxTries = 15
        while retries < maxTries and not self.__com.connect(timeout=self.__config.getIPCConnectionTimeout()):
            retries += 1
            self.logDebugWithPID(self.logMessageWithLastError("Failed to connect to slave in %i. try" % retries))
 
            if not self.__slaveProc.isRunning():
                self.__logger.error("Slave died with exit code %s" % self.__slaveProc.getExitCode())
                self.__slaveProc.finish(printLog=True)
                return False
 
            # Use a sleep timer to give the slave process more time to start up.
            self.__logger.debug("Sleeping for %s seconds" % (timerSleep))
            time.sleep(timerSleep)
 
        if not self.__com.isConnected():
            # quit the mlab that we were not able to talk to
            self.logErrorWithPID("Failed to connect to slave within %d seconds." % (maxTries * timerSleep))
            if not self.stopSlave():
                self.__logger.error("Failed to stop the slave after connection error.")
                self.__slaveProc.finish(printLog=True)
            return False
        else:
            self.logDebugWithPID("Connected to slave in %s. try" % (retries + 1))
 
        # Send slave a list of packages that are available. On first run an empty
        # string is sent; in the __buildTestAgenda call this list will be
        # retrieved. Later the verified list of tests will be sent.
        if self.__xmlRoot:
            resultNode = self.__sendRequest("SetPackageList", self.__testCfg.find("Packages"), 5)
            return resultNode.get("errorCode") == "Ok"
 
        return True
 
    def stopSlave(self):
        """Stop the slave process.
        If the slave is running this method tries to stop the slave. This method
        will run until the slave has stopped. After 3 tries on unix a KILL signal
        is sent.
        @return True if the slave was stopped.
        """
        if self.__slave:
            # ugly special condition for when a running MeVisLab instance is used
            # as slave.
            return True
 
        self.logDebugWithPID("Shutting down slave")
 
        if not self.__isSlaveStopped():
            # try soft shutdown first by requesting clean quit
            xmlNode = self.__sendRequest("Quit", timeout=1, tries=1)
 
            if xmlNode.get("errorCode") == "Ok":
                self.logDebugWithPID("Response received, waiting for shutdown")
                # wait up to five seconds for the slave to stop:
                i = 0
                while not self.__isSlaveStopped() and i < 10:
                    time.sleep(0.5)
                    i += 1
 
            # kindly asking for shutdown was obviously not enough, enforce shutdown
            if not self.__isSlaveStopped():
                self.logDebugWithPID("No response, killing slave")
                self.__slaveProc.kill()
 
        if self.__isSlaveStopped():
            self.__slaveProc.finish(printLog=self.__slaveProc.wasKilled())
        else:
            self.logErrorWithPID("Failed to kill slave!")
            self.__hangingSlaves.append(self.__slaveProc)
        self.__slaveProc = None
 
        return self.__isSlaveStopped()
 
    def __sendRequest(self, command, parameterNode=None, timeout=None, tries=2, restart=False):
        """Sends a message to the slave and waits for the response.
        The message consists of a tag (aka a command) and a message (aka the parameter).
 
        @param command The command sent.
        @param parameterNode Information connected with the command (XML).
        @param timeout The timeout used for the command.
        @param tries The number of retries used for the command.
        @return The resulting XML node.
        """
        trial = 0
 
        requestNode = etree.Element("Command", type=command)
        requestNode.append(parameterNode if parameterNode != None else etree.Element("Dummy"))
 
        if self.__slave:
            self.logDebugWithPID("Handling '%s' request" % command)
            resultNode = self.__slave.runCommand(requestNode)
        else:
            self.logDebugWithPID("Sending '%s' request to slave" % command)
            resultNode = None
            # The default timeout is taken from the configuration file.
            if not timeout:
                timeout = self.__config.getDefaultTestTimeoutSeconds()
 
            string = None
            while not string and (trial < tries):
                timer = timeout if isinstance(timeout, TestCaseTimer) else TestCaseTimer(timeout)
                if self.__com.send(etree.tostring(requestNode), timer.getSecondsRemaining()):
                    # since we allow receiving intermediate "Progress" result values,
                    # we loop until we receive something that is not a "Progress" message:
                    while not string and not timer.isExpired():
                        string = self.__com.recv(timer.getSecondsRemaining())
                        if string:
                            recvNode = Utils.filterXMLString(string)
                            self.logDebugWithPID("Received node of type '%s'" % recvNode.tag)
                            if recvNode.tag == "Progress":
                                shouldStop = False
                                if self.__testCaseListener:
                                    try:
                                        self.__testCaseListener.startTestCaseFunction(
                                            recvNode.get("testType"),
                                            recvNode.get("testCase"),
                                            recvNode.get("testFunction"),
                                        )
                                    except TestSupport.TestHelper.CancelTestException:
                                        shouldStop = True
                                # tell slave if it should stop or go on:
                                self.__com.send("0" if shouldStop else "1", 5)
                                string = None
                            elif recvNode.tag == "Status":
                                if self.__testCaseListener:
                                    self.__testCaseListener.endTestCaseFunction(int(recvNode.get("status")), 0)
                                string = None
                            else:
                                resultNode = recvNode
                        else:
                            if self.__stackTraceFile and os.path.exists(self.__stackTraceFile):
                                self.__logger.warning(
                                    "It seems the test client is crashing. Collecting the stacktrace may take some while."
                                )
                                # Add additional grace period to timer
                                timer.extendTimeout(300)
                                # wait for slave process to stop
                                while not self.__isSlaveStopped() and not timer.isExpired():
                                    time.sleep(0.5)
                            break
 
                if not string:
                    trial += 1
 
                    if restart and (trial < tries):
                        self.__logger.info("Restarting due to communication error ...")
                        self.__startSlave()
 
            if resultNode is None:
                self.logDebugWithPID("Error: Received no result from slave.")
                resultNode = etree.Element("Result", errorCode="CommunicationError")
                etree.SubElement(resultNode, "Error").text = (
                    "Communication error [%d]: %s" % self.__com.getLastErrorWithMessage()
                )
 
        self.logDebugWithPID("Result error code: %s" % resultNode.get("errorCode"))
        content = etree.tostring(resultNode).decode()
        self.logDebugWithPID("Result content: %s%s" % (content[:150], " [...]" if len(content) > 150 else ""))
        return resultNode