From 7c2bf134b1afc23687645bc97388c5b7c6b9bb4f Mon Sep 17 00:00:00 2001 From: Clay Gerrard Date: Wed, 30 Mar 2011 15:04:15 -0500 Subject: [PATCH] fixed lockups and lost messages in swift-init and capture_stdio --- swift/common/manager.py | 11 ++++++++--- swift/common/utils.py | 16 +++++++--------- test/unit/common/test_manager.py | 19 +++++++++++++++++-- test/unit/common/test_utils.py | 30 +++++++++++++++++++----------- 4 files changed, 51 insertions(+), 25 deletions(-) diff --git a/swift/common/manager.py b/swift/common/manager.py index b5b126a822..902d188054 100644 --- a/swift/common/manager.py +++ b/swift/common/manager.py @@ -41,6 +41,7 @@ GRACEFUL_SHUTDOWN_SERVERS = MAIN_SERVERS + ['auth-server'] START_ONCE_SERVERS = REST_SERVERS KILL_WAIT = 15 # seconds to wait for servers to die +WARNING_WAIT = 3 # seconds to wait after message that may just be a warning MAX_DESCRIPTORS = 32768 MAX_MEMORY = (1024 * 1024 * 1024) * 2 # 2 GB @@ -530,9 +531,13 @@ class Server(): output = proc.stdout.read() if output: print output - proc.communicate() - if proc.returncode: - status += 1 + start = time.time() + # wait for process to die (output may just be a warning) + while time.time() - start < WARNING_WAIT: + time.sleep(0.1) + if proc.poll() is not None: + status += proc.returncode + break return status def interact(self, **kwargs): diff --git a/swift/common/utils.py b/swift/common/utils.py index 8d31b69512..2c8bd1d622 100644 --- a/swift/common/utils.py +++ b/swift/common/utils.py @@ -470,19 +470,17 @@ def capture_stdio(logger, **kwargs): logger.critical(_('UNCAUGHT EXCEPTION'), exc_info=exc_info) # collect stdio file desc not in use for logging - stdio_fds = [0, 1, 2] - for _junk, handler in getattr(get_logger, - 'console_handler4logger', {}).items(): - try: - stdio_fds.remove(handler.stream.fileno()) - except ValueError: - pass # fd not in list + stdio_files = [sys.stdin, sys.stdout, sys.stderr] + console_fds = [h.stream.fileno() for _junk, h in getattr( + get_logger, 'console_handler4logger', {}).items()] + stdio_files = [f for f in stdio_files if f.fileno() not in console_fds] with open(os.devnull, 'r+b') as nullfile: # close stdio (excludes fds open for logging) - for desc in stdio_fds: + for f in stdio_files: + f.flush() try: - os.dup2(nullfile.fileno(), desc) + os.dup2(nullfile.fileno(), f.fileno()) except OSError: pass diff --git a/test/unit/common/test_manager.py b/test/unit/common/test_manager.py index 47a50c6a24..df07a760bf 100644 --- a/test/unit/common/test_manager.py +++ b/test/unit/common/test_manager.py @@ -910,8 +910,9 @@ class TestServer(unittest.TestCase): print >>self._stdout, 'mock process failed to start' self.close_stdout() - def communicate(self): + def poll(self): self.returncode = self._returncode + return self.returncode or None def run(self): print >>self._stdout, 'mock process started' @@ -922,9 +923,21 @@ class TestServer(unittest.TestCase): print >>self._stdout, 'mock process finished' self.finished = True + class MockTime(): + + def time(self): + return time() + + def sleep(self, *args, **kwargs): + pass + with temptree([]) as t: old_stdout = sys.stdout + old_wait = manager.WARNING_WAIT + old_time = manager.time try: + manager.WARNING_WAIT = 0.01 + manager.time = MockTime() with open(os.path.join(t, 'output'), 'w+') as f: # acctually capture the read stdout (for prints) sys.stdout = f @@ -933,7 +946,7 @@ class TestServer(unittest.TestCase): server.procs = [proc] status = server.wait() self.assertEquals(status, 0) - # wait should return as soon as stdout is closed + # wait should return before process exits self.assert_(proc.isAlive()) self.assertFalse(proc.finished) self.assert_(proc.finished) # make sure it did finish... @@ -965,6 +978,8 @@ class TestServer(unittest.TestCase): proc.join() finally: sys.stdout = old_stdout + manager.WARNING_WAIT = old_wait + manager.time = old_time def test_interact(self): class MockProcess(): diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index 79ff1068e7..323f60672e 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -29,7 +29,7 @@ from getpass import getuser from shutil import rmtree from StringIO import StringIO from functools import partial -from tempfile import NamedTemporaryFile +from tempfile import TemporaryFile, NamedTemporaryFile from eventlet import sleep @@ -77,7 +77,13 @@ class MockOs(): class MockSys(): - __stderr__ = sys.__stderr__ + def __init__(self): + self.stdin = TemporaryFile('w') + self.stdout = TemporaryFile('r') + self.stderr = TemporaryFile('r') + self.__stderr__ = self.stderr + self.stdio_fds = [self.stdin.fileno(), self.stdout.fileno(), + self.stderr.fileno()] def reset_loggers(): @@ -541,9 +547,9 @@ log_name = yarr''' # basic test utils.capture_stdio(logger) self.assert_(utils.sys.excepthook is not None) - self.assertEquals(utils.os.closed_fds, [0, 1, 2]) - self.assert_(utils.sys.stdout is not None) - self.assert_(utils.sys.stderr is not None) + self.assertEquals(utils.os.closed_fds, utils.sys.stdio_fds) + self.assert_(isinstance(utils.sys.stdout, utils.LoggerFileObject)) + self.assert_(isinstance(utils.sys.stderr, utils.LoggerFileObject)) # reset; test same args, but exc when trying to close stdio utils.os = MockOs(raise_funcs=('dup2',)) @@ -553,25 +559,27 @@ log_name = yarr''' utils.capture_stdio(logger) self.assert_(utils.sys.excepthook is not None) self.assertEquals(utils.os.closed_fds, []) - self.assert_(utils.sys.stdout is not None) - self.assert_(utils.sys.stderr is not None) + self.assert_(isinstance(utils.sys.stdout, utils.LoggerFileObject)) + self.assert_(isinstance(utils.sys.stderr, utils.LoggerFileObject)) # reset; test some other args - logger = utils.get_logger(None, log_to_console=True) utils.os = MockOs() utils.sys = MockSys() + logger = utils.get_logger(None, log_to_console=True) # test console log utils.capture_stdio(logger, capture_stdout=False, capture_stderr=False) self.assert_(utils.sys.excepthook is not None) # when logging to console, stderr remains open - self.assertEquals(utils.os.closed_fds, [0, 1]) + self.assertEquals(utils.os.closed_fds, utils.sys.stdio_fds[:2]) reset_loggers() # stdio not captured - self.assertFalse(hasattr(utils.sys, 'stdout')) - self.assertFalse(hasattr(utils.sys, 'stderr')) + self.assertFalse(isinstance(utils.sys.stdout, + utils.LoggerFileObject)) + self.assertFalse(isinstance(utils.sys.stderr, + utils.LoggerFileObject)) reset_loggers() finally: utils.sys = _orig_sys