def testAddressAlreadyInUseRoundRobinPortReservation():
"""
#38 - Address already in use FDT Java
https://trac.hep.caltech.edu/trac/fdtcp/ticket/38
Address already in use problem was seen during #5:comment:20
https://trac.hep.caltech.edu/trac/fdtcp/ticket/5#comment:20
2 times out of 338 transfer (attempts). Probably, when there is
traffic the port can't be bound immediately even if it was
released very short ago by the previous process.
This test could not reproduce the problem (when reusing immediately
the same port number for the next request), so FDTD.getFreePort()
was reimplemented to reserver ports on round-robin basis.
"""
hostName = os.uname()[1]
f = getTempFile(functionalFDTDConfiguration)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
testName = inspect.stack()[0][3]
logger = Logger(name=testName, logFile="/tmp/fdtdtest-%s.log" % testName, level=logging.DEBUG)
apMon = None
fdtd = FDTD(conf, apMon, logger)
# launch two subsequent ReceivingServerAction, second will likely fail
# to bind the same, just very short ago, released port
serverId = "%s" % testName
testAction = TestAction(hostName, hostName)
testAction.id = serverId
# do TestAction
r = fdtd.service.service(testAction)
assert r.status == 0
options = dict(gridUserDest="someuserDest", clientIP=os.uname()[1], destFiles=[])
recvServerAction = ReceivingServerAction(testAction.id, options)
# do ReceivingServerAction - start FDT Java server
r = fdtd.service.service(recvServerAction)
print(r.msg)
assert r.status == 0
assert r.serverPort == 54321
cleanupAction = CleanupProcessesAction(serverId, timeout=0, waitTimeout=False)
# do CleanupProcessesAction - shut FDT Java server, port shall be
# released
r = fdtd.service.service(cleanupAction)
print(r.msg)
assert r.status == 0
# do another ReceivingServerAction - start FDT Java server
r = fdtd.service.service(recvServerAction)
print(r.msg)
assert r.status == 0
# will not get the same port, but the next one in the range
assert r.serverPort == 54322
# in fact, if separate log files are enabled, after this last
# ReceivingServerAction, there is a separate log file open.
# taking the the service down, it should also closed it's related
# to open files #41 problem
fdtd.shutdown()
fdtd.pyroDaemon.closedown()
logger.close()
def testWrongPortRange():
c = """
[general]
port = 5000
portRangeFDTServer = 54321,54400x
"""
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
py.test.raises(FDTDException, FDTD, conf, apMon, logger)
c = """
[general]
port = 5000
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
py.test.raises(FDTDException, FDTD, conf, apMon, logger)
def testTracebackComplex():
logger = Logger("test logger", level=logging.DEBUG)
try:
old_div(1, 0)
except Exception:
logger.getTracebackComplex()
logger.close()
def testLogIntoClosedLogFile():
"""
Test writing into a closed logger. The logger should handle.
"""
testFile = TEST_LOG_FILE
for met, level in (('warning', logging.WARNING),
('warn', logging.WARNING),
('fatal', logging.FATAL),
('error', logging.ERROR),
('debug', logging.DEBUG),
('critical', logging.CRITICAL),
('info', logging.INFO)):
if os.path.exists(testFile):
m = "Can't do logging into file test, file %s exists." % testFile
py.test.fail(m)
logger = Logger("test file logger", logFile=testFile, level=level)
testMessage = "testLogIntoClosedLogFile-%s" % met
c = getattr(logger, met)
logger.close()
# log after closing the logger
c(testMessage)
# message to search for
toSearchMsg = ("Attempt to log into already closed.*$\n.*%s" %
testMessage)
pattObj = re.compile(toSearchMsg, re.MULTILINE)
fd = open(testFile, 'r')
match = pattObj.search(fd.read())
if not match:
m = ("Log file '%s' should contain log message '%s' - does "
"not." % (testFile, toSearchMsg))
py.test.fail(m)
os.remove(testFile)
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 as ex:
logger.debug("OK: Process PID:%s doesn't exist now." % executor.proc.pid)
def testLogIntoClosedLogFile():
"""
Test writing into a closed logger. The logger should handle.
"""
testFile = TEST_LOG_FILE
for met, level in (('warning', logging.WARNING), ('warn', logging.WARNING),
('fatal', logging.FATAL), ('error', logging.ERROR),
('debug', logging.DEBUG),
('critical', logging.CRITICAL), ('info', logging.INFO)):
if os.path.exists(testFile):
m = "Can't do logging into file test, file %s exists." % testFile
py.test.fail(m)
logger = Logger("test file logger", logFile=testFile, level=level)
testMessage = "testLogIntoClosedLogFile-%s" % met
c = getattr(logger, met)
logger.close()
# log after closing the logger
c(testMessage)
# message to search for
toSearchMsg = ("Attempt to log into already closed.*$\n.*%s" %
testMessage)
pattObj = re.compile(toSearchMsg, re.MULTILINE)
fd = open(testFile, 'r')
match = pattObj.search(fd.read())
if not match:
m = ("Log file '%s' should contain log message '%s' - does "
"not." % (testFile, toSearchMsg))
py.test.fail(m)
os.remove(testFile)
def testTracebackSimple():
logger = Logger("test logger", level=logging.DEBUG)
try:
old_div(1, 0)
except Exception:
logger.getTracebackSimple()
logger.error("exception", traceBack=True)
logger.fatal("exception", traceBack=True)
logger.close()
def testFDTDServiceOpenFiles():
"""
#41 - Too many open files (fdtd side)
"""
hostName = os.uname()[1]
f = getTempFile(functionalFDTDConfiguration)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
testName = inspect.stack()[0][3]
logger = Logger(name=testName, logFile="/tmp/fdtdtest-%s.log" % testName, level=logging.DEBUG)
apMon = None
fdtd = FDTD(conf, apMon, logger)
proc = Process(os.getpid())
initStateNumOpenFiles = len(proc.get_open_files())
for testAction in [TestAction("fakeSrc", "fakeDst") for i in range(3)]:
r = fdtd.service.service(testAction)
logger.debug("Result: %s" % r)
assert r.status == 0
# after TestAction, there should not be left behind any open files
numOpenFilesNow = len(proc.get_open_files())
assert initStateNumOpenFiles == numOpenFilesNow
# test on ReceivingServerAction - it's action after which the
# separate logger is not closed, test the number of open files went +1,
# send CleanupProcessesAction and shall again remain
# initStateNumOpenFiles send appropriate TestAction first (like in real)
serverId = "server-id"
testAction = TestAction(hostName, hostName)
testAction.id = serverId
r = fdtd.service.service(testAction)
assert r.status == 0
options = dict(gridUserDest="someuserDest", clientIP=os.uname()[1], destFiles=[])
recvServerAction = ReceivingServerAction(testAction.id, options)
r = fdtd.service.service(recvServerAction)
print(r.msg)
assert r.status == 0
numOpenFilesNow = len(proc.get_open_files())
# there should be only 1 extra opened file now
assert initStateNumOpenFiles == numOpenFilesNow - 1
cleanupAction = CleanupProcessesAction(serverId, timeout=2)
r = fdtd.service.service(cleanupAction)
print(r.msg)
assert r.status == 0
numOpenFilesNow = len(proc.get_open_files())
assert initStateNumOpenFiles == numOpenFilesNow
fdtd.shutdown()
fdtd.pyroDaemon.closedown()
logger.close()
def testTracebackSimple():
logger = Logger("test logger", level=logging.DEBUG)
try:
old_div(1, 0)
except Exception:
logger.getTracebackSimple()
logger.error("exception", traceBack=True)
logger.fatal("exception", traceBack=True)
logger.close()
def testReleasePort():
c = """
[general]
port = 5000
portRangeFDTServer = 54321,54323
"""
# only ports 54321, 54322, 54323 are available to play:
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)
assert daemon.getFreePort() == 54321
assert daemon.getFreePort() == 54322
# nothing should happen
py.test.raises(PortReservationException, daemon.releasePort, 20)
py.test.raises(PortReservationException, daemon.releasePort, "aa")
assert daemon.getFreePort() == 54323
daemon.releasePort(54321)
daemon.releasePort(54322)
assert daemon.getFreePort() == 54321
assert daemon.getFreePort() == 54322
py.test.raises(PortReservationException, daemon.getFreePort)
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testTransfersCopyJobFileWrongFormat():
# blank lines (triple quotes not directly in front of the first line
# should also cause exception being raised
# non-numeric port numbers
data = """
fdt://host1:123/tmp/file host5:123/tmp/fileX1
fdt://host2:123234/tmp/file1
fdt://host2:14124/tmp/file3 host6:124/tmp/fileX
fdt://host2:14124c/tmp/file3 host6:124c/tmp/fileX
fdt://host2:14124/tmp/file3 fdt://host6:124c/tmp/fileX
fdt://host2:14124x/tmp/file3 fdt://host6:124/tmp/fileX
- -
"""
logger = Logger("test logger", level=logging.DEBUG)
for line in data.split('\n'):
copyJobFile = tempfile.NamedTemporaryFile("w+") # read / write
print("copyjobfile contains: '%s'" % line)
copyJobFile.write(line)
copyJobFile.flush()
copyJobFile.seek(0)
inputOption = "--copyjobfile=%s" % copyJobFile.name
conf = ConfigFDTCopy(inputOption.split())
apMon = None
py.test.raises(FDTCopyException, Transfers, conf, apMon, logger)
def __init__(self, idE, command, caller=None, port=None,
userName=None, logger=None):
# id of the associated action / request
self.id = idE
# actual command to execute in the process
self.command = command
# caller is the creator of this Executor class instance, if caller is
# provided, it has to have addExecutor(), removeExecutor() and
# checkExecutorPresence() methods by which this instance
# registers / de-registers itself with the upper layer (its invoker)
self.caller = caller
# in case of non-blocking process (and if it's a service running on
# a port) keep track of this port, if desirable
self.port = port
# if the process is run via sudo, keep track of the sudo-owner of this
# process (i.e. of this Executor) - needed when killing this process,
# default None means the same user who runs the main script
self.userName = userName
self.logger = logger or Logger(name="Executor", level=logging.DEBUG)
self.lastMessage = ""
# process instance as created by subprocess.Popen
self.proc = None
# returncode from the underlying self.proc instance
self.returncode = None
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 testLoggerFile():
testFile = "testlogfile.log"
if not os.path.exists(testFile):
logger = Logger("test file logger", logFile = testFile,
level = logging.INFO)
testMessage = "testmessage"
logger.info(testMessage)
line = open(testFile, 'r').readlines()
os.remove(testFile)
last = line[-1].split()[-1]
logger.close()
assert testMessage == last
else:
m = "Can't do logging into file test, file %s exists." % testFile
py.test.fail(m)
def testLoggerFile():
testFile = TEST_LOG_FILE
if not os.path.exists(testFile):
logger = Logger("test file logger",
logFile=testFile,
level=logging.INFO)
testMessage = "testmessage"
logger.info(testMessage)
logger.close()
line = open(testFile, 'r').readlines()
os.remove(testFile)
# not the last line which the logger closing plus 3 x \n , but
# line before that
last = line[-5].split()[-1]
assert testMessage == last
else:
m = "Can't do logging into file test, file %s exists." % testFile
py.test.fail(m)
def testFDTDDesiredPortOccupiedRaisesException():
inputOptions = "-d DEBUG -p 6700 -H localhost"
conf = ConfigFDTD(inputOptions.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
daemon = FDTD(conf, apMon, logger)
py.test.raises(FDTDException, FDTD, conf, apMon, logger)
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testTransfersCopyJobFile():
# correct data
data = \
"""fdt://host1:111/tmp/file fdt://host5:222//tmp/fileX1
fdt://host2:555/tmp/fileGY fdt://host5:444/tmp/fileX2
fdt://host2:555/tmp/fileWA fdt://host5:444/tmp/fileX
fdt://host3:777/tmp/fileWQ fdt://host7:888/tmp/fileTY
fdt://host4:999/tmp/file9Y fdt://host8:1212/tmp/fileIO"""
logger = Logger("test logger", level=logging.DEBUG)
copyJobFile = tempfile.NamedTemporaryFile("w+") # read / write
copyJobFile.write(data)
copyJobFile.flush()
copyJobFile.seek(0)
inputOption = "--copyjobfile=%s" % copyJobFile.name
conf = ConfigFDTCopy(inputOption.split())
apMon = None
transfers = Transfers(conf, apMon, logger)
assert len(transfers.transfers) == 4
assert len(transfers.transfers["host1:111-host5:222"].files) == 1
assert len(transfers.transfers["host2:555-host5:444"].files) == 2
assert len(transfers.transfers["host3:777-host7:888"].files) == 1
assert len(transfers.transfers["host4:999-host8:1212"].files) == 1
# correct port numbers are tested as part of key to transfers.transfer
assert transfers.transfers["host1:111-host5:222"].hostSrc == "host1"
assert transfers.transfers["host1:111-host5:222"].hostDest == "host5"
assert transfers.transfers["host1:111-host5:222"].files[0].fileSrc == \
"/tmp/file"
assert transfers.transfers["host1:111-host5:222"].files[0].fileDest == \
"/tmp/fileX1"
assert transfers.transfers["host2:555-host5:444"].hostSrc == "host2"
assert transfers.transfers["host2:555-host5:444"].hostDest == "host5"
assert transfers.transfers["host2:555-host5:444"].files[0].fileSrc == \
"/tmp/fileGY"
assert transfers.transfers["host2:555-host5:444"].files[0].fileDest == \
"/tmp/fileX2"
assert transfers.transfers["host2:555-host5:444"].files[1].fileSrc == \
"/tmp/fileWA"
assert transfers.transfers["host2:555-host5:444"].files[1].fileDest == \
"/tmp/fileX"
assert transfers.transfers["host3:777-host7:888"].hostSrc == "host3"
assert transfers.transfers["host3:777-host7:888"].hostDest == "host7"
assert transfers.transfers["host3:777-host7:888"].files[0].fileSrc == \
"/tmp/fileWQ"
assert transfers.transfers["host3:777-host7:888"].files[0].fileDest == \
"/tmp/fileTY"
assert transfers.transfers["host4:999-host8:1212"].hostSrc == "host4"
assert transfers.transfers["host4:999-host8:1212"].hostDest == "host8"
assert transfers.transfers["host4:999-host8:1212"].files[0].fileSrc == \
"/tmp/file9Y"
assert transfers.transfers["host4:999-host8:1212"].files[0].fileDest == \
"/tmp/fileIO"
def testAuthService():
inputOptions = "-d DEBUG -p 6700 -H localhost"
conf = ConfigFDTD(inputOptions.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
daemon = FDTD(conf, apMon, logger)
# shall fail due to unavailable grid credentials (when running locally)
py.test.raises(AuthServiceException, AuthService, daemon, conf, logger)
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testReceivingServerActionCheckTargetFileNames():
logger = Logger()
files = ["/mnt/data", "/etc/passwd", "/etc/something/nonsence", "/tmp"]
options = dict(port=1000, gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
logger.info("%s - checking presence of files at target location ..." %
a.__class__.__name__)
r = a._checkTargetFileNames(files)
logger.debug("Results:\n%s" % r)
expected = \
""" exists True: /mnt/data
exists False: /mnt/.data
exists True: /etc/passwd
exists False: /etc/.passwd
exists False: /etc/something/nonsence
exists False: /etc/something/.nonsence
exists True: /tmp
exists False: /.tmp
"""
assert r == expected
def testFDTDKillProcess1():
inputOptions = "-d DEBUG -p 6700 -H localhost"
conf = ConfigFDTD(inputOptions.split())
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
apMon = None
daemon = FDTD(conf, apMon, logger)
# now doesn't fail, just says "some_id" process doesn't exist in the
# executors container
daemon.killProcess("some_id", logger)
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testTracebackComplex():
logger = Logger("test logger", level=logging.DEBUG)
try:
old_div(1, 0)
except Exception:
logger.getTracebackComplex()
logger.close()
def testConfigIllegalPort():
# wrong port - expect exception - port as string
inputOptions = "-d DEBUG -p ABC"
testName = inspect.stack()[0][3]
logger = Logger(name=testName, level=logging.DEBUG)
conf = ConfigFDTD(inputOptions.split())
apMon = None
py.test.raises(FDTDException, FDTD, conf, apMon, logger)
# if port is not set ...
conf._options["port"] = None
apMon = None
py.test.raises(FDTDException, FDTD, conf, apMon, logger)
def testFDTDServiceOpenFiles():
"""
#41 - Too many open files (fdtd side)
"""
hostName = os.uname()[1]
f = getTempFile(functionalFDTDConfiguration)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
testName = inspect.stack()[0][3]
logger = Logger(name=testName,
logFile="/tmp/fdtdtest-%s.log" % testName,
level=logging.DEBUG)
apMon = None
fdtd = FDTD(conf, apMon, logger)
proc = Process(os.getpid())
initStateNumOpenFiles = len(proc.get_open_files())
for testAction in [TestAction("fakeSrc", "fakeDst") for i in range(3)]:
r = fdtd.service.service(testAction)
logger.debug("Result: %s" % r)
assert r.status == 0
# after TestAction, there should not be left behind any open files
numOpenFilesNow = len(proc.get_open_files())
assert initStateNumOpenFiles == numOpenFilesNow
# test on ReceivingServerAction - it's action after which the
# separate logger is not closed, test the number of open files went +1,
# send CleanupProcessesAction and shall again remain
# initStateNumOpenFiles send appropriate TestAction first (like in real)
serverId = "server-id"
testAction = TestAction(hostName, hostName)
testAction.id = serverId
r = fdtd.service.service(testAction)
assert r.status == 0
options = dict(gridUserDest="someuserDest",
clientIP=os.uname()[1],
destFiles=[])
recvServerAction = ReceivingServerAction(testAction.id, options)
r = fdtd.service.service(recvServerAction)
print r.msg
assert r.status == 0
numOpenFilesNow = len(proc.get_open_files())
# there should be only 1 extra opened file now
assert initStateNumOpenFiles == numOpenFilesNow - 1
cleanupAction = CleanupProcessesAction(serverId, timeout=2)
r = fdtd.service.service(cleanupAction)
print r.msg
assert r.status == 0
numOpenFilesNow = len(proc.get_open_files())
assert initStateNumOpenFiles == numOpenFilesNow
fdtd.shutdown()
fdtd.pyroDaemon.closedown()
logger.close()
def testCleanupProcessesAction():
logger = Logger()
a = CleanupProcessesAction("some_id", timeout=4)
assert a.id == "some_id"
assert a.timeout == 4
assert a.waitTimeout
fdtd = Mock()
# wihtout this, it remains in the loop, see
# CleanupProcessesAction.execute()
fdtd.getExecutor().syncFlag = False
r = a.execute(caller=fdtd, logger=logger)
assert r.status == 0
a = CleanupProcessesAction("some_id", timeout=5, waitTimeout=False)
assert a.waitTimeout == False
def testTransfersGeneral():
logger = Logger("test logger", level=logging.DEBUG)
conf = ConfigFDTCopy("-r /tmp/report fdt://host1:123/tmp/file "
"fdt://host2:12355/tmp/file1".split())
apMon = None
transfers = Transfers(conf, apMon, logger)
assert len(transfers.transfers) == 1
assert len(transfers.transfers["host1:123-host2:12355"].files) == 1
assert transfers.transfers["host1:123-host2:12355"].hostSrc == "host1"
assert transfers.transfers["host1:123-host2:12355"].portSrc == "123"
assert transfers.transfers["host1:123-host2:12355"].files[0].fileSrc == \
"/tmp/file"
assert transfers.transfers["host1:123-host2:12355"].hostDest == "host2"
assert transfers.transfers["host1:123-host2:12355"].portDest == "12355"
assert transfers.transfers["host1:123-host2:12355"].files[0].fileDest == \
"/tmp/file1"
assert transfers.transfers["host1:123-host2:12355"].result == 1
def testCorrectPortRange():
c = """
[general]
port = 5000
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)
assert daemon._portMgmt._ports[0]._port == 54321
assert daemon._portMgmt._ports[-1]._port == 54400
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testGetFreePort():
c = """
[general]
port = 5000
portRangeFDTServer = 54321,54323
"""
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)
assert daemon.getFreePort() == 54321
assert daemon.getFreePort() == 54322
assert daemon.getFreePort() == 54323
py.test.raises(PortReservationException, daemon.getFreePort)
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testTransfer():
# correct data
data = \
"""fdt://localhost1:111/tmp/file fdt://localhost5:444/tmp/fileX1
fdt://localhost2:111/tmp/fileGY fdt://localhost5:444/tmp/fileX2
fdt://localhost2:111/tmp/fileWA fdt://localhost5:444/tmp/fileX
fdt://localhost3:111/tmp/fileWQ fdt://localhost7:444/tmp/fileTY
fdt://localhost4:111/tmp/file9Y fdt://localhost8:444/tmp/fileIO"""
logger = Logger("test logger", level=logging.DEBUG)
copyJobFile = tempfile.NamedTemporaryFile("w+") # read / write
copyJobFile.write(data)
copyJobFile.flush()
copyJobFile.seek(0)
inputOption = "--copyjobfile=%s" % copyJobFile.name
conf = ConfigFDTCopy(inputOption.split())
# transfers actually fail with could not connect to remote PYRO
# wrong hosts - no Transfer instances will be setUp()
apMon = None
transfers = Transfers(conf, apMon, logger)
def testLoggerFile():
testFile = TEST_LOG_FILE
if not os.path.exists(testFile):
logger = Logger("test file logger",
logFile=testFile,
level=logging.INFO)
testMessage = "testmessage"
logger.info(testMessage)
logger.close()
line = open(testFile, 'r').readlines()
os.remove(testFile)
# not the last line which the logger closing plus 3 x \n , but
# line before that
last = line[-5].split()[-1]
assert testMessage == last
else:
m = "Can't do logging into file test, file %s exists." % testFile
py.test.fail(m)
def testReceivingServerActionCheckTargetFileNames():
logger = Logger()
files = ["/mnt/data", "/etc/passwd", "/etc/something/nonsence", "/tmp"]
options = dict(port=1000, gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
logger.info("%s - checking presence of files at target location ..." %
a.__class__.__name__)
r = a._checkTargetFileNames(files)
logger.debug("Results:\n%s" % r)
expected = \
""" exists True: /mnt/data
exists False: /mnt/.data
exists True: /etc/passwd
exists False: /etc/.passwd
exists False: /etc/something/nonsence
exists False: /etc/something/.nonsence
exists True: /tmp
exists False: /.tmp
"""
assert r == expected
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 testLogger():
logger = Logger("test logger", level=logging.DEBUG)
logger.info("info message")
logger.warn("warn message")
logger.warning("warning message")
logger.error("error message")
logger.critical("critical message")
logger.fatal("fatal message")
logger.debug("debug message")
logger.close()
def testLoggerTraceBackTrueOnNoException():
logger = Logger("test file logger", level=logging.DEBUG)
logger.debug("my msg", traceBack=True)
def testReceivingServerAddressAlreadyInUse():
c = """
[general]
port = 6700
debug = DEBUG
portRangeFDTServer = 54321,54323
fdtReceivingServerCommand = java -jar ../fdtjava/fdt.jar -bs 64K -p %(port)s -wCount 5 -S -noupdates
fdtServerLogOutputTimeout = 2
fdtServerLogOutputToWaitFor = "FDTServer start listening on port: %(port)s"
fdtReceivingServerKillTimeout = 1
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
files = ["/mnt/data", "/etc/passwd", "/etc/something/nonsence", "/tmp"]
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
a._checkForAddressAlreadyInUseError("some message", 222, logger)
a._checkForAddressAlreadyInUseError("some message", 25, logger)
a._checkForAddressAlreadyInUseError("Address already in use", 25, logger)
a._checkForAddressAlreadyInUseError("Address already in use", 22225,
logger)
logger.info("Now real FDT Java server real attempts")
logger.info('#' * 78)
# 1) successful attempt
logger.info('1' * 78)
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
assert len(daemon._executors) == 0
result = a.execute(conf=conf, caller=daemon, apMon=apMon, logger=logger)
assert len(daemon._executors) == 1
assert result.status == 0
assert result.serverPort == 54321
assert result.msg == "FDT server is running"
# 2) this executor attempt shall fail with Address already in use,
# fool into reusing the same port 54321 as the previous process
# by replacing caller.getFreePort() method which is used in
# ReceivingServerAction.exectute()
def myFoolGetFreePort(inp, logger):
def returner():
logger.debug("myFoolGetFreePort called, returning %s" % inp)
return inp
return returner
daemon.getFreePort = myFoolGetFreePort(54321, logger)
logger.info('2' * 78)
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id-2", options)
py.test.raises(FDTDException,
a.execute,
conf=conf,
caller=daemon,
apMon=apMon,
logger=logger)
# starting FDT Java command failed, but the request remains in the
# executor container for later cleanup
assert len(daemon._executors) == 2
# 3) kill both executors / processes - one running, other failed
logger.info('3' * 78)
daemon.killProcess("some_id", logger, waitTimeout=False)
assert len(daemon._executors) == 1
daemon.killProcess("some_id-2", logger, waitTimeout=False)
assert len(daemon._executors) == 0
# 4) try starting FDT Java server on privileged port - will fail
logger.info('4' * 78)
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
daemon.getFreePort = myFoolGetFreePort(999, logger)
py.test.raises(FDTDException,
a.execute,
conf=conf,
caller=daemon,
apMon=apMon,
logger=logger)
assert len(daemon._executors) == 1
daemon.killProcess("some_id", logger, waitTimeout=False)
assert len(daemon._executors) == 0
daemon.shutdown()
daemon.pyroDaemon.closedown()
f.flush()
f.close()
def main():
# all values and action information held in the conf object
optBackup = sys.argv[:]
try:
conf = ConfigFDTCopy(sys.argv[1:])
conf.sanitize()
except ConfigurationException, ex:
print "fdtcp failed to start, reason: %s" % ex
sys.exit(1)
logger = Logger(name="fdtcp",
logFile=conf.get("logFile"),
level=conf.get("debug"))
# ticket #35 - mercurial expandable keywords in the code
# information from the SCM (expandable keywords)
versionInfo = dict(Revision="$Revision: cf25e731af0a $",
Tags="$Tags: tip $")
logger.info("fdtcp starting ... version: %s" %
logger.pprintFormat(versionInfo))
logger.debug("Search sys.path:\n%s\n" % logger.pprintFormat(sys.path))
logger.debug("PYRO_STORAGE: '%s'" % os.environ.get("PYRO_STORAGE"))
logger.debug("Input command line arguments: '%s'" % optBackup)
logger.debug("Configuration values (processed):\n%s\n" %
logger.pprintFormat(conf._options))
apMon = None
def testReceivingServerAddressAlreadyInUse():
c = """
[general]
port = 6700
debug = DEBUG
portRangeFDTServer = 54321,54323
fdtReceivingServerCommand = java -jar ../fdtjava/fdt.jar -bs 64K -p %(port)s -wCount 5 -S -noupdates
fdtServerLogOutputTimeout = 2
fdtServerLogOutputToWaitFor = "FDTServer start listening on port: %(port)s"
fdtReceivingServerKillTimeout = 1
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
files = ["/mnt/data", "/etc/passwd", "/etc/something/nonsence", "/tmp"]
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
a._checkForAddressAlreadyInUseError("some message", 222, logger)
a._checkForAddressAlreadyInUseError("some message", 25, logger)
a._checkForAddressAlreadyInUseError("Address already in use", 25, logger)
a._checkForAddressAlreadyInUseError("Address already in use", 22225,
logger)
logger.info("Now real FDT Java server real attempts")
logger.info('#' * 78)
# 1) successful attempt
logger.info('1' * 78)
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
assert len(daemon._executors) == 0
result = a.execute(conf=conf, caller=daemon, apMon=apMon, logger=logger)
assert len(daemon._executors) == 1
assert result.status == 0
assert result.serverPort == 54321
assert result.msg == "FDT server is running"
# 2) this executor attempt shall fail with Address already in use,
# fool into reusing the same port 54321 as the previous process
# by replacing caller.getFreePort() method which is used in
# ReceivingServerAction.exectute()
def myFoolGetFreePort(inp, logger):
def returner():
logger.debug("myFoolGetFreePort called, returning %s" % inp)
return inp
return returner
daemon.getFreePort = myFoolGetFreePort(54321, logger)
logger.info('2' * 78)
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id-2", options)
py.test.raises(FDTDException, a.execute, conf=conf, caller=daemon,
apMon=apMon, logger=logger)
# starting FDT Java command failed, but the request remains in the
# executor container for later cleanup
assert len(daemon._executors) == 2
# 3) kill both executors / processes - one running, other failed
logger.info('3' * 78)
daemon.killProcess("some_id", logger, waitTimeout=False)
assert len(daemon._executors) == 1
daemon.killProcess("some_id-2", logger, waitTimeout=False)
assert len(daemon._executors) == 0
# 4) try starting FDT Java server on privileged port - will fail
logger.info('4' * 78)
options = dict(gridUserDest="someuser", destFiles=files)
a = ReceivingServerAction("some_id", options)
daemon.getFreePort = myFoolGetFreePort(999, logger)
py.test.raises(FDTDException, a.execute, conf=conf, caller=daemon,
apMon=apMon, logger=logger)
assert len(daemon._executors) == 1
daemon.killProcess("some_id", logger, waitTimeout=False)
assert len(daemon._executors) == 0
daemon.shutdown()
daemon.pyroDaemon.closedown()
def testInputCopyJobFileTranslationIntoFDTFileList():
# correct data - input copyjobfile - all must be the same source host,
# destination host pairs, otherwise such input copyjobfile will break
# into a number of FDT fileList files on corresponding source hosts
inputData = \
"""fdt://localhost:111/tmp/file fdt://localhost:222/tmp/fileX1
fdt://localhost:111/tmp/fileGY fdt://localhost:222/tmp/fileX2
fdt://localhost:111/tmp/fileWA fdt://localhost:222/tmp/fileX
fdt://localhost:111/tmp/fileWQ fdt://localhost:222/tmp/fileTY
fdt://localhost:111/tmp/file9Y fdt://localhost:222/tmp/fileIO"""
# desired output fileList for FDT client
outputData = \
"""/tmp/file / /tmp/fileX1
/tmp/fileGY / /tmp/fileX2
/tmp/fileWA / /tmp/fileX
/tmp/fileWQ / /tmp/fileTY
/tmp/file9Y / /tmp/fileIO"""
logger = Logger("test logger", level=logging.DEBUG)
copyJobFile = tempfile.NamedTemporaryFile("w+") # read / write
copyJobFile.write(inputData)
copyJobFile.flush()
copyJobFile.seek(0)
inputOption = "--copyjobfile=%s" % copyJobFile.name
conf = ConfigFDTCopy(inputOption.split())
apMon = None
transfers = Transfers(conf, apMon, logger)
# since having the same source host, destination host pair, should have
# only one transfer job
t = transfers.transfers["localhost:111-localhost:222"]
assert len(transfers.transfers) == 1
assert len(t.files) == 5
# do relevant stuff from fdtcp performTransfer method now
testAction = TestAction(t.hostSrc, t.hostDest, timeout=5)
t.id = testAction.id
options = dict(port="some_port",
hostDest=t.hostDest,
transferFiles=t.files)
sndClientAction = SendingClientAction(testAction.id, options)
assert sndClientAction.options["port"] == "some_port"
assert sndClientAction.options["hostDest"] == t.hostDest
# fileList is constructed at the side of fdtd service (remote site)
# simulate this process ...
class MockFDTDConfig(Mock):
# mock class only to satisfy sndClientAction._setUp() call - when
# it checks for log file
def get(self, what):
return "/tmp/logfile"
# this method is called on fdtd service site
sndClientAction._setUp(MockFDTDConfig())
assert sndClientAction.options["fileList"] == \
"/tmp/fileLists/fdt-fileList-%s" % sndClientAction.id
# now check content of the fileList file - shall be as the output data
data = open(sndClientAction.options["fileList"], 'r').readlines()
for line1, line2 in zip(data, outputData.split('\n')):
assert line1.strip() == line2
# clean up after test, only if succeeded
os.unlink(sndClientAction.options["fileList"])
def testFDTDServiceOpenFilesFullTransfer():
"""
#41:comment:8 - Too many open files (fdtd side)
SendingClient actually removed itself from the executors container
once it finishes so subsequent CleanupProcessesAction doesn't know
about this process, nor about its open separate log file, which
doesn't get closed.
Simulate a simple successful transfer, send all actions and
check number of open files - does all as it happens in fdtd.service()
"""
hostName = os.uname()[1]
testName = inspect.stack()[0][3]
initStateNumOpenFilesTestStart, filesStr = getOpenFilesList()
print("%s: test 0: open files: %s items:\n%s" % (testName, initStateNumOpenFilesTestStart, filesStr))
# there should not be any open files now
assert initStateNumOpenFilesTestStart == 0
f = getTempFile(functionalFDTDConfiguration)
inputOption = "--config=%s --port=10001" % f.name
confServer = ConfigFDTD(inputOption.split())
confServer.sanitize()
loggerServer = Logger(name=testName, logFile="/tmp/fdtdtest-%s-writer.log" % testName, level=logging.DEBUG)
apMon = None
fdtdServer = FDTD(confServer, apMon, loggerServer)
inputOption = "--config=%s --port=10002" % f.name
confReader = ConfigFDTD(inputOption.split())
confReader.sanitize()
loggerReader = Logger(name=testName, logFile="/tmp/fdtdtest-%s-reader.log" % testName, level=logging.DEBUG)
apMon = None
fdtdReader = FDTD(confReader, apMon, loggerReader)
# -2 open log files, additional -1 is the temp config file
initStateNumOpenFiles, filesStr = getOpenFilesList()
print("%s: test 1: open files: %s items:\n%s" % (testName, initStateNumOpenFiles, filesStr))
assert initStateNumOpenFilesTestStart == initStateNumOpenFiles - 2 - 1
testActionServer = TestAction(hostName, hostName)
testActionServer.id = testActionServer.id + "-writer"
r = fdtdServer.service.service(testActionServer)
assert r.status == 0
options = dict(gridUserDest="someuserDest", clientIP=os.uname()[1], destFiles=["/dev/null"])
recvServerAction = ReceivingServerAction(testActionServer.id, options)
r = fdtdServer.service.service(recvServerAction)
print(r.msg)
assert r.status == 0
serverFDTPort = r.serverPort
# there should be only 1 extra opened file now - ReceivingServerAction
# separate log
numOpenFilesNow, filesStr = getOpenFilesList()
print("%s: test 2: open files: %s items:\n%s" % (testName, numOpenFilesNow, filesStr))
assert initStateNumOpenFiles == numOpenFilesNow - 1
testActionReader = TestAction(hostName, hostName)
testActionReader.id = testActionReader.id + "-reader"
r = fdtdReader.service.service(testActionReader)
assert r.status == 0
files = [TransferFile("/etc/passwd", "/dev/null")] # list of TransferFile
options = dict(port=serverFDTPort, hostDest=os.uname()[1], transferFiles=files, gridUserSrc="soemuserSrc")
sndClientAction = SendingClientAction(testActionReader.id, options)
r = fdtdReader.service.service(sndClientAction)
assert r.status == 0
# there should be +2 extra - for separate both server and client
numOpenFilesNow, filesStr = getOpenFilesList()
print("%s: test 3: open files: %s items:\n%s" % (testName, numOpenFilesNow, filesStr))
# 2 extra files - separate transfer log at both ends
assert initStateNumOpenFiles == numOpenFilesNow - 2
# now the transfer is over, both server (writer) and sender (reader)
# parties kept their separate log files open, CleanupProcessesAction
# will close them
print("going to clean up")
cl = CleanupProcessesAction(testActionReader.id, waitTimeout=False)
r = fdtdReader.service.service(cl)
assert r.status == 0
# one shall be closed now
numOpenFilesNow, filesStr = getOpenFilesList()
print("%s: test 4: open files: %s items:\n%s" % (testName, numOpenFilesNow, filesStr))
assert initStateNumOpenFiles == numOpenFilesNow - 1
cl = CleanupProcessesAction(testActionServer.id, waitTimeout=False)
r = fdtdServer.service.service(cl)
assert r.status == 0
# both separate log files should be closed now
# problem #41:comment:8 was here - server behaved correctly, but
# reader kept its separate log file open
numOpenFilesNow, filesStr = getOpenFilesList()
print("%s: test 5: open files: %s items:\n%s" % (testName, numOpenFilesNow, filesStr))
assert initStateNumOpenFiles == numOpenFilesNow
fdtdServer.shutdown()
fdtdServer.pyroDaemon.closedown()
loggerServer.close()
fdtdReader.shutdown()
fdtdReader.pyroDaemon.closedown()
loggerReader.close()
# after even log files were closed, etc
numOpenFilesNow, filesStr = getOpenFilesList()
print("%s: test 6: open files: %s items:\n%s" % (testName, numOpenFilesNow, filesStr))
# -1: the temp configuration file is still open
assert initStateNumOpenFilesTestStart == numOpenFilesNow - 1
def testTransfersCopyJobFileNonExisting():
logger = Logger("test logger", level=logging.DEBUG)
inputOption = "--copyjobfile=/tmp/nonexistingfile"
conf = ConfigFDTCopy(inputOption.split())
apMon = None
py.test.raises(FDTCopyException, Transfers, conf, apMon, logger)
def testLogger():
logger = Logger("test logger", level=logging.DEBUG)
logger.info("info message")
logger.warn("warn message")
logger.warning("warning message")
logger.error("error message")
logger.critical("critical message")
logger.fatal("fatal message")
logger.debug("debug message")
logger.close()
f.flush()
f.close()
def main():
# all values and action information held in the conf object
optBackup = sys.argv[:]
try:
conf = ConfigFDTCopy(sys.argv[1:])
conf.sanitize()
except ConfigurationException, ex:
print "fdtcp failed to start, reason: %s" % ex
sys.exit(1)
logger = Logger(name = "fdtcp", logFile = conf.get("logFile"),
level = conf.get("debug"))
logger.info("fdtcp starting ...")
logger.debug("Search sys.path: '%s'" % sys.path)
logger.debug("PYRO_STORAGE: '%s'" % os.environ.get("PYRO_STORAGE"))
logger.debug("Input command line arguments: '%s'" % optBackup)
logger.debug("Configuration values (processed): '%s'" % conf._options)
apMonDestConf = conf.get("apMonDestinations")
apMonDestinations = tuple(apMonDestConf.split(','))
logger.info("Initializing MonALISA ApMon, destinations: %s ..." % (apMonDestinations,))
apMon = apmon.ApMon(apMonDestinations)
apMon.enableBgMonitoring(True)
# use DNS names rather than IP address
Pyro.config.PYRO_DNS_URI = True
def testTransferGeneral():
logger = Logger("test logger", level=logging.DEBUG)
conf = ConfigFDTCopy("-r /tmp/report fdt://host1:123/tmp/file "
"fdt://host2:123/tmp/file1".split())
apMon = None
transfer = Transfer(conf, apMon, logger)
def testMainLogFileOpeningDuringDaemonisation():
py.test.skip("Test skipped, messes up with input/output streams for "
"other test, better to run it stand-alone: "
"py.test fdtcplib/test/test_fdtd.py -s -k testMainLogFileOpeningDuringDaemonisation")
"""
As described in the problem #41:comment:9, the main log file remains
open thrice (under different descriptor) after initial daemonisation.
In order to include this particular test into whole test suite running
(issue with file descriptors being redirected, etc in fdtd.daemonize()
function), perhaps after running this test, the file descriptors
can be put back from backup sys.__stdout__, etc?
"""
c = """
[general]
logFile = /tmp/fdtd.log
pidFile = /tmp/fdtd.pid
"""
testName = inspect.stack()[0][3]
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
f.close()
logFile = "%s-%s" % (conf.get("logFile"), testName)
pidFile = conf.get("pidFile")
if os.path.exists(logFile):
print("test: %s: file '%s' exists, removing ..." %
(testName, logFile))
os.remove(logFile)
if os.path.exists(pidFile):
print("test: %s: file '%s' exists, removing ..." %
(testName, pidFile))
os.remove(pidFile)
logger = Logger(name=testName, logFile=logFile, level=logging.DEBUG)
logger.debug("Before daemonization ...")
numFiles, filesStr = getOpenFilesList()
logger.debug("Logging open files: %s items:\n%s" % (numFiles, filesStr))
try:
daemonize(conf, logger)
except SystemExit:
# previous leading process continues here
return
# here continues the newly created background daemon
f = open(pidFile, 'r')
rc = f.read()
f.close()
rc = rc.strip()
pid = int(rc)
numFiles, filesStr = getOpenFilesList()
logger.debug("Logging open files: %s items:\n%s" % (numFiles, filesStr))
logger.debug("Before finishing ... ")
logger.close()
# the log file may be open more times due to streams descriptor
# duplication as done in fdtd.daemonization() but now, once is
# closed, there should not any other outstanding open file
assert numFiles == 0
def testMainLogFileOpeningDuringDaemonisation():
py.test.skip(
"Test skipped, messes up with input/output streams for "
"other test, better to run it stand-alone: "
"py.test fdtcplib/test/test_fdtd.py -s -k testMainLogFileOpeningDuringDaemonisation"
)
"""
As described in the problem #41:comment:9, the main log file remains
open thrice (under different descriptor) after initial daemonisation.
In order to include this particular test into whole test suite running
(issue with file descriptors being redirected, etc in fdtd.daemonize()
function), perhaps after running this test, the file descriptors
can be put back from backup sys.__stdout__, etc?
"""
c = """
[general]
logFile = /tmp/fdtd.log
pidFile = /tmp/fdtd.pid
"""
testName = inspect.stack()[0][3]
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
f.close()
logFile = "%s-%s" % (conf.get("logFile"), testName)
pidFile = conf.get("pidFile")
if os.path.exists(logFile):
print("test: %s: file '%s' exists, removing ..." % (testName, logFile))
os.remove(logFile)
if os.path.exists(pidFile):
print("test: %s: file '%s' exists, removing ..." % (testName, pidFile))
os.remove(pidFile)
logger = Logger(name=testName, logFile=logFile, level=logging.DEBUG)
logger.debug("Before daemonization ...")
numFiles, filesStr = getOpenFilesList()
logger.debug("Logging open files: %s items:\n%s" % (numFiles, filesStr))
try:
daemonize(conf, logger)
except SystemExit:
# previous leading process continues here
return
# here continues the newly created background daemon
f = open(pidFile, "r")
rc = f.read()
f.close()
rc = rc.strip()
pid = int(rc)
numFiles, filesStr = getOpenFilesList()
logger.debug("Logging open files: %s items:\n%s" % (numFiles, filesStr))
logger.debug("Before finishing ... ")
logger.close()
# the log file may be open more times due to streams descriptor
# duplication as done in fdtd.daemonization() but now, once is
# closed, there should not any other outstanding open file
assert numFiles == 0
def testLoggerTraceBackTrueOnNoException():
logger = Logger("test file logger", level=logging.DEBUG)
logger.debug("my msg", traceBack=True)
to be run from the project root directory:
python fdtcplib/common/test/logtest.py
"""
from fdtcplib.common.actions import SendingClientAction
from fdtcplib.utils.Logger import Logger
transferFiles = [
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_65 / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_65_uprBpUmMbtrlF910_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_AB / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_AB_VBggLIppuOd19CPC_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_E3 / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_E3_nxS6pVoM1of60fNW_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_0B / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_0B_QIG6aG9hpal8XTJD_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_1B / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_1B_but3hjz0eT7bWHrr_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_39 / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_39_mcBzPcNt1pJcaAkc_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_81 / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_81_QueqvduaTBMjk3pu_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_CB / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_CB_YbQNLdVZnUIEukVe_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_1C / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_1C_3iyt9ymMVRpAVEWz_3962",
"/mnt/hadoop/user/uscms01/pnfs/unl.edu/data4/cms/store/phedex_monarctest/Nebraska/LoadTest07_Nebraska_62 / /mnt/hadoop/store/PhEDEx_LoadTest07/LoadTest07_Debug_US_Nebraska/US_Caltech/3962/LoadTest07_Nebraska_62_wboDVRwpaSU8jU0O_3962",
]
options = dict(port=54321, hostDest="gridftp05.ultralight.org", transferFiles=transferFiles, gridUserSrc="cmsphedex")
s = SendingClientAction("fdtcp-cithep249.ultralight.org-phedex-2011-04-08--06h:19m:21s:822724mics-epjiu", options)
# logger = Logger(name = "fdtcp", logFile = "/tmp/logfile")
logger = Logger(name="fdtcp")
uri = "some.machine.edu:333/PYRO"
logger.debug("Calling '%s' request: %s\n%s ..." % (uri, s.__class__.__name__, s))
logger.close()
logger.error("erroneous message")