Skip to content

fix(Base): log the output of successful commands as debug. - #951

Open
lengau wants to merge 5 commits into
mainfrom
fix/issue-250-subprocess-output-not-logged
Open

fix(Base): log the output of successful commands as debug.#951
lengau wants to merge 5 commits into
mainfrom
fix/issue-250-subprocess-output-not-logged

Conversation

@lengau

@lengau lengau commented Apr 22, 2026

Copy link
Copy Markdown
Collaborator

Reproducer for #250

craft-providers runs many commands inside instances (apt-get, systemctl, snap, etc.) but never logs their output, even when running with debug/trace logging. Operators diagnosing problems have to reproduce a full failure to see what a command printed.

Failing test

test_execute_run_logs_output_at_debug — shows that _execute_run() captures stdout via capture_output=True but never writes it to the logger. After the command completes successfully, the output is simply discarded.

Bonus passing test

test_execute_run_output_included_in_error_details — verifies that the other half of #250 ("output not shown on error") already works: when a subprocess fails, its stdout is preserved on the CalledProcessError and included in the BaseConfigurationError details via details_from_called_process_error(). This serves as a regression guard.

Fix

In Base._execute_run(), after executor.execute_run() returns successfully, log proc.stdout and proc.stderr at logger.debug level (guarded by a truthiness check so empty output is not logged).

Closes #250

lengau and others added 2 commits April 22, 2026 00:16
…250)

Adds two tests for subprocess output visibility:

1. test_execute_run_logs_output_at_debug [FAILS] — _execute_run() captures
   stdout from every command via capture_output=True, but never logs it.
   Operators using debug/trace logging see nothing from in-container commands
   (apt-get, systemctl, etc.) even when they run successfully.

2. test_execute_run_output_included_in_error_details [PASSES] — verifies that
   the 'output shown on error' half of #250 already works: when a subprocess
   fails, its stdout is captured and included in the BaseConfigurationError
   details via details_from_called_process_error().

The fix for the failing test is to log proc.stdout at debug level inside
_execute_run() after a successful run.

Fixes: #250

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
_execute_run() captures output via capture_output=True but previously
discarded it on success. Now logs proc.stdout and proc.stderr at debug
level so operators running with -v or debug logging can see what in-
container commands (apt-get, systemctl, snap, etc.) printed without
needing to reproduce a full failure.

Fixes: #250

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@lengau lengau changed the title test: failing reproducer - subprocess output not logged (issue #250) fix(Base): log the output of successful commands as debug. Apr 22, 2026
@lengau
lengau marked this pull request as ready for review April 22, 2026 05:26
@lengau
lengau requested a review from a team as a code owner April 22, 2026 05:26
@tigarmo

tigarmo commented Apr 22, 2026

Copy link
Copy Markdown
Contributor

how noisy is this on a regular run?

@bepri

bepri commented Apr 22, 2026

Copy link
Copy Markdown
Member

I like the change, but I second Tiago's question -- if it's particularly noisy, I might suggest moving this to trace instead.

@lengau

lengau commented May 2, 2026

Copy link
Copy Markdown
Collaborator Author

@tigarmo @bepri logger.debug does only get output by craft-cli in trace mode.

@lengau
lengau requested review from bepri and tigarmo May 2, 2026 23:35

@mr-cal mr-cal left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

This will be a very helpful improvement, just being critical on readability.

Comment thread tests/unit/bases/test_ubuntu_buildd.py
Comment thread tests/unit/bases/test_ubuntu_buildd.py
lengau and others added 2 commits May 4, 2026 11:32
Co-authored-by: Callahan Kovacs <callahan.kovacs@canonical.com>
Signed-off-by: Alex Lowe <alex.lowe@canonical.com>
Co-authored-by: Callahan Kovacs <callahan.kovacs@canonical.com>
Signed-off-by: Alex Lowe <alex.lowe@canonical.com>
@lengau
lengau requested a review from mr-cal May 4, 2026 15:32

@mr-cal mr-cal left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

bases: subprocess output is not logged nor shown on error

4 participants