vmm, ch-remote: add env_logger, replace eprintln! with error! for consistency #7183

mguentner · 2025-07-08T21:12:02Z

In #7179 (comment) we discovered that ch-remote does not print any log lines generated via log::level!.
This PR aims to add env_logger to log them.

Furthermore, replace eprintln! with log::error! as they would be used alongside each other.
When using env_logger, messages printed "in between" with eprintln! lack proper formatting/colors.
This is currently only relevant in ch-remote + cli_print_error_chain.

Note that replaced messages now end up in cloud-hypervisor's logfile when configured, rather than stderr.

likebreath

Overall looks good. Some comments below. Thank you!

Cargo.toml

likebreath · 2025-07-08T22:27:12Z

hypervisor/Cargo.toml


 [dev-dependencies]
-env_logger = "0.11.3"
+env_logger = { workspace = true }


src/lib.rs

src/main.rs

Signed-off-by: Maximilian Güntner <[email protected]>

Until now all messages generated using `log::level!` (e.g., `warn!`) have not been printed as `ch-remote` did not register a logger. Furthermore, replace all `eprintln!` with `error!` to align formatting for consistency. Signed-off-by: Maximilian Güntner <[email protected]>

Unify log formatting and printing as `eprintln!` and `log::error!` would be used alongside each other. When using e.g. `env_logger` lines printed with `eprintln!` would lack formatting / colors. Currently only relevant in `ch-remote` + `cli_print_error_chain`. Note that the replaced messages now also end up in the logfile of `cloud-hypervisor` when configured and not any longer in stderr. Signed-off-by: Maximilian Güntner <[email protected]>

Other lines are already logged using `log::error!` and `env_logger` is initialized before calling `start_net_backend` in `main()`. Signed-off-by: Maximilian Güntner <[email protected]>

This was missed from cloud-hypervisor#7183, likely because `eprint!` is used instead of `eprintln!`. Signed-off-by: Bo Chen <[email protected]>

This was missed from #7183, likely because `eprint!` is used instead of `eprintln!`. Signed-off-by: Bo Chen <[email protected]>

phip1611 · 2025-08-11T09:24:50Z

@mguentner @likebreath @rbradford I wanted to double-check if this is the intended direction. This change modifies the behavior we introduced in v47 with #7066.

Error: Cloud Hypervisor exited with the following chain of errors:
 0: Error booting VM
 1: The VM could not boot
 2: Error manipulating firmware file
 3: No such file or directory (os error 2)

Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" })))

we now have

cloud-hypervisor: 31.385730ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:27 -- Error: Cloud Hypervisor exited with the following chain of errors:
cloud-hypervisor: 31.417961ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 --   0: Error booting VM
cloud-hypervisor: 31.448078ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 --   1: The VM could not boot
cloud-hypervisor: 31.486711ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 --   2: Error manipulating firmware file
cloud-hypervisor: 31.513331ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 --   3: No such file or directory (os error 2)
cloud-hypervisor: 31.548037ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:44 -- 
cloud-hypervisor: 31.568045ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:45 -- Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" })))

I’m concerned that the new format is harder to read and may make it more difficult for users to quickly grasp the root cause. Could we discuss whether the extra verbosity here is worth the trade-off in readability?

I might be missing something tho! Personally, I consider error!() to be good for runtime errors that do not crash the program - I'm looking forward to your thoughts!

rbradford · 2025-08-11T09:30:46Z

I'm not sure of the context here - but indeed this looks a bit off. One thing about using error! is that it would get sent to a log file but the stderr might not. Perhaps we could pretty print the error to stderr - but send the "Debug Info" line via error! (perhaps before so as to make the output look clearer.)

e.g.

cloud-hypervisor: 31.568045ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:45 -- Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" })))
Error: Cloud Hypervisor exited with the following chain of errors:
 0: Error booting VM
 1: The VM could not boot
 2: Error manipulating firmware file
 3: No such file or directory (os error 2)

phip1611 · 2025-08-11T09:33:42Z

Sounds reasonable. I'll set up a PR; let's move the discussion there

This partially reverts ed8f347 from cloud-hypervisor#7183 and 6277d7d from cloud-hypervisor#7201. # Output how it was merged for v47 (cloud-hypervisor#7066) ``` Error: Cloud Hypervisor exited with the following chain of errors: 0: Error booting VM 1: The VM could not boot 2: Error manipulating firmware file 3: No such file or directory (os error 2) Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" }))) ``` # Output after cloud-hypervisor#7183 and cloud-hypervisor#7201 ``` cloud-hypervisor: 31.385730ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:27 -- Error: Cloud Hypervisor exited with the following chain of errors: cloud-hypervisor: 31.417961ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 0: Error booting VM cloud-hypervisor: 31.448078ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 1: The VM could not boot cloud-hypervisor: 31.486711ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 2: Error manipulating firmware file cloud-hypervisor: 31.513331ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 3: No such file or directory (os error 2) cloud-hypervisor: 31.548037ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:44 -- cloud-hypervisor: 31.568045ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:45 -- Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" }))) ``` The "proper logger" has indeed the advantage that messages can be gracefully redirected to log files etc. However, this makes the error message hardly readable. Therefore, I propose to use error!() only for runtime errors that are non-critical, i.e., messages whose error cause will not lead to a VMM shutdown. Signed-off-by: Philipp Schuster <[email protected]> On-behalf-of: SAP [email protected]

