def test_master_startup(self): proc = NonBlockingPopen( [ sys.executable, self.get_script_path("master"), "-c", RUNTIME_VARS.TMP_CONF_DIR, "-l", "info", ], stdout=subprocess.PIPE, stderr=subprocess.STDOUT, ) out = b"" err = b"" # Testing this should never be longer than 1 minute max_time = time.time() + 60 try: while True: if time.time() > max_time: assert False, "Max timeout ocurred" time.sleep(0.5) _out = proc.recv() _err = proc.recv_err() if _out: out += _out if _err: err += _err if b"DeprecationWarning: object() takes no parameters" in out: self.fail( "'DeprecationWarning: object() takes no parameters' was seen in" " output" ) if b"TypeError: object() takes no parameters" in out: self.fail( "'TypeError: object() takes no parameters' was seen in output" ) if b"Setting up the master communication server" in out: # We got past the place we need, stop the process break if out is None and err is None: break if proc.poll() is not None: break finally: terminate_process(proc.pid, kill_children=True)
def test_master_startup(self): proc = NonBlockingPopen( [ self.get_script_path('master'), '-c', self.config_dir, '-l', 'info' ], stdout=subprocess.PIPE, stderr=subprocess.STDOUT ) out = six.b('') err = six.b('') # Testing this should never be longer than 1 minute max_time = time.time() + 60 try: while True: if time.time() > max_time: assert False, 'Max timeout ocurred' time.sleep(0.5) _out = proc.recv() _err = proc.recv_err() if _out: out += _out if _err: err += _err if six.b('DeprecationWarning: object() takes no parameters') in out: self.fail('\'DeprecationWarning: object() takes no parameters\' was seen in output') if six.b('TypeError: object() takes no parameters') in out: self.fail('\'TypeError: object() takes no parameters\' was seen in output') if six.b('Setting up the master communication server') in out: # We got past the place we need, stop the process break if out is None and err is None: break if proc.poll() is not None: break finally: terminate_process(proc.pid, kill_children=True)
def test_deferred_write_on_atexit(tmp_path): # Python will .flush() and .close() all logging handlers at interpreter shutdown. # This should be enough to flush our deferred messages. pyscript = dedent(r""" import sys import time import logging CODE_DIR = {!r} if CODE_DIR in sys.path: sys.path.remove(CODE_DIR) sys.path.insert(0, CODE_DIR) from salt._logging.handlers import DeferredStreamHandler # Reset any logging handlers we might have already logging.root.handlers[:] = [] handler = DeferredStreamHandler(sys.stderr) handler.setLevel(logging.DEBUG) logging.root.addHandler(handler) log = logging.getLogger(__name__) sys.stdout.write('STARTED\n') sys.stdout.flush() log.debug('Foo') sys.exit(0) """.format(RUNTIME_VARS.CODE_DIR)) script_path = tmp_path / "atexit_deferred_logging_test.py" script_path.write_text(pyscript, encoding="utf-8") proc = NonBlockingPopen( [sys.executable, str(script_path)], stdout=subprocess.PIPE, stderr=subprocess.PIPE, ) out = b"" err = b"" # This test should never take more than 5 seconds execution_time = 5 max_time = time.time() + execution_time try: # Just loop consuming output while True: if time.time() > max_time: pytest.fail("Script didn't exit after {} second".format( execution_time)) time.sleep(0.125) _out = proc.recv() _err = proc.recv_err() if _out: out += _out if _err: err += _err if _out is None and _err is None: # The script exited break if proc.poll() is not None: # The script exited break finally: terminate_process(proc.pid, kill_children=True) if b"Foo" not in err: pytest.fail("'Foo' should be in stderr and it's not: {}".format(err))
def test_deferred_write_on_sigint(tmp_path): pyscript = dedent(r""" import sys import time import signal import logging CODE_DIR = {!r} if CODE_DIR in sys.path: sys.path.remove(CODE_DIR) sys.path.insert(0, CODE_DIR) from salt._logging.handlers import DeferredStreamHandler # Reset any logging handlers we might have already logging.root.handlers[:] = [] handler = DeferredStreamHandler(sys.stderr) handler.setLevel(logging.DEBUG) logging.root.addHandler(handler) if signal.getsignal(signal.SIGINT) != signal.default_int_handler: # Looking at you Debian based distros :/ signal.signal(signal.SIGINT, signal.default_int_handler) log = logging.getLogger(__name__) start_printed = False while True: try: log.debug('Foo') if start_printed is False: sys.stdout.write('STARTED\n') sys.stdout.write('SIGINT HANDLER: {{!r}}\n'.format(signal.getsignal(signal.SIGINT))) sys.stdout.flush() start_printed = True time.sleep(0.125) except (KeyboardInterrupt, SystemExit): log.info('KeyboardInterrupt caught') sys.stdout.write('KeyboardInterrupt caught\n') sys.stdout.flush() break log.info('EXITING') sys.stdout.write('EXITING\n') sys.stdout.flush() sys.exit(0) """.format(RUNTIME_VARS.CODE_DIR)) script_path = tmp_path / "sigint_deferred_logging_test.py" script_path.write_text(pyscript, encoding="utf-8") proc = NonBlockingPopen( [sys.executable, str(script_path)], stdout=subprocess.PIPE, stderr=subprocess.PIPE, ) out = b"" err = b"" # Test should take less than 20 seconds, way less execution_time = 10 start = time.time() max_time = time.time() + execution_time try: signalled = False log.info("Starting Loop") while True: time.sleep(0.125) _out = proc.recv() _err = proc.recv_err() if _out: out += _out if _err: err += _err if b"STARTED" in out and not signalled: # Enough time has passed proc.send_signal(signal.SIGINT) signalled = True log.debug("Sent SIGINT after: %s", time.time() - start) if signalled is False: if out: pytest.fail( "We have stdout output when there should be none: {}". format(out)) if err: pytest.fail( "We have stderr output when there should be none: {}". format(err)) if _out is None and _err is None: log.info("_out and _err are None") if b"Foo" not in err: pytest.fail( "No more output and 'Foo' should be in stderr and it's not: {}" .format(err)) break if proc.poll() is not None: log.debug("poll() is not None") if b"Foo" not in err: pytest.fail( "Process terminated and 'Foo' should be in stderr and it's not: {}" .format(err)) break if time.time() > max_time: log.debug("Reached max time") if b"Foo" not in err: pytest.fail( "'Foo' should be in stderr and it's not:\n{0}\nSTDERR:\n{0}\n{1}\n{0}\nSTDOUT:\n{0}\n{2}\n{0}" .format("-" * 80, err, out)) finally: terminate_process(proc.pid, kill_children=True) log.debug("Test took %s seconds", time.time() - start)