run.py: stop hiding sandbox and recommend --debug on sandbox failure #4068
Conversation
![github-advanced-security[bot]](https://avatars.githubusercontent.com/in/57789?s=60&v=4){kind=small}
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]>
marc-hb
force-pushed
the
warn-sandbox
branch
from
7ae25d2 to
2a19d45
Compare
| if ARG_DEBUG.get(): | ||
| # Complete but very long and hard to read. It could be reusable. | ||
| logging.error(f"{shlex.join(['mkosi-sandbox', *sandbox, *cmdline])}") | ||
| else: | ||
| logging.error("sandbox command omitted, rerun with --debug to see full command with bind mounts") | ||
| logging.error(f"{shlex.join(cmdline)}") |
There was a problem hiding this comment.
Please stick to a single call to logging.error() and use newlines instead. I would keep the original log message the same and if --debug is not set, simply append another line that says the following:
"sandbox details omitted, rerun with --debug to see the full sandbox command."
There was a problem hiding this comment.
... and use newlines instead. I would keep the original log message the same...
So are you ok with printing the error message on a separate line? Adding just one newline. Not 100% clear to me from the above, sorry.
I tested this PR heavily (especially compared to how small of a code change it is...) and NOT having the error message trailing a 5-10 lines-long command made a massive difference. It's quite painful to find before this PR.
I don't mind the code style and the number of logging statements, the terminal output and "user experience" is really the purpose of this.
| if ARG_DEBUG.get(): | ||
| # Complete but very long and hard to read. It could be reusable. | ||
| logging.error(f"{shlex.join(['mkosi-sandbox', *sandbox, *cmdline])}") | ||
| else: | ||
| logging.error("sandbox command omitted, rerun with --debug to see full command with bind mounts") | ||
| logging.error(f"{shlex.join(cmdline)}") |
There was a problem hiding this comment.
... and use newlines instead. I would keep the original log message the same...
So are you ok with printing the error message on a separate line? Adding just one newline. Not 100% clear to me from the above, sorry.
I tested this PR heavily (especially compared to how small of a code change it is...) and NOT having the error message trailing a 5-10 lines-long command made a massive difference. It's quite painful to find before this PR.
I don't mind the code style and the number of logging statements, the terminal output and "user experience" is really the purpose of this.
|
@marc-hb I merged a variation of this PR in the linked pr. Let me know if that doesn't address your issue |
|
That should do it, thx! |
2 participants
As discussed in #3948 and #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.pywas 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 inrun.py. After that commit, the sandbox was logged byrun.pyonly in --debug mode and became completely invisible otherwise.