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 testReceivingServerAction(): c = \ """ [general] fdtSendingClientCommand = sudo -u %(sudouser)s bash wrapper_fdt.sh -P 35 -p %(port)s -c %(hostDest)s -d / -fl %(fileList)s -noupdates fdtReceivingServerCommand = sudo -u %(sudouser)s bash wrapper_fdt.sh -bs 2M -p %(port)s -noupdates """ f = getTempFile(c) inputOption = "--config=%s" % f.name conf = ConfigFDTD(inputOption.split()) a = ReceivingServerAction("some_id", dict(port=1000, gridUserDest="someuser")) a._setUp(conf, 1000) assert a.options["port"] == 1000 # this one did not get interpolated for server action, so it's not set py.test.raises(KeyError, a.options.__getitem__, "fdtSendingClientCommand") cmd = "sudo -u someuser bash wrapper_fdt.sh -bs 2M -p 1000 -noupdates" assert a.command == cmd
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 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 performTransfer(self): self.logger.info("Starting transfer %s" % self) if self.result != None: self.logger.warn("Skipping transfer %s (already failed)." % self) return # timeout is used only on TestActions (testing mutual connection) # id of the initial action (this test (TestAction)) is later used # in all subsequent actions related to this particular transfer timeout = int(self.conf.get("timeout")) testAction = TestAction(self.hostSrc, self.hostDest, timeout=timeout) self.id = testAction.id self.logger.info("Testing remote parties availability, " "transfer id: '%s' ..." % testAction.id) self.receiver.perform(testAction) self.sender.perform(testAction) # remote services are available, authenticate with both # remoteGridUserSrc - user's name at the source site # remoteGridUserDest - user's name at the destination site authStartTime = datetime.datetime.now() remoteGridUserSrc, remoteGridUserDest = self._runAuthChain() authEndTime = datetime.datetime.now() authTime = (authEndTime - authStartTime).seconds par = dict(id=self.id, authentication=authTime) self.logger.debug("Authentication lasted: %s [s]." % authTime) if self.apMon: self.logger.debug("Sending data to ApMon ...") self.apMon.sendParameters("fdtcp", None, par) # find out client IP address, server will need # it (-f <allowedIPsList>) when starting clientIP = socket.gethostbyname(self.hostSrc) self.logger.debug("Client IP address is: '%s'" % clientIP) # since the separate log file may not be closed properly once the # ReceivingServer request is send, register the request for possible # cleaning now (issue found during ticket:5#comment:24) # no exception was raised, remote process must be running, register # for clean up (remote process may however terminate normally, then # shall be removed from the container of processes at the remote # party) self.toCleanup.append(self.receiver.uri) # start receiving server first, information on its port will need # the client # destFiles - list if files at destination - just check (#36) destFiles = [f.fileDest for f in self.files] options = dict(gridUserDest=remoteGridUserDest, clientIP=clientIP, destFiles=destFiles) recvServerAction = ReceivingServerAction(self.id, options) result = self.receiver.perform(recvServerAction) serverFDTPort = result.serverPort self.logger.info("Remote FDT server: %s:%s" % (result.host, serverFDTPort)) # calling the client is synchronous action - waiting until it finishes # if the client hangs without progress - may want to kill such remote # process, thus register the remote URI into clean up local container # if something goes wrong, this remote URI later receives # CleanupAction to kill its running processes self.toCleanup.append(self.sender.uri) # start sending FDT client which initiates the transfer process options = dict(port=serverFDTPort, hostDest=self.hostDest, transferFiles=self.files, gridUserSrc=remoteGridUserSrc) sndClientAction = SendingClientAction(self.id, options) # this command will stop the execution flow, for very very long if # the transfer data is bulky - status monitoring via MonALISA # using the transfer id result = self.sender.perform(sndClientAction) self.logger.info("Transfer result: %s, logs (FDT sending " "client):\n%s" % (result, result.log)) self.result = result.status # don't put the log there for now, but in case of failure it puts the # log into result and then into report file # self.log = result.log # clean up remote processes # the server - FDT Java server is run with -S - it gets # automatically shut once the transfer is over # the client - if everything was all right (client not hanging), it # has already successfully finished (and the key of the process # has been removed from the container with the client) # yet call the cleanup at both sides explicitly self.performCleanup(waitTimeout=True)
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()