Skip to content

Commit

Permalink
Run a callback when command process starts
Browse files Browse the repository at this point in the history
When `Command.run()` spawns new process for the given command, by
calling `subprocess.Popen`, an optional callable provided by `run()`
caller would be called.

Generally, of not much use, but an async watchdog check might need to
interrupt the local process managing the test. It might be a SSH
process, or `podman exec`, but it runs in a thread started by an
`execute` plugin. Plugin calls `guest.execute(test_command, ...)`, and
`guest.execute()` wait for the command to complete. But, if the
watchdog, running in another thread, detects the guest is lost,
unresponsive, there are two options:

* mark the invocation with a "guest dead" label, and wait for the
  test process to terminate (by running out of time, or getting killed
  by network timeouts, etc.), or
* mark the invocation with a "guest dead" label, and kill the local test
  process. To do this, watchdog in thread B must have access to PID of a
  process started in thread A. The callback would allow the plugin to
  store process in the test invocation instance.
  • Loading branch information
happz committed Jan 3, 2024
1 parent 87e7d04 commit bc5122b
Show file tree
Hide file tree
Showing 6 changed files with 44 additions and 4 deletions.
6 changes: 6 additions & 0 deletions tmt/steps/execute/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
import datetime
import json
import os
import subprocess
from contextlib import suppress
from dataclasses import dataclass
from typing import TYPE_CHECKING, Any, Optional, TypeVar, cast
Expand Down Expand Up @@ -152,6 +153,11 @@ class TestInvocation:
test: 'tmt.base.Test'
guest: Guest

#: Process running the test. What binary it is depends on the guest
#: implementation and the test, it may be, for example, a shell process,
#: SSH process, or a ``podman`` process.
process: Optional[subprocess.Popen[bytes]] = None

return_code: Optional[int] = None
start_time: Optional[str] = None
end_time: Optional[str] = None
Expand Down
11 changes: 10 additions & 1 deletion tmt/steps/execute/internal.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import dataclasses
import os
import subprocess
import textwrap
from typing import Any, Optional, cast

Expand All @@ -17,7 +18,7 @@
from tmt.steps import safe_filename
from tmt.steps.execute import SCRIPTS, TEST_OUTPUT_FILENAME, TMT_REBOOT_SCRIPT, TestInvocation
from tmt.steps.provision import Guest
from tmt.utils import EnvironmentType, Path, ShellScript, Stopwatch, field
from tmt.utils import Command, EnvironmentType, Path, ShellScript, Stopwatch, field

TEST_PIDFILE_FILENAME = 'tmt-test.pid'
TEST_PIDFILE_LOCK_FILENAME = f'{TEST_PIDFILE_FILENAME}.lock'
Expand Down Expand Up @@ -346,6 +347,12 @@ def _test_output_logger(
level=level,
topic=topic)

def _save_process(
command: Command,
process: subprocess.Popen[bytes],
logger: tmt.log.Logger) -> None:
invocation.process = process

