Skip to content

feat: Add EOF and TIMEOUT exception handling in SolConnection._deacti… #49

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
DawidBerk wants to merge 1 commit into
base: main
Choose a base branch
from
Open

feat: Add EOF and TIMEOUT exception handling in SolConnection._deacti… #49

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
104 changes: 98 additions & 6 deletions mfd_connect/sol.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -327,17 +327,109 @@ def _establish_connection(self, retry_count: int = 0) -> "pexpect.spawn":

return sol_connection_process

def _deactivate_sol_session(self) -> None:
# clearing old session
def _deactivate_sol_session(self, retry_count: int = 2) -> None:
"""
Clear/deactivate previous SoL IPMI session before opening a new one.

Retries graceful deactivation via ipmiutil, then falls back to killing
defunct ipmiutil process(es) if all attempts fail.

:param retry_count: Number of graceful deactivation attempts
:raises SolException: if graceful deactivation and fallback cleanup fail
"""
logger.log(level=log_levels.MODULE_DEBUG, msg="Clearing/Deactivating previous SoL IPMI session...")
process = pexpect.popen_spawn.PopenSpawn(f"{self._ipmi_tool_name} sol -d {self._ipmi_parameters}", timeout=60)
# Both patterns below signal a successful deactivation (either the session was closed,
# or there was none to close in the first place) - pexpect.expect() raises TIMEOUT/EOF
# if neither is matched, so a returned index always means success.
correct_responses = [
"completed successfully",
"Invalid Session Handle or Empty Buffer",
]
expect_index = process.expect(correct_responses)
if expect_index > len(correct_responses) - 1:
raise SolException(f"Fatal Error while deactivating previous SoL session! \n{process.before}")

for attempt in range(1, retry_count + 1):
logger.log(
level=log_levels.MODULE_DEBUG,
msg=f"Attempt {attempt}/{retry_count} to deactivate previous SoL session...",
)
try:
process = pexpect.popen_spawn.PopenSpawn(
f"{self._ipmi_tool_name} sol -d {self._ipmi_parameters}", timeout=60
)
process.expect(correct_responses)
except (pexpect.TIMEOUT, pexpect.EOF) as e:
logger.log(
level=log_levels.MODULE_DEBUG,
msg=f"Attempt {attempt}/{retry_count}: "
f"{self._ipmi_tool_name} did not respond as expected while deactivating SoL session: {e}",
)
continue
Comment thread
DawidBerk marked this conversation as resolved.

logger.log(level=log_levels.MODULE_DEBUG, msg="...Done - previous SoL session deactivated.")
return

logger.log(
level=log_levels.MODULE_DEBUG,
msg=f"Could not gracefully deactivate SoL session after {retry_count} attempt(s). "
f"Trying to locate and kill defunct {self._ipmi_tool_name} process(es)...",
)
self._kill_defunct_ipmiutil_processes()

def _kill_defunct_ipmiutil_processes(self) -> None:
"""
Find and kill defunct/stopped ipmiutil process(es).

Processes are matched by command name and only STAT='T' entries are killed.
'T' means stopped by job control signal, while healthy ipmiutil usually
has 'S' or 'S+' (interruptible sleep, waiting for an event).

:raises SolException: if process listing fails, no defunct process is found,
or kill operation fails
"""
try:
ps_process = pexpect.popen_spawn.PopenSpawn(f"ps aux | grep {self._ipmi_tool_name}", timeout=30)
ps_process.expect(pexpect.EOF)

@tjankows-itp tjankows-itp Sep 1, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When using ps aux a exceeding timeout for the reply is rather unlikely, but it may be worth to just in case add also pexpect.TIMEOUT as an expected result?

ps_output = ps_process.before.decode("ASCII", errors="ignore")
except (pexpect.TIMEOUT, pexpect.EOF) as e:
Comment thread
DawidBerk marked this conversation as resolved.
raise SolException(f"Fatal Error while searching for defunct {self._ipmi_tool_name} process(es)! \n{e}")

defunct_pids = []
for line in ps_output.splitlines():
columns = line.split()
if len(columns) <= 10:
continue

@tjankows-itp tjankows-itp Sep 1, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This path of execution is not covered in unit-tests.

I don't understand the idea here. Are you sure, that the ps_output can change after interactions with the spawned process ended in line 390? If the execution reached passed lines 392-393, where any possible end-of-line or timeout exceptions are handled, I would assume that the complete output has already been acquired...

pid, stat, command = columns[1], columns[7], columns[10]
if command.rsplit("/", 1)[-1] != self._ipmi_tool_name:
continue
if stat.startswith("T"):
defunct_pids.append(pid)
else:
logger.log(
level=log_levels.MODULE_DEBUG,
msg=f"{self._ipmi_tool_name} process PID {pid} is in a healthy state '{stat}' "
"- leaving it running.",
)

