chore(xtest): Improve tool use output capture #323
Conversation
![gemini-code-assist[bot]](https://avatars.githubusercontent.com/in/956858?s=60&v=4){kind=small}
There was a problem hiding this comment.
Summary of Changes
Hello @dmihalcik-virtru, I'm Gemini Code Assist1! I'm currently reviewing this pull request and will post my feedback shortly. In the meantime, here's a summary to help you and other reviewers quickly get up to speed!
This pull request focuses on improving the observability and robustness of subprocess interactions within the xtest test suite. The primary goal is to ensure that all output (both standard output and standard error) from external tools is consistently captured and logged, making it significantly easier to debug test failures and understand the behavior of the system under test. This is achieved through systematic changes to subprocess calls and comprehensive logging configurations.
Highlights
- Enhanced Subprocess Output Capture: Modified all
subprocess.Popencalls inxtest/abac.pyto explicitly capture bothstdoutandstderr, ensuring more complete diagnostic information is available from external tool invocations. - Standardized Process Exit Code Checks: Updated
xtest/abac.pyto consistently useprocess.returncodefor checking subprocess exit status, replacing the less directprocess.wait()andcodevariable approach. - Improved Test Logging and Debugging: Introduced comprehensive logging configurations in
xtest/conftest.pyand a newxtest/pytest.inifile. This setspytestand Python'sloggingmodule toDEBUGlevel, ensuring all subprocess output and internal test logs are captured and displayed, with unbuffered output for immediate feedback. - Robust Subprocess Execution in
tdfs.py: Refactoredtdfs.pyto utilizesubprocess.runinstead ofsubprocess.check_outputandsubprocess.check_call. This provides more granular control over output capture and ensures thatCalledProcessErrorexceptions contain bothstdoutandstderrfor better debugging of failures. - Detailed Failure Diagnostics in
test_policytypes.py: Enhanced thedecrypt_or_dontfunction inxtest/test_policytypes.pyto log detailedstdoutandstderrfrom subprocesses, especially when expected failures occur. This significantly aids in diagnosing the exact reasons for test failures by providing full context.
Using Gemini Code Assist
The full guide for Gemini Code Assist can be found on our documentation page, here are some quick tips.
Invoking Gemini
You can request assistance from Gemini at any point in your pull request via creating an issue comment (i.e. comment on the pull request page) using either /gemini <command> or @gemini-code-assist <command>. Below is a summary of the supported commands.
| Feature | Command | Description |
|---|---|---|
| Code Review | /gemini review |
Performs a code review for the current pull request in its current state. |
| Pull Request Summary | /gemini summary |
Provides a summary of the current pull request in its current state. |
| Comment | @gemini-code-assist | Responds in comments when explicitly tagged, both in issue comments and review comments. |
| Help | /gemini help |
Displays a list of available commands. |
Customization
To customize Gemini Code Assist for GitHub experience, repository maintainers can create a configuration file and/or provide a custom code review style guide (such as PEP-8 for Python) by creating and adding files to a .gemini/ folder in the base of the repository. Detailed instructions can be found here.
Limitations & Feedback
Gemini Code Assist is currently in preview and may make mistakes. Please leave feedback on any instances where its feedback is incorrect or counter productive. You can react with 👍 and 👎 on @gemini-code-assist comments to provide feedback.
You can also get AI-powered code generation, chat, as well as code reviews directly in the IDE at no cost with the Gemini Code Assist IDE Extension.
Footnotes
-
Review the Privacy Notices, Generative AI Prohibited Use Policy, Terms of Service, and learn how to configure Gemini Code Assist in GitHub here. Gemini can make mistakes, so double check it and use code with caution. ↩
|
There was a problem hiding this comment.
Code Review
This pull request significantly improves the test suite by enhancing subprocess output capturing, which will make debugging test failures much easier. The changes correctly address potential deadlocks and bugs in handling stderr from subprocesses.
My main feedback is to remove some redundant configuration in conftest.py and test_policytypes.py to keep the setup clean and centralized in the new pytest.ini file. Also, I suggested to log the error output using the logger instead of printing to stderr in abac.py.
Overall, this is a valuable improvement to the repository's testing infrastructure.
| @pytest.hookimpl(trylast=True) | ||
| def pytest_configure(config: Any) -> None: | ||
| # Set log capture level to debug to ensure all logs are captured | ||
| if hasattr(config, "option"): | ||
| config.option.log_cli = True | ||
| config.option.log_cli_level = "DEBUG" | ||
| config.option.log_cli_format = ( | ||
| "%(asctime)s - %(name)s - %(levelname)s - %(message)s" | ||
| ) | ||
|
|
||
| # Configure logging to ensure we see everything from subprocesses | ||
| logging.basicConfig( | ||
| level=logging.DEBUG, | ||
| format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", | ||
| stream=sys.stdout, # Ensure output goes to stdout for pytest capture | ||
| ) | ||
| # Make sure subprocess logger is set to DEBUG level | ||
| logging.getLogger("subprocess").setLevel(logging.DEBUG) | ||
|
|
||
| # Set environment variable to make sure Python doesn't buffer stdout/stderr | ||
| os.environ["PYTHONUNBUFFERED"] = "1" | ||
|
|
||
| # Set buffering mode for subprocess to line buffered | ||
| os.environ["PYTHONFAULTHANDLER"] = "1" |
There was a problem hiding this comment.
This pytest_configure hook is redundant with the settings in the new xtest/pytest.ini file. To avoid duplication and keep configuration in a single, declarative place, this function should be removed.
- The
log_cli*options are set inpytest.ini. - The
envsection inpytest.inisetsPYTHONUNBUFFEREDandPYTHONFAULTHANDLER. - The
logging.basicConfigcall is also made redundant by pytest's logging setup when usinglog_cli.
| # Configure logging to ensure we see everything | ||
| logging.basicConfig( | ||
| level=logging.DEBUG, | ||
| format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", | ||
| stream=sys.stdout, # Ensure output goes to stdout for pytest capture | ||
| ) | ||
| # Make sure our logger is set to DEBUG level | ||
| logger.setLevel(logging.DEBUG) | ||
|
|
||
| # Configure subprocess logging if needed | ||
| logging.getLogger("subprocess").setLevel(logging.DEBUG) |
There was a problem hiding this comment.
This logging configuration is redundant now that logging is configured centrally for the test suite in xtest/pytest.ini. This block can be removed to avoid duplication. The root logger configuration in pytest.ini will apply to all loggers, including the "xtest" and "subprocess" loggers.
| logger.info(f"kr-ls [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| code = process.wait() | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| cmd += [f"--public-keys={public_key.model_dump_json()}"] | ||
| logger.info(f"kr-create [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| cmd += [f"--kas={kas.uri}"] | ||
| logger.info(f"kr-keys-ls [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| code = process.wait() | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) | ||
| out, err = process.communicate() |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| logger.info(f"ns-create [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| code = process.wait() | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| logger.info(f"attr-create [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| code = process.wait() | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| logger.info(f"scs-create [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| code = process.wait() | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)| logger.info(f"sm-create [{' '.join(cmd)}]") | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE) | ||
| code = process.wait() | ||
| process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE) |
There was a problem hiding this comment.
Consider logging the error output using the logger instead of printing to stderr. This allows for consistent logging and easier debugging.[^1]
logger.error(err)1 participant
No description provided.