Automated nbdkit instance name visible in debug logs#6838
Automated nbdkit instance name visible in debug logs#6838xiaodwan merged 2 commits intoautotest:masterfrom
Conversation
WalkthroughAdds a new Estimated code review effort🎯 3 (Moderate) | ⏱️ ~20 minutes 🚥 Pre-merge checks | ✅ 2 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (2 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ Finishing Touches🧪 Generate unit tests (beta)
Comment |
There was a problem hiding this comment.
Actionable comments posted: 1
🧹 Nitpick comments (2)
v2v/tests/src/nbdkit/nbdkit.py (2)
745-749: Consider using dynamic ports to avoid conflicts.Hardcoded ports 10809 (default NBD port) and 10810 may conflict with other services or parallel test runs. Consider using
-U(Unix socket) or-p 0to let the system assign available ports, similar to patterns used elsewhere in this codebase.🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 745 - 749, The test currently hardcodes ports in the instances list (instances = [{"name": "server-gold", "port": 10809}, {"name": "server-silver", "port": 10810}]) which can cause conflicts; change the test to request dynamic ports (e.g., pass "-p 0" or use "-U" for a Unix socket) when launching the nbdkit servers and capture the assigned port/socket from the server startup (stdout, returned metadata, or the helper that starts the process) and store that back into the instances structure so subsequent code uses the real, assigned endpoint for "server-gold" and "server-silver". Ensure any code that reads instances[*]["port"] or connects to the servers uses the dynamically discovered value.
772-778: Add delay or retry for server readiness.The
poll()check only confirms the process hasn't crashed, not that it's ready to accept connections. This could cause intermittent failures if qemu-io attempts to connect before the server is listening.♻️ Proposed fix - add sleep after process check
for inst, p in handles: if p.poll() is not None: test.fail(f"nbdkit {inst['name']} failed to start! Check {log_path}") + # Wait for servers to be ready to accept connections + import time + time.sleep(1) + # Trigger activity with qemu-io🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 772 - 778, The current loop that checks handles with p.poll() only verifies the nbdkit process hasn't exited but doesn't ensure it's listening, so modify the startup sequence after the existing poll checks to wait for server readiness: implement a short retry loop (with timeout) per instance (using the existing instances list and inst['port']/inst['name']) that either sleeps briefly between attempts or tries a simple TCP connect to localhost:inst['port'] until successful, then proceed to the qemu-io activity; ensure the loop fails the test with a clear message if the port never becomes ready within the timeout.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 779-783: The qemu-io invocation builds a shell-escaped command
string (qemu_cmd) but calls process.run without shell=True so the shell
metacharacters aren't interpreted; update the call to process.run to execute the
string via the shell (pass shell=True) or alternatively avoid shell escaping by
passing args list to process.run; change the usage around the qemu_cmd and
process.run invocation (and keep the existing failure handling that calls
test.fail for non-zero exit via result.exit_status) so the command executes
correctly.
---
Nitpick comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 745-749: The test currently hardcodes ports in the instances list
(instances = [{"name": "server-gold", "port": 10809}, {"name": "server-silver",
"port": 10810}]) which can cause conflicts; change the test to request dynamic
ports (e.g., pass "-p 0" or use "-U" for a Unix socket) when launching the
nbdkit servers and capture the assigned port/socket from the server startup
(stdout, returned metadata, or the helper that starts the process) and store
that back into the instances structure so subsequent code uses the real,
assigned endpoint for "server-gold" and "server-silver". Ensure any code that
reads instances[*]["port"] or connects to the servers uses the dynamically
discovered value.
- Around line 772-778: The current loop that checks handles with p.poll() only
verifies the nbdkit process hasn't exited but doesn't ensure it's listening, so
modify the startup sequence after the existing poll checks to wait for server
readiness: implement a short retry loop (with timeout) per instance (using the
existing instances list and inst['port']/inst['name']) that either sleeps
briefly between attempts or tries a simple TCP connect to localhost:inst['port']
until successful, then proceed to the qemu-io activity; ensure the loop fails
the test with a clear message if the port never becomes ready within the
timeout.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: 8723feb7-2ef4-4bdf-8d66-fefd6b19db99
📒 Files selected for processing (2)
v2v/tests/cfg/nbdkit/nbdkit.cfgv2v/tests/src/nbdkit/nbdkit.py
6b3e46c to
82f49b5
Compare
There was a problem hiding this comment.
Actionable comments posted: 1
🧹 Nitpick comments (1)
v2v/tests/src/nbdkit/nbdkit.py (1)
754-770: File handle closed while subprocesses still writing to it.The
withblock closeslog_fileat line 770, but the nbdkit processes continue running and writing debug output. While this works on Unix due to file descriptor inheritance, it's fragile and could cause issues:
- Inconsistent behavior across platforms
- Confusing code structure
Consider keeping the file open until after process cleanup.
♻️ Suggested refactor to keep file open throughout test
handles = [] + log_file = None try: - with open(log_path, "a") as log_file: - for inst in instances: - LOG.info(f"Starting nbdkit instance: {inst['name']}") - - # Construct the command - # --foreground: Keeps it attached so we can redirect output easily - # --debug: Required to see the instance name in logs - cmd = [ - "nbdkit", "-f", "-v", - "--name", inst['name'], - "--port", str(inst['port']), - "memory", "10M" - ] - # Start nbdkit as a background process, piping stderr to our log file - p = Popen(cmd, stderr=log_file, stdout=log_file) - handles.append((inst, p)) + log_file = open(log_path, "a") + for inst in instances: + LOG.info(f"Starting nbdkit instance: {inst['name']}") + + cmd = [ + "nbdkit", "-f", "-v", + "--name", inst['name'], + "--port", str(inst['port']), + "memory", "10M" + ] + p = Popen(cmd, stderr=log_file, stdout=log_file) + handles.append((inst, p)) for inst, p in handles:And close it in the
finallyblock after process cleanup:finally: # Cleanup: Kill the processes LOG.info("Cleanup: Kill the processes") for _, p in handles: if p.poll() is None: p.terminate() try: p.wait(timeout=5) except TimeoutExpired: p.kill() if log_file: log_file.close()🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 754 - 770, The log file is opened inside a with block and closed while nbdkit subprocesses started with Popen (see handles list and cmd construction) may still be writing to it; refactor to open log_path once before launching instances (e.g., assign log_file = open(log_path, "a")), use that open file for Popen(stderr=log_file, stdout=log_file) while appending (handles.append((inst, p))), and then in the existing finally/cleanup section iterate over handles to terminate/wait/kill subprocesses and only after all processes are stopped call log_file.close(); ensure no other early closes or context managers close the file.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 772-783: The test currently only checks processes in handles with
p.poll() and then immediately runs qemu-io (qemu_cmd via process.run) against
each entry in instances; change this to wait for nbdkit readiness by adding a
retry/timeout loop per instance that attempts to connect (e.g., try running a
lightweight probe or TCP connect to inst['port']) with short sleeps between
attempts and a reasonable overall timeout before invoking qemu_cmd, and only
call process.run(qemu_cmd) once the probe succeeds (also keep the existing
poll() check to fail early if p.poll() != None).
---
Nitpick comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 754-770: The log file is opened inside a with block and closed
while nbdkit subprocesses started with Popen (see handles list and cmd
construction) may still be writing to it; refactor to open log_path once before
launching instances (e.g., assign log_file = open(log_path, "a")), use that open
file for Popen(stderr=log_file, stdout=log_file) while appending
(handles.append((inst, p))), and then in the existing finally/cleanup section
iterate over handles to terminate/wait/kill subprocesses and only after all
processes are stopped call log_file.close(); ensure no other early closes or
context managers close the file.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: ba73784f-71d3-4a56-a14c-433a9fd79348
📒 Files selected for processing (2)
v2v/tests/cfg/nbdkit/nbdkit.cfgv2v/tests/src/nbdkit/nbdkit.py
🚧 Files skipped from review as they are similar to previous changes (1)
- v2v/tests/cfg/nbdkit/nbdkit.cfg
Signed-off-by: Ganesh Hubale <ghubale@redhat.com>
82f49b5 to
e501149
Compare
There was a problem hiding this comment.
🧹 Nitpick comments (2)
v2v/tests/src/nbdkit/nbdkit.py (2)
743-743: Move imports to module level.Imports (
Popen,TimeoutExpiredfromsubprocess, andtimeat line 777) are placed inside the function. For consistency with the rest of the file and Python conventions, these should be at the module level.♻️ Proposed fix to move imports to module level
At the top of the file (after line 5):
import time from subprocess import Popen, TimeoutExpiredThen remove lines 743 and 777 from inside the function.
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@v2v/tests/src/nbdkit/nbdkit.py` at line 743, The local imports of Popen and TimeoutExpired (from subprocess) and time should be moved to module-level to follow project conventions: add "import time" and "from subprocess import Popen, TimeoutExpired" near the top of the file, then remove the in-function imports currently present (the lines importing Popen/TimeoutExpired around where the function uses them and the time import at line 777). Locate the function that calls Popen/TimeoutExpired/time in nbdkit.py (search for uses of Popen, TimeoutExpired, or time) and ensure it now relies on the module-level imports only.
746-750: Hardcoded ports may cause test flakiness.Ports 10809 and 10810 are hardcoded. If another process (or a parallel test) is already using these ports, the test will fail. Consider using dynamic port allocation or at least checking port availability before starting.
♻️ Optional: Dynamic port allocation approach
+ import socket + + def get_free_port(): + with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as s: + s.bind(('', 0)) + return s.getsockname()[1] + instances = [ - {"name": "server-gold", "port": 10809}, - {"name": "server-silver", "port": 10810} + {"name": "server-gold", "port": get_free_port()}, + {"name": "server-silver", "port": get_free_port()} ]🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 746 - 750, The test hardcodes ports in the instances list (entries with "name": "server-gold"/"server-silver" and "port": 10809/10810), which can cause flakiness; instead, allocate ports dynamically before building instances by finding free ports (e.g., bind a temporary socket to port 0 or call an existing get_free_port/get_unused_port helper) and replace the hardcoded port values with those discovered ports, or at minimum check availability and retry if in use; update the code that constructs the instances list to use the dynamically obtained port variables.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Nitpick comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Line 743: The local imports of Popen and TimeoutExpired (from subprocess) and
time should be moved to module-level to follow project conventions: add "import
time" and "from subprocess import Popen, TimeoutExpired" near the top of the
file, then remove the in-function imports currently present (the lines importing
Popen/TimeoutExpired around where the function uses them and the time import at
line 777). Locate the function that calls Popen/TimeoutExpired/time in nbdkit.py
(search for uses of Popen, TimeoutExpired, or time) and ensure it now relies on
the module-level imports only.
- Around line 746-750: The test hardcodes ports in the instances list (entries
with "name": "server-gold"/"server-silver" and "port": 10809/10810), which can
cause flakiness; instead, allocate ports dynamically before building instances
by finding free ports (e.g., bind a temporary socket to port 0 or call an
existing get_free_port/get_unused_port helper) and replace the hardcoded port
values with those discovered ports, or at minimum check availability and retry
if in use; update the code that constructs the instances list to use the
dynamically obtained port variables.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: e1377a8c-d165-443e-a804-6638b0588163
📒 Files selected for processing (2)
v2v/tests/cfg/nbdkit/nbdkit.cfgv2v/tests/src/nbdkit/nbdkit.py
🚧 Files skipped from review as they are similar to previous changes (1)
- v2v/tests/cfg/nbdkit/nbdkit.cfg
Signed-off-by: Ganesh Hubale <ghubale@redhat.com>
There was a problem hiding this comment.
Actionable comments posted: 2
♻️ Duplicate comments (1)
v2v/tests/src/nbdkit/nbdkit.py (1)
772-778:⚠️ Potential issue | 🟠 MajorThe fixed one-second delay is still racy.
A one-second sleep can still race listener startup on a slow or loaded runner, so this checkpoint remains intermittent. Please replace the sleep with a bounded readiness probe per instance before the write loop.
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed. In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 772 - 778, The fixed time.sleep(1) is racy; replace it with a bounded readiness probe per nbdkit instance: for each (inst, p) in handles, loop until either the process has exited (p.poll() != None -> test.fail(..., log_path)) or the instance answers a real readiness check (e.g., attempt a TCP connect to the instance listen address or open its expected socket/path from inst, or perform the same operation the test will later use) with a short sleep between attempts and an overall timeout (e.g., a few seconds); if the timeout is reached call test.fail with the instance name and log_path. Remove the unconditional time.sleep(1) and ensure the readiness loop uses inst, p, test.fail and log_path to report failures.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.
Inline comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Line 750: The nbdkit debug log is being written to a temp directory (log_path
= os.path.join(data_dir.get_tmp_dir(), "nbdkit_debug.log")) which gets
discarded; change the path to store the log in the test artifact directory (use
test.logdir or the Avocado artifact API) instead of data_dir.get_tmp_dir(), and
also emit the validated instance-name lines to the test logger (e.g., via
self.log or the test object logger) so they appear in test artifacts; apply the
same change for the similar block around lines referencing the same log_path
logic (the 789-798 region) so both locations persist debug output to the test
results directory.
- Around line 785-787: The call to process.run in the qemu-io block should pass
ignore_status=True so CmdError is not raised on non-zero exit; update the
process.run(qemu_cmd, ...) invocation to include ignore_status=True, allowing
the subsequent check of result.exit_status and the instance-specific
test.fail(f"qemu-io failed for {inst['name']}") to execute normally.
---
Duplicate comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 772-778: The fixed time.sleep(1) is racy; replace it with a
bounded readiness probe per nbdkit instance: for each (inst, p) in handles, loop
until either the process has exited (p.poll() != None -> test.fail(...,
log_path)) or the instance answers a real readiness check (e.g., attempt a TCP
connect to the instance listen address or open its expected socket/path from
inst, or perform the same operation the test will later use) with a short sleep
between attempts and an overall timeout (e.g., a few seconds); if the timeout is
reached call test.fail with the instance name and log_path. Remove the
unconditional time.sleep(1) and ensure the readiness loop uses inst, p,
test.fail and log_path to report failures.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Organization UI
Review profile: CHILL
Plan: Pro
Run ID: 8b558e2e-cac5-4da5-857d-cd9c6b96a493
📒 Files selected for processing (1)
v2v/tests/src/nbdkit/nbdkit.py
| {"name": "server-gold", "port": 10809}, | ||
| {"name": "server-silver", "port": 10810} | ||
| ] | ||
| log_path = os.path.join(data_dir.get_tmp_dir(), "nbdkit_debug.log") |
There was a problem hiding this comment.
🧩 Analysis chain
🏁 Script executed:
# First, let's examine the file at lines 750, 789-798, and surrounding context
wc -l v2v/tests/src/nbdkit/nbdkit.pyRepository: autotest/tp-libvirt
Length of output: 97
🏁 Script executed:
# Read the relevant sections with context
sed -n '740,810p' v2v/tests/src/nbdkit/nbdkit.pyRepository: autotest/tp-libvirt
Length of output: 3219
🏁 Script executed:
# Also check lines 789-798
sed -n '785,805p' v2v/tests/src/nbdkit/nbdkit.pyRepository: autotest/tp-libvirt
Length of output: 1066
🏁 Script executed:
# Check if there are other logging patterns in this file
rg "log_path|logdir|outputdir|self.log" v2v/tests/src/nbdkit/nbdkit.py -n -A 2 -B 2Repository: autotest/tp-libvirt
Length of output: 914
🏁 Script executed:
# Check Avocado test class and imports in this file
head -50 v2v/tests/src/nbdkit/nbdkit.pyRepository: autotest/tp-libvirt
Length of output: 1474
🏁 Script executed:
# Search for how logs are typically handled in this test suite
rg "\.log\(|logdir|outputdir" v2v/tests/src/nbdkit/ -n -lRepository: autotest/tp-libvirt
Length of output: 45
🏁 Script executed:
# Search for test.logdir or similar usage in the test suite
rg "test\.logdir|test\.outputdir|test\.logfile" v2v/tests/src/ -n | head -20Repository: autotest/tp-libvirt
Length of output: 45
🏁 Script executed:
# Check other nbdkit tests or similar tests for logging patterns
rg "data_dir\.get_tmp_dir\(\)" v2v/tests/src/nbdkit/ -n -B 2 -A 2Repository: autotest/tp-libvirt
Length of output: 7430
🏁 Script executed:
# Check for process output redirection patterns in similar tests
rg "with open.*log" v2v/tests/src/ -n -l | head -10Repository: autotest/tp-libvirt
Length of output: 93
🏁 Script executed:
# Look for Avocado test logging API usage in this file
rg "self\.log\(|LOG\." v2v/tests/src/nbdkit/nbdkit.py -n | head -20Repository: autotest/tp-libvirt
Length of output: 1061
Move nbdkit debug log to test artifacts directory.
The nbdkit debug output containing instance name validation is written to a temporary directory and discarded after test completion. This prevents passing tests from surfacing the debug information needed for troubleshooting. Store the log file in the test results directory (using test.logdir or similar Avocado test artifact API) and/or emit the validated instance name lines through the test logger so the information persists in test artifacts.
Also applies to: 789-798
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@v2v/tests/src/nbdkit/nbdkit.py` at line 750, The nbdkit debug log is being
written to a temp directory (log_path = os.path.join(data_dir.get_tmp_dir(),
"nbdkit_debug.log")) which gets discarded; change the path to store the log in
the test artifact directory (use test.logdir or the Avocado artifact API)
instead of data_dir.get_tmp_dir(), and also emit the validated instance-name
lines to the test logger (e.g., via self.log or the test object logger) so they
appear in test artifacts; apply the same change for the similar block around
lines referencing the same log_path logic (the 789-798 region) so both locations
persist debug output to the test results directory.
| result = process.run(qemu_cmd, shell=True) | ||
| if result.exit_status != 0: | ||
| test.fail(f"qemu-io failed for {inst['name']}") |
There was a problem hiding this comment.
🧩 Analysis chain
🏁 Script executed:
find . -type f -name "nbdkit.py" | head -20Repository: autotest/tp-libvirt
Length of output: 95
🏁 Script executed:
if [ -f "v2v/tests/src/nbdkit/nbdkit.py" ]; then
sed -n '780,795p' "v2v/tests/src/nbdkit/nbdkit.py"
else
echo "File not found at expected path"
find . -name "nbdkit.py" -type f 2>/dev/null | head -5
fiRepository: autotest/tp-libvirt
Length of output: 831
🏁 Script executed:
if [ -f "v2v/tests/src/nbdkit/nbdkit.py" ]; then
head -50 "v2v/tests/src/nbdkit/nbdkit.py" | grep -E "^import|^from" | head -20
fiRepository: autotest/tp-libvirt
Length of output: 465
🏁 Script executed:
if [ -f "v2v/tests/src/nbdkit/nbdkit.py" ]; then
rg "process\.run\(" "v2v/tests/src/nbdkit/nbdkit.py" -A 3 -B 1
fiRepository: autotest/tp-libvirt
Length of output: 24805
🌐 Web query:
avocado.utils.process.run() default ignore_status behavior exception
💡 Result:
In avocado.utils.process.run(cmd, ...), the ignore_status parameter defaults to False. With the default (ignore_status=False), if the command exits with a non-zero status, run() will raise avocado.utils.process.CmdError instead of returning normally. When ignore_status=True, it will not raise on non-zero exit status and will return the result anyway. [1]
Source(s):
[1] Avocado utils API docs (avocado.utils.process.run signature and ignore_status/CmdError behavior) (avocado-framework.readthedocs.io)
Citations:
🌐 Web query:
avocado framework process.run non-zero exit default behavior
💡 Result:
In Avocado, avocado.utils.process.run() defaults to ignore_status=False, meaning a non-zero exit code causes process.run() to raise avocado.utils.process.CmdError (instead of returning normally). If you want to accept non-zero exits, pass ignore_status=True. [1]
This is why Avocado docs commonly show wrapping process.run() in a try/except process.CmdError when failures are expected/handled. [2]
Sources: [1] [3] [2] [4]
Pass ignore_status=True to handle qemu-io failures gracefully.
avocado.utils.process.run() raises CmdError on non-zero exit when ignore_status is not set, making the result.exit_status check unreachable. Add ignore_status=True so the code can catch failures and fail the test with the instance-specific error message instead of a generic exception.
🛠️ Minimal fix
- result = process.run(qemu_cmd, shell=True)
+ result = process.run(qemu_cmd, shell=True, ignore_status=True)
if result.exit_status != 0:
- test.fail(f"qemu-io failed for {inst['name']}")
+ test.fail(
+ f"qemu-io failed for {inst['name']}: "
+ f"{result.stderr_text or result.stdout_text}"
+ )🧰 Tools
🪛 Ruff (0.15.6)
[error] 785-785: Function call with shell=True parameter identified, security issue
(S604)
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.
In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 785 - 787, The call to
process.run in the qemu-io block should pass ignore_status=True so CmdError is
not raised on non-zero exit; update the process.run(qemu_cmd, ...) invocation to
include ignore_status=True, allowing the subsequent check of result.exit_status
and the instance-specific test.fail(f"qemu-io failed for {inst['name']}") to
execute normally.
Test result:
Summary by CodeRabbit