if not defunct_pids:
raise SolException(
f"Fatal Error while deactivating previous SoL session! "
f"No defunct (stopped, STAT=T) {self._ipmi_tool_name} process(es) found to kill."
)

logger.log(
level=log_levels.MODULE_DEBUG,
msg=f"Found defunct {self._ipmi_tool_name} process(es) with PID(s): {defunct_pids}. Killing them...",
)
for pid in defunct_pids:
logger.log(level=log_levels.MODULE_DEBUG, msg=f"Killing defunct {self._ipmi_tool_name} process, PID: {pid}")
try:
# sudo -n (non-interactive) fails immediately if a password prompt would appear,
# avoiding indefinite blocking in automation.
kill_process = pexpect.popen_spawn.PopenSpawn(f"sudo -n kill -KILL {pid}", timeout=30)
kill_process.expect(pexpect.EOF)
except (pexpect.TIMEOUT, pexpect.EOF) as e:
raise SolException(f"Fatal Error while killing defunct {self._ipmi_tool_name} process PID {pid}! \n{e}")

logger.log(level=log_levels.MODULE_DEBUG, msg=f"...Done - defunct {self._ipmi_tool_name} process(es) killed.")

@log_func_info(logger)
def wait_for_string(self, string_list: List[str], expect_timeout: bool = False, timeout: int = 30) -> int:
Expand Down
141 changes: 141 additions & 0 deletions tests/unit/test_mfd_connect/test_sol.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
from subprocess import CalledProcessError
from textwrap import dedent

import pexpect
import pytest
from mfd_typing.os_values import OSBitness, OSType, OSName
from pytest import raises, fixture
Expand Down Expand Up @@ -152,6 +153,146 @@ def test_establish_connection_retries_once(self, sol, mocker):
assert spawn.call_count == 2
assert result is second_child

def test_deactivate_sol_session_success_first_attempt(self, sol, mocker):
sol._ipmi_tool_name = "ipmiutil"
sol._ipmi_parameters = "-F lan2 -U admin -P secret -N 10.10.10.10 -V 4"
child = mocker.Mock()
child.expect.return_value = 0
popen_spawn = mocker.patch("mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", return_value=child)
kill_mock = mocker.patch.object(sol, "_kill_defunct_ipmiutil_processes")

sol._deactivate_sol_session()

popen_spawn.assert_called_once()
kill_mock.assert_not_called()

def test_deactivate_sol_session_retries_after_timeout_then_succeeds(self, sol, mocker):
sol._ipmi_tool_name = "ipmiutil"
sol._ipmi_parameters = "-F lan2 -U admin -P secret -N 10.10.10.10 -V 4"
first_child = mocker.Mock()
first_child.expect.side_effect = pexpect.TIMEOUT("timed out")
second_child = mocker.Mock()
second_child.expect.return_value = 0
popen_spawn = mocker.patch(
"mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", side_effect=[first_child, second_child]
)
kill_mock = mocker.patch.object(sol, "_kill_defunct_ipmiutil_processes")

sol._deactivate_sol_session()

assert popen_spawn.call_count == 2
kill_mock.assert_not_called()

def test_deactivate_sol_session_falls_back_to_kill_after_repeated_failures(self, sol, mocker):
"""Both attempts raise pexpect exceptions (defunct process) - the whole run must not crash."""
sol._ipmi_tool_name = "ipmiutil"
sol._ipmi_parameters = "-F lan2 -U admin -P secret -N 10.10.10.10 -V 4"
first_child = mocker.Mock()
first_child.expect.side_effect = pexpect.TIMEOUT("timed out")
second_child = mocker.Mock()
second_child.expect.side_effect = pexpect.EOF("eof")
popen_spawn = mocker.patch(
"mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", side_effect=[first_child, second_child]
)
kill_mock = mocker.patch.object(sol, "_kill_defunct_ipmiutil_processes")

sol._deactivate_sol_session() # must not raise

assert popen_spawn.call_count == 2
kill_mock.assert_called_once()

def test_kill_defunct_ipmiutil_processes_kills_found_pid(self, sol, mocker):
sol._ipmi_tool_name = "ipmiutil"
ps_child = mocker.Mock()
ps_child.before = (
b"berta 206865 0.0 0.3 9368 6700 pts/0 T 15:40 0:00 "
b"ipmiutil sol -a -F lan2 -U -P -N 10.102.20.61 -V 4\n"
b"berta 213349 0.0 0.1 6544 2392 pts/1 S+ 16:00 0:00 grep --color=auto ipmiutil\n"
)
kill_child = mocker.Mock()
popen_spawn = mocker.patch("mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", side_effect=[ps_child, kill_child])