# TODO: do we want timestamps? Yes, we do, leaving that for refactoring later,
# to use some reusable decorator.
test_check_results += self.run_checks_before_test(
Expand All @@ -368,6 +375,7 @@ def _test_output_logger(
tty=test.tty,
log=_test_output_logger,
timeout=tmt.utils.duration_to_seconds(test.duration),
on_process_start=_save_process,
test_session=True,
friendly_command=str(test.test))
invocation.return_code = 0
Expand All @@ -382,6 +390,7 @@ def _test_output_logger(
elif tmt.utils.ProcessExitCodes.is_pidfile(invocation.return_code):
logger.warn('Test failed to manage its pidfile.')

invocation.process = None
invocation.end_time = self.format_timestamp(timer.end_time)
invocation.real_duration = self.format_duration(timer.duration)

Expand Down
6 changes: 6 additions & 0 deletions tmt/steps/provision/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
from tmt.steps import Action
from tmt.utils import (
Command,
OnProcessStartCallback,
Path,
SerializableContainer,
ShellScript,
Expand Down Expand Up @@ -889,6 +890,7 @@ def execute(self,
silent: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
interactive: bool = False,
on_process_start: Optional[OnProcessStartCallback] = None,
**kwargs: Any) -> tmt.utils.CommandOutput:
pass

Expand All @@ -903,6 +905,7 @@ def execute(self,
silent: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
interactive: bool = False,
on_process_start: Optional[OnProcessStartCallback] = None,
**kwargs: Any) -> tmt.utils.CommandOutput:
pass

Expand All @@ -916,6 +919,7 @@ def execute(self,
silent: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
interactive: bool = False,
on_process_start: Optional[OnProcessStartCallback] = None,
**kwargs: Any) -> tmt.utils.CommandOutput:
"""
Execute a command on the guest.
Expand Down Expand Up @@ -1288,6 +1292,7 @@ def execute(self,
silent: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
interactive: bool = False,
on_process_start: Optional[OnProcessStartCallback] = None,
**kwargs: Any) -> tmt.utils.CommandOutput:
"""
Execute a command on the guest.
Expand Down Expand Up @@ -1349,6 +1354,7 @@ def execute(self,
silent=silent,
cwd=cwd,
interactive=interactive,
on_process_start=on_process_start,
**kwargs)

def push(self,
Expand Down
4 changes: 3 additions & 1 deletion tmt/steps/provision/local.py
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@
import tmt.steps
import tmt.steps.provision
import tmt.utils
from tmt.utils import Command, Path, ShellScript
from tmt.utils import Command, OnProcessStartCallback, Path, ShellScript


@dataclasses.dataclass
Expand Down Expand Up @@ -76,6 +76,7 @@ def execute(self,
silent: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
interactive: bool = False,
on_process_start: Optional[OnProcessStartCallback] = None,
**kwargs: Any) -> tmt.utils.CommandOutput:
""" Execute command on localhost """
# Prepare the environment (plan/cli variables override)
Expand All @@ -98,6 +99,7 @@ def execute(self,
silent=silent,
cwd=cwd,
interactive=interactive,
on_process_start=on_process_start,
**kwargs)

def stop(self) -> None:
Expand Down
4 changes: 3 additions & 1 deletion tmt/steps/provision/podman.py
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@
import tmt.steps
import tmt.steps.provision
import tmt.utils
from tmt.utils import Command, Path, ShellScript, field, retry
from tmt.utils import Command, OnProcessStartCallback, Path, ShellScript, field, retry

# Timeout in seconds of waiting for a connection
CONNECTION_TIMEOUT = 60
Expand Down Expand Up @@ -298,6 +298,7 @@ def execute(self,
silent: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
interactive: bool = False,
on_process_start: Optional[OnProcessStartCallback] = None,
**kwargs: Any) -> tmt.utils.CommandOutput:
""" Execute given commands in podman via shell """
if not self.container and not self.is_dry_run:
Expand Down Expand Up @@ -342,6 +343,7 @@ def execute(self,
friendly_command=friendly_command or str(command),
silent=silent,
interactive=interactive,
on_process_start=on_process_start,
**kwargs)

def push(
Expand Down
17 changes: 16 additions & 1 deletion tmt/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -474,6 +474,13 @@ def get_output(self) -> Optional[str]:
#: A raw command line form, a list of elements.
RawCommand = list[RawCommandElement]

#: Type of a callable to be called by :py:meth:`Command.run` after starting the
#: child process.
OnProcessStartCallback = Callable[
['Command', subprocess.Popen[bytes], tmt.log.Logger],
None
]


@dataclasses.dataclass(frozen=True)
class CommandOutput:
Expand Down Expand Up @@ -585,6 +592,7 @@ def run(
join: bool = False,
interactive: bool = False,
timeout: Optional[int] = None,
on_process_start: Optional[OnProcessStartCallback] = None,
# Logging
message: Optional[str] = None,
friendly_command: Optional[str] = None,
Expand All @@ -608,6 +616,8 @@ def run(
interaction with user.
:param timeout: if set, command would be interrupted, if still running,
after this many seconds.
:param on_process_start: if set, this callable would be called after the
command process started.
:param message: if set, it would be logged for more friendly logging.
:param friendly_command: if set, it would be logged instead of the
command itself, to improve visibility of the command in logging output.
Expand Down Expand Up @@ -693,6 +703,9 @@ def run(
except FileNotFoundError as exc:
raise RunError(f"File '{exc.filename}' not found.", self, 127, caller=caller) from exc

if on_process_start:
on_process_start(self, process, logger)

# Create and start stream loggers
stdout_logger = StreamLogger(
'out',
Expand Down Expand Up @@ -1337,7 +1350,8 @@ def run(self,
interactive: bool = False,
join: bool = False,
log: Optional[tmt.log.LoggingFunction] = None,
timeout: Optional[int] = None) -> CommandOutput:
timeout: Optional[int] = None,
on_process_start: Optional[OnProcessStartCallback] = None) -> CommandOutput:
"""
Run command, give message, handle errors
Expand Down Expand Up @@ -1366,6 +1380,7 @@ def run(self,
shell=shell,
env=env,
interactive=interactive,
on_process_start=on_process_start,
join=join,
log=log,
timeout=timeout,
Expand Down

0 comments on commit bc5122b

Please sign in to comment.