def hgfs_setup_and_teardown():
"""
build up and tear down hg repos to test with.
"""
initial_child_processes = psutil.Process().children()
source_dir = Path(__file__).resolve().parent.joinpath("files")
tempdir = tempfile.TemporaryDirectory()
tempsubdir = tempdir.name / Path("subdir/")
tempsubdir.mkdir()
tempdirPath = Path(tempdir.name)
for file in source_dir.iterdir():
to_file = tempdirPath / file.name
to_file2 = tempsubdir / file.name
shutil.copy(file.as_posix(), to_file.as_posix())
shutil.copy(file.as_posix(), to_file2.as_posix())
client = hglib.init(bytes(tempdirPath.as_posix(), encoding="utf8"))
client.close()
with hglib.open(bytes(tempdirPath.as_posix(), encoding="utf8")) as repo:
repo.add(bytes(tempdirPath.as_posix(), encoding="utf8"))
repo.commit(b"init commit", user="******")
repo.tag(b"test", user="******")
repo.branch(b"test")
repo.commit(b"create test branch", user="******")
repo.bookmark(b"bookmark_test")
try:
yield tempdirPath.as_uri()
finally:
tempdir.cleanup()
for child in psutil.Process().children():
if child not in initial_child_processes:
terminate_process(process=child, kill_children=True)
def req_server_channel(salt_master, req_channel_crypt):
req_server_channel_process = ReqServerChannelProcess(
salt_master.config.copy(), req_channel_crypt)
try:
with req_server_channel_process:
yield
finally:
terminate_process(pid=req_server_channel_process.pid,
kill_children=True,
slow_stop=False)
def test_event_return(self):
evt = None
try:
evt = salt.utils.event.EventReturn(salt.config.DEFAULT_MASTER_OPTS.copy())
evt.start()
except TypeError as exc:
if "object" in str(exc):
self.fail("'{}' TypeError should have not been raised".format(exc))
finally:
if evt is not None:
terminate_process(evt.pid, kill_children=True)
def close(self):
if self._closing:
return
self._closing = True
if self.process_manager is None:
return
self.process_manager.terminate()
self.pub_server_channel.close()
# Really terminate any process still left behind
for pid in self.process_manager._process_map:
terminate_process(pid=pid, kill_children=True, slow_stop=False)
self.process_manager = None
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 close(self):
if self._closing:
return
self._closing = True
if self.process_manager is None:
return
self.process_manager.stop_restarting()
self.process_manager.send_signal_to_processes(signal.SIGTERM)
self.pub_server_channel.pub_close()
self.process_manager.kill_children()
# Really terminate any process still left behind
for pid in self.process_manager._process_map:
terminate_process(pid=pid, kill_children=True, slow_stop=False)
self.process_manager = None
def terminate(self):
"""
Terminate the started daemon
"""
if self._terminal is None:
return self._terminal_result
atexit.unregister(self.terminate)
log.info("Stopping %s", self)
# Collect any child processes information before terminating the process
try:
for child in psutil.Process(
self._terminal.pid).children(recursive=True):
if child not in self._children:
self._children.append(child)
except psutil.NoSuchProcess:
# The terminal process is gone
pass
# poll the terminal before trying to terminate it, running or not, so that
# the right returncode is set on the popen object
self._terminal.poll()
# Lets log and kill any child processes left behind
terminate_process(
pid=self._terminal.pid,
kill_children=True,
children=self._children,
slow_stop=self.slow_stop,
)
stdout, stderr = self._terminal.communicate()
try:
log_message = "Terminated {}.".format(self)
if stdout or stderr:
log_message += " Process Output:"
if stdout:
log_message += "\n>>>>> STDOUT >>>>>\n{}\n<<<<< STDOUT <<<<<".format(
stdout.strip())
if stderr:
log_message += "\n>>>>> STDERR >>>>>\n{}\n<<<<< STDERR <<<<<".format(
stderr.strip())
log_message += "\n"
log.info(log_message)
self._terminal_result = ProcessResult(self._terminal.returncode,
stdout,
stderr,
cmdline=self._terminal.args)
return self._terminal_result
finally:
self._terminal = None
self._terminal_timeout = None
self._children = []
def schedule(tmp_path):
try:
subprocess_list = SubprocessList()
root_dir = tmp_path / "schedule-unit-tests"
sock_dir = str(root_dir / "test-socks")
default_config = salt.config.minion_config(None)
default_config["conf_dir"] = str(root_dir)
default_config["root_dir"] = str(root_dir)
default_config["sock_dir"] = sock_dir
default_config["pki_dir"] = str(root_dir / "pki")
default_config["cachedir"] = str(root_dir / "cache")
with patch("salt.utils.schedule.clean_proc_dir", MagicMock(return_value=None)):
functions = {"test.ping": ping}
_schedule = salt.utils.schedule.Schedule(
copy.deepcopy(default_config),
functions,
returners={},
new_instance=True,
)
_schedule.opts["loop_interval"] = 1
_schedule._subprocess_list = subprocess_list
yield _schedule
finally:
processes = subprocess_list.processes
_schedule.reset()
del _schedule
for proc in processes:
if proc.is_alive():
terminate_process(proc.pid, kill_children=True, slow_stop=True)
subprocess_list.cleanup()
processes = subprocess_list.processes
if processes:
for proc in processes:
if proc.is_alive():
terminate_process(proc.pid, kill_children=True, slow_stop=False)
subprocess_list.cleanup()
processes = subprocess_list.processes
if processes:
log.warning("Processes left running: %s", processes)
del default_config
del subprocess_list
def tearDown(self):
subprocess_list = self.subprocess_list
processes = subprocess_list.processes
self.schedule.reset()
del self.schedule
for proc in processes:
if proc.is_alive():
terminate_process(proc.pid, kill_children=True, slow_stop=True)
subprocess_list.cleanup()
processes = subprocess_list.processes
if processes:
for proc in processes:
if proc.is_alive():
terminate_process(proc.pid,
kill_children=True,
slow_stop=False)
subprocess_list.cleanup()
processes = subprocess_list.processes
if processes:
log.warning("Processes left running: %s", processes)
def run_script(
self,
script,
arg_str,
catch_stderr=False,
with_retcode=False,
catch_timeout=False,
# FIXME A timeout of zero or disabling timeouts may not return results!
timeout=15,
raw=False,
popen_kwargs=None,
log_output=None,
config_dir=None,
**kwargs
):
"""
Execute a script with the given argument string
The ``log_output`` argument is ternary, it can be True, False, or None.
If the value is boolean, then it forces the results to either be logged
or not logged. If it is None, then the return code of the subprocess
determines whether or not to log results.
"""
import salt.utils.platform
script_path = self.get_script_path(script)
if not os.path.isfile(script_path):
return False
popen_kwargs = popen_kwargs or {}
python_path_env_var = os.environ.get("PYTHONPATH") or None
if python_path_env_var is None:
python_path_entries = [RUNTIME_VARS.CODE_DIR]
else:
python_path_entries = python_path_env_var.split(os.pathsep)
if RUNTIME_VARS.CODE_DIR in python_path_entries:
python_path_entries.remove(RUNTIME_VARS.CODE_DIR)
python_path_entries.insert(0, RUNTIME_VARS.CODE_DIR)
python_path_entries.extend(sys.path[0:])
if "env" not in popen_kwargs:
popen_kwargs["env"] = os.environ.copy()
popen_kwargs["env"]["PYTHONPATH"] = os.pathsep.join(python_path_entries)
if "cwd" not in popen_kwargs:
popen_kwargs["cwd"] = RUNTIME_VARS.TMP
if salt.utils.platform.is_windows():
cmd = "python "
else:
cmd = "python{}.{} ".format(*sys.version_info)
cmd += "{} --config-dir={} {} ".format(
script_path, config_dir or RUNTIME_VARS.TMP_CONF_DIR, arg_str
)
if kwargs:
# late import
import salt.utils.json
for key, value in kwargs.items():
cmd += "'{}={} '".format(key, salt.utils.json.dumps(value))
tmp_file = tempfile.SpooledTemporaryFile()
popen_kwargs = dict(
{"shell": True, "stdout": tmp_file, "universal_newlines": True},
**popen_kwargs
)
if catch_stderr is True:
popen_kwargs["stderr"] = subprocess.PIPE
if salt.utils.platform.is_windows():
# Windows does not support closing FDs
close_fds = False
elif salt.utils.platform.is_freebsd() and sys.version_info < (3, 9):
# Closing FDs in FreeBSD before Py3.9 can be slow
# https://bugs.python.org/issue38061
close_fds = False
else:
close_fds = True
popen_kwargs["close_fds"] = close_fds
if not salt.utils.platform.is_windows():
def detach_from_parent_group():
# detach from parent group (no more inherited signals!)
os.setpgrp()
popen_kwargs["preexec_fn"] = detach_from_parent_group
def format_return(retcode, stdout, stderr=None, timed_out=False):
"""
DRY helper to log script result if it failed, and then return the
desired output based on whether or not stderr was desired, and
wither or not a retcode was desired.
"""
log_func = log.debug
if timed_out:
log.error(
"run_script timed out after %d seconds (process killed)", timeout
)
log_func = log.error
if log_output is True or timed_out or (log_output is None and retcode != 0):
log_func(
"run_script results for: %s %s\n"
"return code: %s\n"
"stdout:\n"
"%s\n\n"
"stderr:\n"
"%s",
script,
arg_str,
retcode,
stdout,
stderr,
)
stdout = stdout or ""
stderr = stderr or ""
if not raw:
stdout = stdout.splitlines()
stderr = stderr.splitlines()
ret = [stdout]
if catch_stderr:
ret.append(stderr)
if with_retcode:
ret.append(retcode)
if catch_timeout:
ret.append(timed_out)
return ret[0] if len(ret) == 1 else tuple(ret)
log.debug("Running Popen(%r, %r)", cmd, popen_kwargs)
process = subprocess.Popen(cmd, **popen_kwargs)
if timeout is not None:
stop_at = datetime.now() + timedelta(seconds=timeout)
while True:
process.poll()
time.sleep(0.1)
if datetime.now() <= stop_at:
# We haven't reached the timeout yet
if process.returncode is not None:
break
else:
terminate_process(process.pid, kill_children=True)
return format_return(
process.returncode, *process.communicate(), timed_out=True
)
tmp_file.seek(0)
try:
out = tmp_file.read().decode(__salt_system_encoding__)
except (NameError, UnicodeDecodeError):
# Let's cross our fingers and hope for the best
out = tmp_file.read().decode("utf-8")
if catch_stderr:
_, err = process.communicate()
# Force closing stderr/stdout to release file descriptors
if process.stdout is not None:
process.stdout.close()
if process.stderr is not None:
process.stderr.close()
# pylint: disable=maybe-no-member
try:
return format_return(process.returncode, out, err or "")
finally:
try:
if os.path.exists(tmp_file.name):
if isinstance(tmp_file.name, str):
# tmp_file.name is an int when using SpooledTemporaryFiles
# int types cannot be used with os.remove() in Python 3
os.remove(tmp_file.name)
else:
# Clean up file handles
tmp_file.close()
process.terminate()
except OSError as err:
# process already terminated
pass
# pylint: enable=maybe-no-member
# TODO Remove this?
process.communicate()
if process.stdout is not None:
process.stdout.close()
try:
return format_return(process.returncode, out)
finally:
try:
if os.path.exists(tmp_file.name):
if isinstance(tmp_file.name, str):
# tmp_file.name is an int when using SpooledTemporaryFiles
# int types cannot be used with os.remove() in Python 3
os.remove(tmp_file.name)
else:
# Clean up file handles
tmp_file.close()
process.terminate()
except OSError as err:
# process already terminated
pass
def start_daemon(
daemon_name=None,
daemon_id=None,
daemon_log_prefix=None,
daemon_cli_script_name=None,
daemon_config=None,
daemon_config_dir=None,
daemon_class=None,
bin_dir_path=None,
fail_hard=False,
start_timeout=10,
slow_stop=False,
environ=None,
cwd=None,
event_listener_config_dir=None,
):
"""
Returns a running salt daemon
"""
# Old config name
daemon_config["pytest_port"] = daemon_config["runtests_conn_check_port"]
# New config name
daemon_config["pytest_engine_port"] = daemon_config[
"runtests_conn_check_port"]
request = None
if fail_hard:
fail_method = RuntimeError
else:
fail_method = RuntimeWarning
log.info("[%s] Starting pytest %s(%s)", daemon_name, daemon_log_prefix,
daemon_id)
attempts = 0
process = None
get_script_path(RUNTIME_VARS.TMP_SCRIPT_DIR, daemon_cli_script_name)
while attempts <= 3: # pylint: disable=too-many-nested-blocks
attempts += 1
try:
process = daemon_class(
request=request,
config=daemon_config,
config_dir=daemon_config_dir,
bin_dir_path=bin_dir_path,
log_prefix=daemon_log_prefix,
cli_script_name=daemon_cli_script_name,
slow_stop=slow_stop,
environ=environ,
cwd=cwd,
event_listener_config_dir=event_listener_config_dir,
)
except TypeError:
process = daemon_class(
request=request,
config=daemon_config,
config_dir=daemon_config_dir,
bin_dir_path=bin_dir_path,
log_prefix=daemon_log_prefix,
cli_script_name=daemon_cli_script_name,
slow_stop=slow_stop,
environ=environ,
cwd=cwd,
)
process.start()
if process.is_alive():
try:
connectable = process.wait_until_running(timeout=start_timeout)
if connectable is False:
connectable = process.wait_until_running(
timeout=start_timeout / 2)
if connectable is False:
process.terminate()
if attempts >= 3:
fail_method(
"The pytest {}({}) has failed to confirm running status "
"after {} attempts".format(
daemon_name, daemon_id, attempts))
continue
except Exception as exc: # pylint: disable=broad-except
log.exception("[%s] %s", daemon_log_prefix, exc, exc_info=True)
terminate_process(process.pid,
kill_children=True,
slow_stop=slow_stop)
if attempts >= 3:
raise fail_method(str(exc))
continue
log.info(
"[%s] The pytest %s(%s) is running and accepting commands "
"after %d attempts",
daemon_log_prefix,
daemon_name,
daemon_id,
attempts,
)
break
else:
terminate_process(process.pid,
kill_children=True,
slow_stop=slow_stop)
continue
else:
if process is not None:
terminate_process(process.pid,
kill_children=True,
slow_stop=slow_stop)
raise fail_method(
"The pytest {}({}) has failed to start after {} attempts".format(
daemon_name, daemon_id, attempts - 1))
return process
def run_script(
self,
script,
arg_str,
catch_stderr=False,
with_retcode=False,
catch_timeout=False,
# FIXME A timeout of zero or disabling timeouts may not return results!
timeout=15,
raw=False,
popen_kwargs=None,
log_output=None,
config_dir=None,
**kwargs):
"""
Execute a script with the given argument string
The ``log_output`` argument is ternary, it can be True, False, or None.
If the value is boolean, then it forces the results to either be logged
or not logged. If it is None, then the return code of the subprocess
determines whether or not to log results.
"""
import salt.utils.platform
script_path = self.get_script_path(script)
if not os.path.isfile(script_path):
return False
popen_kwargs = popen_kwargs or {}
if salt.utils.platform.is_windows():
cmd = "python "
if "cwd" not in popen_kwargs:
popen_kwargs["cwd"] = os.getcwd()
if "env" not in popen_kwargs:
popen_kwargs["env"] = os.environ.copy()
popen_kwargs["env"]["PYTHONPATH"] = RUNTIME_VARS.CODE_DIR
else:
cmd = "PYTHONPATH="
python_path = os.environ.get("PYTHONPATH", None)
if python_path is not None:
cmd += "{}:".format(python_path)
if sys.version_info[0] < 3:
cmd += "{} ".format(":".join(sys.path[1:]))
else:
cmd += "{} ".format(":".join(sys.path[0:]))
cmd += "python{}.{} ".format(*sys.version_info)
cmd += "{} --config-dir={} {} ".format(
script_path, config_dir or RUNTIME_VARS.TMP_CONF_DIR, arg_str)
if kwargs:
# late import
import salt.utils.json
for key, value in kwargs.items():
cmd += "'{}={} '".format(key, salt.utils.json.dumps(value))
tmp_file = tempfile.SpooledTemporaryFile()
popen_kwargs = dict(
{
"shell": True,
"stdout": tmp_file,
"universal_newlines": True
}, **popen_kwargs)
if catch_stderr is True:
popen_kwargs["stderr"] = subprocess.PIPE
if not sys.platform.lower().startswith("win"):
popen_kwargs["close_fds"] = True
def detach_from_parent_group():
# detach from parent group (no more inherited signals!)
os.setpgrp()
popen_kwargs["preexec_fn"] = detach_from_parent_group
def format_return(retcode, stdout, stderr=None, timed_out=False):
"""
DRY helper to log script result if it failed, and then return the
desired output based on whether or not stderr was desired, and
wither or not a retcode was desired.
"""
log_func = log.debug
if timed_out:
log.error(
"run_script timed out after %d seconds (process killed)",
timeout)
log_func = log.error
if log_output is True or timed_out or (log_output is None
and retcode != 0):
log_func(
"run_script results for: %s %s\n"
"return code: %s\n"
"stdout:\n"
"%s\n\n"
"stderr:\n"
"%s",
script,
arg_str,
retcode,
stdout,
stderr,
)
stdout = stdout or ""
stderr = stderr or ""
if not raw:
stdout = stdout.splitlines()
stderr = stderr.splitlines()
ret = [stdout]
if catch_stderr:
ret.append(stderr)
if with_retcode:
ret.append(retcode)
if catch_timeout:
ret.append(timed_out)
return ret[0] if len(ret) == 1 else tuple(ret)
log.debug("Running Popen(%r, %r)", cmd, popen_kwargs)
process = subprocess.Popen(cmd, **popen_kwargs)
if timeout is not None:
stop_at = datetime.now() + timedelta(seconds=timeout)
term_sent = False
while True:
process.poll()
time.sleep(0.1)
if datetime.now() <= stop_at:
# We haven't reached the timeout yet
if process.returncode is not None:
break
else:
terminate_process(process.pid, kill_children=True)
return format_return(process.returncode,
*process.communicate(),
timed_out=True)
tmp_file.seek(0)
try:
out = tmp_file.read().decode(__salt_system_encoding__)
except (NameError, UnicodeDecodeError):
# Let's cross our fingers and hope for the best
out = tmp_file.read().decode("utf-8")
if catch_stderr:
if sys.version_info < (2, 7):
# On python 2.6, the subprocess'es communicate() method uses
# select which, is limited by the OS to 1024 file descriptors
# We need more available descriptors to run the tests which
# need the stderr output.
# So instead of .communicate() we wait for the process to
# finish, but, as the python docs state "This will deadlock
# when using stdout=PIPE and/or stderr=PIPE and the child
# process generates enough output to a pipe such that it
# blocks waiting for the OS pipe buffer to accept more data.
# Use communicate() to avoid that." <- a catch, catch situation
#
# Use this work around were it's needed only, python 2.6
process.wait()
err = process.stderr.read()
else:
_, err = process.communicate()
# Force closing stderr/stdout to release file descriptors
if process.stdout is not None:
process.stdout.close()
if process.stderr is not None:
process.stderr.close()
# pylint: disable=maybe-no-member
try:
return format_return(process.returncode, out, err or "")
finally:
try:
if os.path.exists(tmp_file.name):
if isinstance(tmp_file.name, str):
# tmp_file.name is an int when using SpooledTemporaryFiles
# int types cannot be used with os.remove() in Python 3
os.remove(tmp_file.name)
else:
# Clean up file handles
tmp_file.close()
process.terminate()
except OSError as err:
# process already terminated
pass
# pylint: enable=maybe-no-member
# TODO Remove this?
process.communicate()
if process.stdout is not None:
process.stdout.close()
try:
return format_return(process.returncode, out)
finally:
try:
if os.path.exists(tmp_file.name):
if isinstance(tmp_file.name, str):
# tmp_file.name is an int when using SpooledTemporaryFiles
# int types cannot be used with os.remove() in Python 3
os.remove(tmp_file.name)
else:
# Clean up file handles
tmp_file.close()
process.terminate()
except OSError as err:
# process already terminated
pass
def test_interrupt_on_long_running_job(salt_cli, salt_master, salt_minion):
"""
Ensure that a call to ``salt`` that is taking too long, when a user
hits CTRL-C, that the JID is printed to the console.
Refer to https://github.com/saltstack/salt/issues/60963 for more details
"""
# Ensure test.sleep is working as supposed
start = time.time()
ret = salt_cli.run("test.sleep", "1", minion_tgt=salt_minion.id)
stop = time.time()
assert ret.exitcode == 0
assert ret.json is True
assert stop - start > 1, "The command should have taken more than 1 second"
# Now the real test
terminal_stdout = tempfile.SpooledTemporaryFile(512000, buffering=0)
terminal_stderr = tempfile.SpooledTemporaryFile(512000, buffering=0)
cmdline = [
sys.executable,
salt_cli.get_script_path(),
"--config-dir={}".format(salt_master.config_dir),
salt_minion.id,
"test.sleep",
"30",
]
# If this test starts failing, commend the following block of code
proc = subprocess.Popen(
cmdline,
shell=False,
stdout=terminal_stdout,
stderr=terminal_stderr,
universal_newlines=True,
)
# and uncomment the following block of code
# with default_signals(signal.SIGINT, signal.SIGTERM):
# proc = subprocess.Popen(
# cmdline,
# shell=False,
# stdout=terminal_stdout,
# stderr=terminal_stderr,
# universal_newlines=True,
# )
# What this means is that something in salt or the test suite is setting
# the SIGTERM and SIGINT signals to SIG_IGN, ignore.
# Check which line of code is doing that and fix it
start = time.time()
try:
# Make sure it actually starts
proc.wait(1)
except subprocess.TimeoutExpired:
pass
else:
terminate_process(proc.pid, kill_children=True)
pytest.fail("The test process failed to start")
time.sleep(2)
# Send CTRL-C to the process
os.kill(proc.pid, signal.SIGINT)
with proc:
# Wait for the process to terminate, to avoid zombies.
# Shouldn't really take the 30 seconds
proc.wait(30)
# poll the terminal so the right returncode is set on the popen object
proc.poll()
# This call shouldn't really be necessary
proc.communicate()
stop = time.time()
terminal_stdout.flush()
terminal_stdout.seek(0)
if sys.version_info < (3, 6): # pragma: no cover
stdout = proc._translate_newlines(
terminal_stdout.read(), __salt_system_encoding__
)
else:
stdout = proc._translate_newlines(
terminal_stdout.read(), __salt_system_encoding__, sys.stdout.errors
)
terminal_stdout.close()
terminal_stderr.flush()
terminal_stderr.seek(0)
if sys.version_info < (3, 6): # pragma: no cover
stderr = proc._translate_newlines(
terminal_stderr.read(), __salt_system_encoding__
)
else:
stderr = proc._translate_newlines(
terminal_stderr.read(), __salt_system_encoding__, sys.stderr.errors
)
terminal_stderr.close()
ret = ProcessResult(proc.returncode, stdout, stderr, cmdline=proc.args)
log.debug(ret)
# If the minion ID is on stdout it means that the command finished and wasn't terminated
assert (
salt_minion.id not in ret.stdout
), "The command wasn't actually terminated. Took {} seconds.".format(
round(stop - start, 2)
)
# Make sure the ctrl+c exited gracefully
assert "Exiting gracefully on Ctrl-c" in ret.stderr
assert "Exception ignored in" not in ret.stderr
assert "This job's jid is" in ret.stderr
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)
