def testFDTDAndExecutorContainerHandling():
c = """
[general]
port = 6700
debug = DEBUG
portRangeFDTServer = 54321,54323
killCommand = "kill -9 %(pid)s"
killCommandSudo = "kill -9 %(pid)s"
"""
f = getTempFile(c)
inputOptions = "-d DEBUG -p 6700 --config=%s" % f.name
conf = ConfigFDTD(inputOptions.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
daemon = FDTD(conf, apMon, logger)
assert len(daemon._executors) == 0
# needs to be blocking command, since simple ls finishes too quickly
# for default blocking it would be considered that it failed
# just needed existing process and executor container handling with it
executor = Executor("some_id", "ls /tmp", logger=logger, blocking=True)
executor.execute()
daemon.addExecutor(executor)
# subsequent adding of the same executor shall raise exception
# (the same id)
py.test.raises(FDTDException, daemon.addExecutor, executor)
daemon.removeExecutor(executor)
assert len(daemon._executors) == 0
# need long running job
command = "dd if=/dev/zero of=/dev/null count=100000000 bs=102400"
# caller is not explicitly specified, so all executors container
# manipulation is done from this test
executor = Executor("some_id",
command,
blocking=False,
killTimeout=0,
logger=logger)
executor.execute()
daemon.addExecutor(executor)
assert len(daemon._executors) == 1
# check getting the executor reference from the container
ex = daemon.getExecutor("some_id_nonsence") # doens't exist
assert ex == None
ex = daemon.getExecutor("some_id")
assert ex == executor
# this in fact should discover that the process is still running
# and not remove it
daemon.removeExecutor(executor)
assert len(daemon._executors) == 1
# now kill the process and try to remove it afterwards - test
# different branch of removeExecutor
daemon.killProcess(executor.id, logger)
assert len(daemon._executors) == 0 # should have been removed
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testExecutorNonBlockingWaitingForLogOutput():
script = """
c=2
while [ $c -gt 0 ]
do
echo "some undesired logging output"
sleep 1
let "c -= 1"
done
echo "expected logging output"
sleep 1
"""
f = getTempFile(script)
command = "bash %s" % f.name
# wait for correct log output
logOutputToWaitFor = "expected logging output"
e = Executor("some_id",
command,
blocking=False,
logOutputToWaitFor=logOutputToWaitFor,
logOutputWaitTime=3)
logs = e.execute()
# the process shall be considered running - the expected log output
# was captured
assert e.returncode == None # the process
time.sleep(3)
# internal Executor returncode hasn't been updated since the last call
# chain: .execute()
assert e.proc.poll() == 0 # by now shall finish with 0 (no errors)
# wait for wrong log output
logOutputToWaitFor = "EXPECTED LOGGING OUTPUT"
# wait more than the time of running of script, it script will finish
# though from here (for non-blocking long-running) process, it is as if
# the process failed
e = Executor("some_id",
command,
blocking=False,
logOutputToWaitFor=logOutputToWaitFor,
logOutputWaitTime=5)
py.test.raises(ExecutorException, e.execute)
# wait too short time, so it seems the process runs anyway and check that
logOutputToWaitFor = "rubbish"
e = Executor("some_id",
command,
blocking=False,
logOutputToWaitFor=logOutputToWaitFor,
logOutputWaitTime=1)
logs = e.execute()
time.sleep(0.5)
# even after this time, the process shall still be running
assert e.proc.poll() == None
time.sleep(1)
# by now it shall be finished
assert e.proc.poll() == 0
def testExecutorBlocking():
command = "ls -la1 /tmp"
e = Executor("some_id", command, blocking=True, caller=MockCaller())
logs = e.execute()
# test __str__ method
print "running '%s'" % e
print "logs:%s" % logs
s = e.getLogs()
e = Executor("some_id", command, blocking=True, caller=None)
logs = e.execute()
# test __str__ method
print "running '%s'" % e
print "logs:%s" % logs
s = e.getLogs()
def testExecutorInstantiation():
e = Executor("someid",
"mycommand",
blocking=True,
catchLogs=False,
port=10,
logOutputToWaitFor="my log output",
killTimeout=100)
assert e.id == "someid"
assert e.caller == None
assert e.command == "mycommand"
assert e.blocking == True
assert e.catchLogs == False
assert e.port == 10
assert e.logOutputToWaitFor == "my log output"
assert e.logOutputWaitTime == 0
assert e.userName == None
assert e.killTimeout == 100
assert isinstance(e.logger, Logger) == True
assert e.stdOut == None
assert e.stdErr == None
# process instance as created by subprocess.Popen
assert e.proc == None
# returncode from the underlying self.proc instance
assert e.returncode == None
def execute(self, conf=None, caller=None, apMon=None, logger=None):
"""This method is invoked by fdtcp (locally)."""
# fileNameToStoreRemoteUserName - file into which AuthClient
# stores name of the Grid user at the remote party, this
# information is then forwarded later to
# fdtd which doens't have to do the user mapping lookup again
fileName = "/tmp/" + self.id + "--" + getRandomString('a', 'z', 5)
if os.path.exists(fileName):
raise FDTCopyException("File %s exists." % fileName)
self._setUp(conf, fileName)
executor = Executor(self.id,
self.command,
blocking=True,
logger=logger)
# here the Java AuthClient stores the Grid user name into the file
output = executor.execute()
try:
remoteGridUser = open(fileName, 'r').read()
os.remove(fileName)
except Exception, ex:
m = ("Problem handling file %s (reading remote Grid user "
"name), reason: %s" % (fileName, ex))
raise FDTCopyException(m)
def testExecutorNonBlocking():
# need long running job
command = "dd if=/dev/zero of=/dev/null count=100000000 bs=102400"
e = Executor("some_id", command, blocking=False, caller=MockCaller())
try:
e.execute()
assert e.proc.poll() == None # means command is running
assert len(e.caller.processes) == 1
finally:
os.kill(e.proc.pid, signal.SIGKILL)
e = Executor("some_id", command, blocking=False, caller=None)
try:
e.execute()
assert e.proc.poll() == None # means command is running
finally:
os.kill(e.proc.pid, signal.SIGKILL)
def execute(self, conf=None, caller=None, apMon=None, logger=None):
"""
This method is invoked by fdtd once the action object is received
from remote fdtcp (where the action instance was created). Options
known on fdtd are set on the action instance (e.g. finalizing command
for invoking FDT Java - location of fdt.jar is known only at fdtd site).
"""
# this method is called on PYRO service side, user its logger
# from now on
localGridUser = self.options["gridUserSrc"]
logger.debug("Local grid user is '%s'" % localGridUser)
self.options["sudouser"] = localGridUser
self._setUp(conf)
killTimeout = conf.get("fdtSendingClientKillTimeout")
executor = Executor(self.id,
self.command,
blocking=True,
caller=caller,
userName=localGridUser,
killTimeout=killTimeout,
syncFlag=False,
logger=logger)
try:
try:
output = executor.execute()
except ExecutorException as ex:
m = ("FDT Java client on %s failed, "
"reason: %s" % (getHostName(), ex))
logger.error(m)
raise FDTDException(m)
except Exception as ex:
m = ("FDT Java client on %s failed, "
"reason: %s" % (getHostName(), ex))
logger.error(m, traceBack=True)
raise FDTDException(m)
else:
# no other exception was raised during execution
r = Result(self.id)
r.status = 0
r.log = output
r.msg = "Output from FDT client"
logger.debug("FDT client log (as sent to "
"fdtcp):\n%s" % output)
return r
finally:
# give signal on this actions Executor instance that its handling
# finished (e.g. CleanupProcessesAction may be waiting for this)
executor.syncFlag = False
def testExecutorNonBlockingException():
# should fail due to permission denied
command = "cat /etc/shadow"
e = Executor("some_id", command, caller=MockCaller(), blocking=False)
try:
py.test.raises(ExecutorException, e.execute)
assert e.proc.poll() != None # means command failed
# the command failed, but if the caller is specified, it is
# stored in its container for subsequent cleanup
assert len(e.caller.processes) == 1
finally:
# in fact should not be running
try:
os.kill(e.proc.pid, signal.SIGKILL)
except OSError:
pass
def testExecutorBlockingException():
# should fail due to permission denied
command = "cat /etc/shadow"
e = Executor("some_id", command, caller=MockCaller(), blocking=True)
py.test.raises(ExecutorException, e.execute)
try:
assert e.proc.wait() != 0 # means command failed
# process has not been removed in
# Executor._handleBlockingProcess()
# remains in the executor container should there be required
# context for some subsequent action
assert len(e.caller.processes) == 1
finally:
# kill it (try it ...)
try:
os.kill(e.proc.pid, signal.SIGKILL)
except OSError:
pass
def testExecutorLogsCatching():
outputLogs = """------------------------------------------------------------------------------
stdout:
output to stdout
------------------------------------------------------------------------------
stderr:
output to stderr
------------------------------------------------------------------------------"""
script = """
echo "output to stdout" > /dev/stdout
echo "output to stderr" > /dev/stderr
"""
f = getTempFile(script)
command = "bash %s" % f.name
e = Executor("some_id", command, caller=None, blocking=True)
output = e.execute()
logs = e.getLogs()
def execute(self, conf=None, caller=None, apMon=None, logger=None):
"""
This method is is called on the remote site where fdtd runs - here
are also known all configuration details, thus final set up has to
happen here.
"""
startTime = datetime.datetime.now()
# may fail with subset of FDTDException which will be propagated
port = caller.getFreePort()
self._setUp(conf, port)
destFiles = self.options["destFiles"]
logger.info("%s - checking presence of files at target "
"location ..." % self.__class__.__name__)
logger.debug("Results:\n%s" % self._checkTargetFileNames(destFiles))
user = self.options["sudouser"]
logger.debug("Local grid user is '%s'" % user)
toWaitFor = conf.get("fdtServerLogOutputToWaitFor") % dict(port=port)
toWaitTimeout = conf.get("fdtServerLogOutputTimeout")
killTimeout = conf.get("fdtReceivingServerKillTimeout")
executor = Executor(self.id,
caller=caller,
command=self.command,
blocking=False,
port=port,
userName=user,
logOutputToWaitFor=toWaitFor,
killTimeout=killTimeout,
logOutputWaitTime=toWaitTimeout,
logger=logger)
try:
output = executor.execute()
# on errors, do not do any cleanup or port releasing, from
# Executor.execute() the instance is in the container and shall
# be handled by CleanupProcessesAction
except Exception, ex:
m = ("Could not start FDT server on %s port: %s, reason: %s" %
(getHostName(), port, ex))
logger.critical(m, traceBack=True)
self._checkForAddressAlreadyInUseError(str(ex), port, logger)
raise FDTDException(m)
def testFDTDKillProcess2():
c = """
[general]
port = 6700
debug = DEBUG
killCommand = ../wrapper_kill.sh %(pid)s
portRangeFDTServer = 54321,54400
"""
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
daemon = FDTD(conf, apMon, logger)
# need long-running, non blocking process
command = "dd if=/dev/zero of=/dev/null count=100000000 bs=102400"
executor = Executor("some_id",
command,
blocking=False,
caller=daemon,
logger=logger,
killTimeout=0)
try:
executor.execute()
daemon.killProcess("some_id", logger)
finally:
# definitely release port and kill the process
daemon.shutdown()
daemon.pyroDaemon.closedown()
try:
p = Process(executor.proc.pid)
m = ("FAIL: Process PID:%s should have been "
"killed." % executor.proc.pid)
logger.debug(m)
py.test.fail(m)
except NoSuchProcess, ex:
logger.debug("OK: Process PID:%s doesn't exist now." %
executor.proc.pid)
def testExecutorLogsNotCatching():
outputLogs = """------------------------------------------------------------------------------
stdout:
<catching disabled on request>
------------------------------------------------------------------------------
stderr:
<catching disabled on request>
------------------------------------------------------------------------------"""
script = """
echo "output to stdout" > /dev/stdout
echo "output to stderr" > /dev/stderr
"""
f = getTempFile(script)
command = "bash %s" % f.name
e = Executor("some_id",
command,
caller=None,
catchLogs=False,
blocking=True)
logs = e.execute()
def execute(self, conf=None, caller=None, apMon=None, logger=None):
"""
This method is invoked by fdtd once the action object is received
from remote fdtcp (where the action instance was created). Options
known on fdtd are set on the action instance (e.g. finalizing command
for invoking FDT Java - location of fdt.jar is known only at fdtd site).
"""
# this method is called on PYRO service side, user its logger
# from now on
localGridUser = self.options["gridUserSrc"]
logger.debug("Local grid user is '%s'" % localGridUser)
self.options["sudouser"] = localGridUser
self._setUp(conf)
killTimeout = conf.get("fdtSendingClientKillTimeout")
executor = Executor(self.id,
self.command,
blocking=True,
caller=caller,
userName=localGridUser,
killTimeout=killTimeout,
syncFlag=True,
logger=logger)
try:
try:
output = executor.execute()
except ExecutorException, ex:
m = ("FDT Java client on %s failed, "
"reason: %s" % (getHostName(), ex))
logger.error(m)
raise FDTDException(m)
except Exception, ex:
m = ("FDT Java client on %s failed, "
"reason: %s" % (getHostName(), ex))
logger.error(m, traceBack=True)
raise FDTDException(m)
def testFDTDWaitingTimeoutWhenCleanup():
"""
Test issues long running job (dd copy) on the background (non-blocking)
and when killing the job, the timeout is set higher than issuing ALARM
signal. It's tested that the ALARM signal was raised, but implemented
as is is in fact ignored. More obvious when the killTimeout is set much
higher.
Implementation of #33 - CleanupProcessesAction - attribute to ignore any
wait-to-finish timeouts
"""
class Handler:
def __init__(self, flag, testName):
self.flag = flag
self.testName = testName
def signalHandler(self, signum, frame):
print("test %s signal handler called (sig: %s)" %
(self.testName, signum))
# sets flag to check whether some reaction was successfully
# invoked
self.flag = True
c = """
[general]
port = 6700
debug = DEBUG
killCommand = ../wrapper_kill.sh %(pid)s
portRangeFDTServer = 54321,54400
"""
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
fdtd = FDTD(conf, apMon, logger)
# need long running job
command = "dd if=/dev/zero of=/dev/null count=100000000 bs=102400"
# set long timeout (will be interrupted sooner by alarm - while
# waiting on kill timeout)
e = Executor("some_id",
command,
caller=fdtd,
blocking=False,
killTimeout=2,
logger=logger)
try:
e.execute() # command remains is running now
# try killing the command
# since waitTimeout = True, kill will be waiting
cl = CleanupProcessesAction("some_id", timeout=1, waitTimeout=True)
handler = Handler(False, testName)
signal.signal(signal.SIGALRM, handler.signalHandler)
assert handler.flag == False
print "test %s is waiting here ..." % testName
signal.alarm(1) # raise alarm in timeout seconds
cl.execute(conf=conf, caller=fdtd, apMon=None, logger=logger)
signal.alarm(0) # disable alarm
# but the alarm was called during this waiting (test flag value)
assert handler.flag == True
finally:
fdtd.shutdown()
fdtd.pyroDaemon.closedown()
def execute(self, conf=None, caller=None, apMon=None, logger=None):
"""
This method is is called on the remote site where fdtd runs - here
are also known all configuration details, thus final set up has to
happen here.
"""
startTime = datetime.datetime.now()
# may fail with subset of FDTDException which will be propagated
port = None
if 'portServer' in self.options:
logger.info("Forcing to use user specified port %s" % self.options['portServer'])
try:
port = int(self.options['portServer'])
except TypeError as er:
logger.info("Provided portServer key is not convertable to integer: %, Error: %s", self.options['portServer'], er)
port = int(caller.getFreePort())
else:
logger.info("Try to get a free port")
port = int(caller.getFreePort())
self._setUp(conf, port)
destFiles = self.options["destFiles"]
logger.info("%s - checking presence of files at target "
"location ..." % self.__class__.__name__)
logger.debug("Results:\n%s" % self._checkTargetFileNames(destFiles))
user = self.options["sudouser"]
logger.debug("Local grid user is '%s'" % user)
toWaitFor = conf.get("fdtServerLogOutputToWaitFor") % dict(port=port)
toWaitTimeout = conf.get("fdtServerLogOutputTimeout")
killTimeout = conf.get("fdtReceivingServerKillTimeout")
executor = Executor(self.id,
caller=caller,
command=self.command,
blocking=False,
port=port,
userName=user,
logOutputToWaitFor=toWaitFor,
killTimeout=killTimeout,
logOutputWaitTime=toWaitTimeout,
logger=logger)
try:
output = executor.execute()
# on errors, do not do any cleanup or port releasing, from
# Executor.execute() the instance is in the container and shall
# be handled by CleanupProcessesAction
except Exception as ex:
raiser, ex = self._checkForAddressAlreadyInUseError(str(ex), port, logger)
m = ("Could not start FDT server on %s port: %s, reason: %s" %
(getHostName(), port, ex))
logger.critical(m, traceBack=True)
raise raiser(m)
else:
r = Result(self.id)
r.status = 0
# port on which FDT Java server runs
r.serverPort = port
r.msg = "FDT server is running"
r.log = output
logger.debug("Response to client: %s" % r)
endTime = datetime.datetime.now()
elapsed = (endTime - startTime).seconds
par = dict(id=self.id, fdt_server_init=elapsed)
logger.debug("Starting FDT server lasted: %s [s]." % elapsed)
if apMon:
logger.debug("Sending data to ApMon ...")
apMon.sendParameters("fdtd_server_writer", None, par)
return r
def testFDTDNotWaitingTimeoutWhenCleanupForced():
"""
Test issues long running job (dd copy) on the background (non-blocking)
and when killing the job, the timeout is set high. But no timeout is
waited and the command is killed immediately. Raising ALARM in 2s never
happens and command shall finish immediately (value of the flag changed
in the signal handler never happens).
Implementation of #33 - CleanupProcessesAction - attribute to ignore any
wait-to-finish timeouts
"""
class Handler:
def __init__(self, flag, testName):
self.flag = flag
self.testName = testName
def signalHandler(self, signum, frame):
print("test %s signal handler called (sig: %s)" %
(self.testName, signum))
# sets flag to check whether some reaction was successfully
# invoked
self.flag = True
c = """
[general]
port = 6700
debug = DEBUG
killCommand = ../wrapper_kill.sh %(pid)s
portRangeFDTServer = 54321,54400
"""
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
fdtd = FDTD(conf, apMon, logger)
# need long running job
command = "dd if=/dev/zero of=/dev/null count=100000000 bs=102400"
# set long timeout, shall be killed immediately anyway
e = Executor("some_id",
command,
caller=fdtd,
blocking=False,
killTimeout=100,
logger=logger)
try:
e.execute() # command remains is running now
# try killing the command
# since waitTimeout = False, shall be killed immediately
cl = CleanupProcessesAction("some_id", timeout=1, waitTimeout=False)
handler = Handler(False, testName)
signal.signal(signal.SIGALRM, handler.signalHandler)
assert handler.flag == False
signal.alarm(1) # raise alarm in timeout seconds
# should happen immediately so that ALARM is not raised
cl.execute(conf=conf, caller=fdtd, apMon=None, logger=logger)
signal.alarm(0) # disable alarm
# the alarm shouldn't have been called - value should have
# remained the same
assert handler.flag == False
finally:
fdtd.shutdown()
fdtd.pyroDaemon.closedown()
def execute(self):
"""
This method is is called on the remote site where fdtd runs - here
are also known all configuration details, thus final set up has to
happen here.
"""
startTime = datetime.datetime.now()
# may fail with subset of FDTDException which will be propagated
if 'portServer' in self.options and self.options['portServer']:
self.logger.info("Forcing to use user specified port %s" %
self.options['portServer'])
try:
self.port = int(self.options['portServer'])
except TypeError as ex:
self.logger.info(
"Provided portServer key is not convertable to integer: %s, Error: %s"
% (self.options['portServer'], ex))
self.port = int(self.caller.getFreePort())
else:
self.logger.info("Try to get a free port")
self.port = int(self.caller.getFreePort())
self._setUp(self.conf, self.port)
destFiles = self.options["destFiles"]
self.logger.info("%s - checking presence of files at target "
"location ..." % self.__class__.__name__)
self.logger.debug("Results:\n%s" %
self._checkTargetFileNames(destFiles))
user = self.options["sudouser"]
self.logger.debug("Local grid user is '%s'" % user)
self.executor = Executor(self.id,
caller=self.caller,
command=self.command,
port=self.port,
userName=user,
logger=self.logger)
try:
output = self.executor.execute()
# on errors, do not do any cleanup or port releasing, from
# Executor.execute() the instance is in the container and shall
# be handled by CleanupProcessesAction
except Exception as ex:
raiser, ex = self._checkAddrAlreadyInUseError(str(ex))
msg = ("Could not start FDT server on %s port: %s, reason: %s" %
(getHostName(), self.port, ex))
self.logger.critical(msg, traceBack=True)
self.status = -2
raise raiser(msg)
else:
rObj = Result(self.id)
rObj.status = 0
self.status = 0
# port on which FDT Java server runs
rObj.serverPort = self.port
rObj.msg = "FDT server is running"
rObj.log = output
self.logger.debug("Response to client: %s" % rObj)
endTime = datetime.datetime.now()
elapsed = (endTime - startTime).seconds
par = dict(id=self.id, fdt_server_init=elapsed)
self.logger.debug("Starting FDT server lasted: %s [s]." % elapsed)
if self.apMon:
self.logger.debug("Sending data to ApMon ...")
self.apMon.sendParameters("fdtd_server_writer", None, par)
return rObj
def testExecutorNonBlockingExceptionWrongCommand():
command = "nonsensecommandnow"
e = Executor("some_id", command, caller=MockCaller(), blocking=False)
py.test.raises(ExecutorException, e.execute)
e = Executor("some_id", command, caller=None, blocking=False)
py.test.raises(ExecutorException, e.execute)
def testKillProcessTimeout():
c = """
[general]
port = 6700
debug = DEBUG
killCommand = ../wrapper_kill.sh %(pid)s
portRangeFDTServer = 54321,54400
"""
script = """
c=$1
while [ $c -gt 0 ]
do
sleep 1
let "c -= 1"
done
exit 0
"""
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
daemon = FDTD(conf, apMon, logger)
f = getTempFile(script)
# wait time 5s
command = "bash %s 5" % f.name
# wait only 2s for me before killing
e = Executor("some_id",
command,
caller=daemon,
blocking=False,
killTimeout=3,
logger=logger)
try:
output = e.execute()
daemon.killProcess("some_id", logger)
finally:
daemon.shutdown()
daemon.pyroDaemon.closedown()
# the process was still running, timeout elapsed and was killed
assert e.proc.poll() == -9
# try different port, even if the previous was released,
# immediate rebinding attempt makes PYRO fail
inputOptions = "-d DEBUG -p 6701"
conf = ConfigFDTD(inputOptions.split())
apMon = None
daemon = FDTD(conf, apMon, logger)
# wait time 2s
command = "bash %s 2" % f.name
e = Executor("some_id",
command,
caller=daemon,
blocking=False,
killTimeout=4,
logger=logger)
try:
output = e.execute()
daemon.killProcess("some_id", logger)
finally:
daemon.shutdown()
daemon.pyroDaemon.closedown()
# the process should have normally finished, waiting killTimeout
assert e.proc.poll() == 0