sol._kill_defunct_ipmiutil_processes()

assert popen_spawn.call_args_list[0].args[0] == "ps aux | grep ipmiutil"
assert popen_spawn.call_args_list[1].args[0] == "sudo -n kill -KILL 206865"
ps_child.expect.assert_called_once_with(pexpect.EOF)
kill_child.expect.assert_called_once_with(pexpect.EOF)

def test_kill_defunct_ipmiutil_processes_kills_multiple_pids(self, sol, mocker):
"""Mirrors real-world output: two stopped (T) ipmiutil sessions must both be killed."""
sol._ipmi_tool_name = "ipmiutil"
ps_child = mocker.Mock()
ps_child.before = (
b"berta 206865 0.0 0.3 9368 6700 pts/0 T 15:40 0:00 "
b"ipmiutil sol -a -F lan2 -U -P -N 10.102.20.61 -V 4\n"
b"berta 210671 0.0 0.3 9368 6644 pts/0 T 15:52 0:00 "
b"ipmiutil sol -a -F lan2 -U -P -N 10.102.20.61 -V 4\n"
b"berta 213349 0.0 0.1 6544 2392 pts/1 S+ 16:00 0:00 grep --color=auto ipmiutil\n"
)
kill_child_1 = mocker.Mock()
kill_child_2 = mocker.Mock()
popen_spawn = mocker.patch(
"mfd_connect.sol.pexpect.popen_spawn.PopenSpawn",
side_effect=[ps_child, kill_child_1, kill_child_2],
)

sol._kill_defunct_ipmiutil_processes()

assert popen_spawn.call_args_list[1].args[0] == "sudo -n kill -KILL 206865"
assert popen_spawn.call_args_list[2].args[0] == "sudo -n kill -KILL 210671"

def test_kill_defunct_ipmiutil_processes_kills_only_stopped_ones(self, sol, mocker):
"""Mix of stopped (T) and healthy (S+) processes - only the stopped one gets killed."""
sol._ipmi_tool_name = "ipmiutil"
ps_child = mocker.Mock()
ps_child.before = (
b"berta 206865 0.0 0.3 9368 6700 pts/0 T 15:40 0:00 "
b"ipmiutil sol -a -F lan2 -U -P -N 10.102.20.61 -V 4\n"
b"berta 220000 0.0 0.3 9368 6700 pts/0 S+ 15:41 0:00 "
b"ipmiutil sol -a -F lan2 -U -P -N 10.102.20.62 -V 4\n"
b"berta 213349 0.0 0.1 6544 2392 pts/1 S+ 16:00 0:00 grep --color=auto ipmiutil\n"
)
kill_child = mocker.Mock()
popen_spawn = mocker.patch("mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", side_effect=[ps_child, kill_child])

sol._kill_defunct_ipmiutil_processes()

assert popen_spawn.call_count == 2 # ps aux + single kill (healthy one skipped)
assert popen_spawn.call_args_list[1].args[0] == "sudo -n kill -KILL 206865"

def test_kill_defunct_ipmiutil_processes_raises_when_no_pid_found(self, sol, mocker):
sol._ipmi_tool_name = "ipmiutil"
ps_child = mocker.Mock()
ps_child.before = b"user 3333 0.0 0.1 1 1 pts/0 S+ 12:00 0:00 grep ipmiutil\n"
mocker.patch("mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", return_value=ps_child)

with pytest.raises(SolException):
sol._kill_defunct_ipmiutil_processes()

def test_kill_defunct_ipmiutil_processes_raises_when_ps_times_out(self, sol, mocker):
sol._ipmi_tool_name = "ipmiutil"
ps_child = mocker.Mock()
ps_child.expect.side_effect = pexpect.TIMEOUT("timed out")
mocker.patch("mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", return_value=ps_child)

with pytest.raises(SolException):
sol._kill_defunct_ipmiutil_processes()

def test_kill_defunct_ipmiutil_processes_raises_when_kill_fails(self, sol, mocker):
sol._ipmi_tool_name = "ipmiutil"
ps_child = mocker.Mock()
ps_child.before = (
b"berta 206865 0.0 0.3 9368 6700 pts/0 T 15:40 0:00 "
b"ipmiutil sol -a -F lan2 -U -P -N 10.102.20.61 -V 4\n"
)
kill_child = mocker.Mock()
kill_child.expect.side_effect = pexpect.TIMEOUT("timed out")
mocker.patch("mfd_connect.sol.pexpect.popen_spawn.PopenSpawn", side_effect=[ps_child, kill_child])

with pytest.raises(SolException):
sol._kill_defunct_ipmiutil_processes()

def test__parse_selection_regex_fallback_blue_background(self):
output = "\x1b[44mSelected Boot Option"

Expand Down
Loading