run.py: always log the sandbox when a command fails #3992
Conversation
The main focus of commit 7e7a3c7 ("Don't log sandbox for every command") was to reduce verbosity in the --debug case and it did just that. To avoid losing the sandbox completely, that commit said "... but still log the full sandbox if a command fails" and it did that too in __init__.py; for both the --debug and non-debug cases. However, what happened in run.py was a bit different: there, commit 7e7a3c7 showed the sandox on failure but only in the --debug case!? Make run.py consistent with __init__.py and always show the sandbox on failure in run.py, in _both_ --debug and non-debug case. This helps with issue systemd#3948: hiding that bind mounts exist is especially confusing on fatal "disk full" failures because that leaves only misleading paths in the error message! On failure, showing such critical sandbox information must not require --debug. Not concealing the sandbox on failure is useful in any case, not just systemd#3948 Signed-off-by: Marc Herbert <[email protected]>
Add v14/v15 test to adjust option based on the mkosi version. No need to change the run_qemu.sh source code anymore. Passing --debug by default is especially useful because hides the sandbox unless --debug is uses, see systemd/mkosi#3992 Signed-off-by: Marc Herbert <[email protected]>
This comment was marked as outdated.
This comment was marked as outdated.
Add v14/v15 test to adjust option based on the mkosi version. No need to change the run_qemu.sh source code anymore. Passing --debug by default is especially useful because hides the sandbox unless --debug is uses, see systemd/mkosi#3992 Signed-off-by: Marc Herbert <[email protected]>
This comment was marked as off-topic.
This comment was marked as off-topic.
Reformat the previous commit as required by ruff Signed-off-by: Marc Herbert <[email protected]>
|
It's really not necessary to get CI fully green. mkosi CI is very susceptible to variations on the distro side, e.g. flaky mirrors. |
|
So I'm of two minds of this. The sandbox commands can be really long and looking at the full command it's harder to see the needle in the haystack. For a lot of use cases seeing the actual command that failed is sufficient and showing the sandbox there would then make it harder to see what is going on. What would you think about a more actionable error message |
|
I'd prefer if we repurpose |
This comment was marked as off-topic.
This comment was marked as off-topic.
That's fair, I focused on Either way, this does print a very long, "haystack" command line. For which I thought of a dead-simple fix: simply split it across 2 lines instead! Like this: Haystack problem solved. That data already comes separate, so why concatenate them after all? Remember: this is still only on failure. When the some command fails, users much, much prefer to have "non-optimal" but complete information about that command. Especially when the command that failed is buried below multiple layers of wrapper scripts in a CI far away, in an environment that is unfortunately not easy to reproduce and that they can't change much. Yes this is the worst possible case but it's not theoretical either; happens regularly. (I just realized that 0c4a895 has later added to
I'm not 100% sure how big of a change that would be but it sounds like a much bigger change than this small PR. Probably bigger than the time I have :-( Value and effort considerations aside, I really think that sandbox information is too important and too relevant to be behind some --debug flag on failure. |
|
Sorry but this is just too verbose to do by default. I gave it a try and it's the difference between a two line error message and an error message that takes up half my terminal when running dnf. I'm going to close this. I'm confident this is not the right solution. |
As discussed in systemd#3948 and systemd#3992, logging commands failing in a sandbox without ever mentioning that a sandbox was in use is misleading and very time-consuming; notably because paths look real but they are not. To remove this confusion and cost, simply add one short line mentioning that a sandbox was involved when the failure happened + recommend to re-run with --debug to display bind mounts and other important information. Also separate the command and error message on different lines for better readability and re-usability. Just for the record: before commit 7e7a3c7 ("Don't log sandbox for every command"), `run.py` was logging sandbox commands every time which was too verbose and unreadable. That commit said "... but still log the full sandbox if a command fails" and it did that do in `__init__.py` - but not always in `run.py`. After that commit, the sandbox was logged by `run.py` only in --debug mode and became completely invisible otherwise. Signed-off-by: Marc Herbert <[email protected]>
As discussed in systemd#3948 and systemd#3992, logging commands failing in a sandbox without ever mentioning that a sandbox was in use is misleading and very time-consuming; notably because paths look real but they are not. To remove this confusion and cost, simply add one short line mentioning that a sandbox was involved when the failure happened + recommend to re-run with --debug to display bind mounts and other important information. Also separate the command and error message on different lines for better readability and re-usability. Just for the record: before commit 7e7a3c7 ("Don't log sandbox for every command"), `run.py` was logging sandbox commands every time which was too verbose and unreadable. That commit said "... but still log the full sandbox if a command fails" and it did that do in `__init__.py` - but not always in `run.py`. After that commit, the sandbox was logged by `run.py` only in --debug mode and became completely invisible otherwise. Signed-off-by: Marc Herbert <[email protected]>
As discussed in systemd#3948 and systemd#3992, logging commands failing in a sandbox without ever mentioning that a sandbox was in use is misleading and very time-consuming; notably because paths look real but they are not. To remove this confusion and cost, simply add one short line mentioning that a sandbox was involved when the failure happened + recommend to re-run with --debug to display bind mounts and other important information. Also separate the command and error message on different lines for better readability and re-usability. Just for the record: before commit 7e7a3c7 ("Don't log sandbox for every command"), `run.py` was logging sandbox commands every time which was too verbose and unreadable. That commit said "... but still log the full sandbox if a command fails" and it did that do in `__init__.py` - but not always in `run.py`. After that commit, the sandbox was logged by `run.py` only in --debug mode and became completely invisible otherwise. Signed-off-by: Marc Herbert <[email protected]>
Done in new PR: |
3 participants
The main focus of commit 7e7a3c7 ("Don't log sandbox for every
command") was to reduce verbosity in the --debug case and it did just
that. To avoid losing the sandbox completely, that commit said "... but
still log the full sandbox if a command fails" and it did that too in
__init__.py; for both the --debug and non-debug cases.However, what happened in run.py was a bit different: there, commit
7e7a3c7 showed the sandox on failure but only in the --debug
case!? Make run.py consistent with
__init__.pyand always show thesandbox on failure in run.py, in both --debug and non-debug case.
This helps with issue #3948: hiding that bind mounts exist is especially
confusing on fatal "disk full" failures because that leaves only
misleading paths in the error message! On failure, showing such critical
sandbox information must not require --debug.
Not concealing the sandbox on failure is useful in any case, not
just #3948
Signed-off-by: Marc Herbert [email protected]