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 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 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 testConfigFDTDCorrectValues():
c = \
"""
[general]
port = 9000
fdtSendingClientCommand = cmd1
fdtReceivingServerCommand = cmd2
portAuthService = 9001
daemonize = False
pidFile = /tmp/something.log
portRangeFDTServer = 54321,54400
transferSeparateLogFile = True
debug = INFO
fdtSendingClientKillTimeout = 10
fdtServerLogOutputTimeout = 11
fdtReceivingServerKillTimeout = 12
authServiceLogOutputTimeout = 13
fdtServerLogOutputToWaitFor = somelog
authServiceLogOutputToWaitFor = someotherlog
# strings - both with " and without " shall work identically
authServiceCommand = "authcommand"
killCommandSudo = "kill command sudo"
killCommand = "kill command"
"""
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
f = getTempFile(c)
inputOption = "-d DEBUG -p 6700 --config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
assert conf.get("debug") == logging.DEBUG
assert conf.get("port") == 6700
assert conf.get("fdtSendingClientCommand") == "cmd1"
assert conf.get("fdtReceivingServerCommand") == "cmd2"
assert conf.get("nonsenceoption") == None
# processing happens on this stage
assert conf.get("portRangeFDTServer") == "54321,54400"
assert conf.get("transferSeparateLogFile") == True
assert conf.get("fdtSendingClientKillTimeout") == 10
assert conf.get("fdtServerLogOutputTimeout") == 11
assert conf.get("fdtReceivingServerKillTimeout") == 12
assert conf.get("authServiceLogOutputTimeout") == 13
assert conf.get("fdtServerLogOutputToWaitFor") == "somelog"
assert conf.get("authServiceLogOutputToWaitFor") == "someotherlog"
assert conf.get("authServiceCommand") == "authcommand"
assert conf.get("killCommandSudo") == "kill command sudo"
assert conf.get("killCommand") == "kill command"
assert conf.get("daemonize") == False
assert conf.get("pidFile") == "/tmp/something.log"
def testConfigFDTDCorrectValues():
c = \
"""
[general]
port = 9000
fdtSendingClientCommand = cmd1
fdtReceivingServerCommand = cmd2
portAuthService = 9001
daemonize = False
pidFile = /tmp/something.log
portRangeFDTServer = 54321,54400
transferSeparateLogFile = True
debug = INFO
fdtSendingClientKillTimeout = 10
fdtServerLogOutputTimeout = 11
fdtReceivingServerKillTimeout = 12
authServiceLogOutputTimeout = 13
fdtServerLogOutputToWaitFor = somelog
authServiceLogOutputToWaitFor = someotherlog
# strings - both with " and without " shall work identically
authServiceCommand = "authcommand"
killCommandSudo = "kill command sudo"
killCommand = "kill command"
"""
f = getTempFile(c)
inputOption = "--config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
f = getTempFile(c)
inputOption = "-d DEBUG -p 6700 --config=%s" % f.name
conf = ConfigFDTD(inputOption.split())
conf.sanitize()
assert conf.get("debug") == logging.DEBUG
assert conf.get("port") == 6700
assert conf.get("fdtSendingClientCommand") == "cmd1"
assert conf.get("fdtReceivingServerCommand") == "cmd2"
assert conf.get("nonsenceoption") == None
# processing happens on this stage
assert conf.get("portRangeFDTServer") == "54321,54400"
assert conf.get("transferSeparateLogFile") == True
assert conf.get("fdtSendingClientKillTimeout") == 10
assert conf.get("fdtServerLogOutputTimeout") == 11
assert conf.get("fdtReceivingServerKillTimeout") == 12
assert conf.get("authServiceLogOutputTimeout") == 13
assert conf.get("fdtServerLogOutputToWaitFor") == "somelog"
assert conf.get("authServiceLogOutputToWaitFor") == "someotherlog"
assert conf.get("authServiceCommand") == "authcommand"
assert conf.get("killCommandSudo") == "kill command sudo"
assert conf.get("killCommand") == "kill command"
assert conf.get("daemonize") == False
assert conf.get("pidFile") == "/tmp/something.log"
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 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 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