This partially reverts ed8f347 from cloud-hypervisor#7183 and 6277d7d from cloud-hypervisor#7201. # Output how it was merged for v47 (cloud-hypervisor#7066) ``` Error: Cloud Hypervisor exited with the following chain of errors: 0: Error booting VM 1: The VM could not boot 2: Error manipulating firmware file 3: No such file or directory (os error 2) Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" }))) ``` # Output after cloud-hypervisor#7183 and cloud-hypervisor#7201 ``` cloud-hypervisor: 31.385730ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:27 -- Error: Cloud Hypervisor exited with the following chain of errors: cloud-hypervisor: 31.417961ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 0: Error booting VM cloud-hypervisor: 31.448078ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 1: The VM could not boot cloud-hypervisor: 31.486711ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 2: Error manipulating firmware file cloud-hypervisor: 31.513331ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 3: No such file or directory (os error 2) cloud-hypervisor: 31.548037ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:44 -- cloud-hypervisor: 31.568045ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:45 -- Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" }))) ``` The "proper logger" has indeed the advantage that messages can be gracefully redirected to log files etc. However, this makes the error message hardly readable. Therefore, I propose to use error!() only for runtime errors messages but not a pretty-printed version of those. Signed-off-by: Philipp Schuster <[email protected]> On-behalf-of: SAP [email protected]

This partially reverts ed8f347 from #7183 and 6277d7d from #7201. # Output how it was merged for v47 (#7066) ``` Error: Cloud Hypervisor exited with the following chain of errors: 0: Error booting VM 1: The VM could not boot 2: Error manipulating firmware file 3: No such file or directory (os error 2) Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" }))) ``` # Output after #7183 and #7201 ``` cloud-hypervisor: 31.385730ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:27 -- Error: Cloud Hypervisor exited with the following chain of errors: cloud-hypervisor: 31.417961ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 0: Error booting VM cloud-hypervisor: 31.448078ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 1: The VM could not boot cloud-hypervisor: 31.486711ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 2: Error manipulating firmware file cloud-hypervisor: 31.513331ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:39 -- 3: No such file or directory (os error 2) cloud-hypervisor: 31.548037ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:44 -- cloud-hypervisor: 31.568045ms: <main> ERROR:/home/pschuster/dev/cloud-hypervisor/src/lib.rs:45 -- Debug Info: VmBoot(VmBoot(FirmwareFile(Os { code: 2, kind: NotFound, message: "No such file or directory" }))) ``` The "proper logger" has indeed the advantage that messages can be gracefully redirected to log files etc. However, this makes the error message hardly readable. Therefore, I propose to use error!() only for runtime errors messages but not a pretty-printed version of those. Signed-off-by: Philipp Schuster <[email protected]> On-behalf-of: SAP [email protected]

mguentner requested a review from a team as a code owner July 8, 2025 21:12

mguentner force-pushed the mguentner/add_logger_to_ch_remote branch from 9712581 to 3538ad5 Compare July 8, 2025 21:22

likebreath reviewed Jul 8, 2025

View reviewed changes

mguentner force-pushed the mguentner/add_logger_to_ch_remote branch 2 times, most recently from baca540 to 858fb24 Compare July 8, 2025 22:54

mguentner added 4 commits July 9, 2025 12:07

build: consolidate env_logger to workspace, update to 0.11.8

e80b432

Signed-off-by: Maximilian Güntner <[email protected]>

misc: vhost_user_net: replace eprintln with log::error

27b4e01

Other lines are already logged using `log::error!` and `env_logger` is initialized before calling `start_net_backend` in `main()`. Signed-off-by: Maximilian Güntner <[email protected]>

mguentner force-pushed the mguentner/add_logger_to_ch_remote branch from 858fb24 to 27b4e01 Compare July 9, 2025 10:10

likebreath approved these changes Jul 10, 2025

View reviewed changes

likebreath added this pull request to the merge queue Jul 10, 2025

Merged via the queue into cloud-hypervisor:main with commit 072f06f Jul 10, 2025
40 of 41 checks passed

likebreath added a commit to likebreath/cloud-hypervisor that referenced this pull request Jul 16, 2025

main: Report errors with 'error!()'

6277d7d

This was missed from cloud-hypervisor#7183, likely because `eprint!` is used instead of `eprintln!`. Signed-off-by: Bo Chen <[email protected]>

likebreath mentioned this pull request Jul 16, 2025

main: Report errors with 'error!()' #7201

Merged

github-merge-queue bot pushed a commit that referenced this pull request Jul 17, 2025

main: Report errors with 'error!()'

987ad11

This was missed from #7183, likely because `eprint!` is used instead of `eprintln!`. Signed-off-by: Bo Chen <[email protected]>

phip1611 mentioned this pull request Aug 11, 2025

misc: switch error output from error! back to stderr #7251

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

vmm, ch-remote: add env_logger, replace eprintln! with error! for consistency #7183

vmm, ch-remote: add env_logger, replace eprintln! with error! for consistency #7183

Uh oh!

mguentner commented Jul 8, 2025

Uh oh!

likebreath left a comment

Uh oh!

Uh oh!

likebreath Jul 8, 2025

Uh oh!

Uh oh!

Uh oh!

Uh oh!

phip1611 commented Aug 11, 2025 •

edited

Loading

Uh oh!

rbradford commented Aug 11, 2025

Uh oh!

phip1611 commented Aug 11, 2025 •

edited

Loading

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

vmm, ch-remote: add env_logger, replace eprintln! with error! for consistency #7183

vmm, ch-remote: add env_logger, replace eprintln! with error! for consistency #7183

Uh oh!

Conversation

mguentner commented Jul 8, 2025

Uh oh!

likebreath left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

likebreath Jul 8, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

phip1611 commented Aug 11, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

rbradford commented Aug 11, 2025

Uh oh!

phip1611 commented Aug 11, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

phip1611 commented Aug 11, 2025 •

edited

Loading

phip1611 commented Aug 11, 2025 •

edited

Loading