Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Try to simplify logging a bit #3

Merged
merged 4 commits into from
Nov 18, 2023
Merged

Try to simplify logging a bit #3

merged 4 commits into from
Nov 18, 2023

Conversation

psychon
Copy link
Contributor

@psychon psychon commented Nov 18, 2023

In my previous PR, I wrote:

I also wanted to change the log() function, but didn't come up with any easy and obvious versions and didn't want to dump a macro-mess on you, nor a new dependency like the log or tracing crates.

Turns out this is not as complicated as I first thought! I can just introduce a macro that hides the format! in log(&format!(....)).

Next, I looked at the standard library. If we press source on the docs of the print!() macro, we learn that this is based on std::format_args!(). Its documentation indicates that this is some kind of container for the formatted string and can be used in Display context to really construct the formatted string. I then went nuts and optimised away the three String allocations in the logging implementation into a single allocation. This definitely did not make the code more readable.

As with the last PR: Feel free to do whatever you want with that. Especially the needless logging optimisation can be taken out if you do not like it. Just tell me so and I'll do it.

There is lots of code looking like this:

    utils::log(&format!("error powering off: {}", err));

Simplify this by adding a log!() macro that hides the format!() dance
and can be used directly like format!().

Signed-off-by: Uli Schlachter <psychon@znc.in>
Before this commit, the caller of log_impl() (= the macro log!())
already did a memory allocation for constructing a String containing the
message to log. This was then borrowed when calling log_impl(). This
function then did another memory allocation plus copy to prepend
"virtme-ng-init:" to the message. Then, if /dev/kmsg exists, another
allocation is done to add a kernel log level tag at the beginning and a
newline at the end.

This commit starts by changing log!() from format!() to format_args!()
which constructs an instance of std::fmt::Arguments. This is just a
specification of how to do the formatting, but nothing was actually done
yet. This is then used in log_impl() to directly construct a string with
"virtme-ng-init:" prepended to the message to log.

Since I wanted to avoid memory allocations, this then replaces
.trim_end_matches('\n') with a manual loop. That way, we still have a
String and do not switch over to a &str for the following code.

Additionally, the "is the message to log empty?"-check was reformulated
to "was there nothing appended to my prefix?". This makes things
slightly more unreadable, but I couldn't find a better way to check
whether the Arguments instance is empty.

There is a slight change in behaviour here: Previously, log!("\n") would
log an empty line since the code first checked if the message is empty
and only afterwards trimmed trailing newlines. This is now done the
other way around.

Finally, when writing to /dev/kmsg, the String that we already have is
mutated in places instead of allocating another one and copying all data
to it.

Why? Just because. I doubt that this will have any measurable
performance benefits, but somehow it felt like the right thing to do.

Signed-off-by: Uli Schlachter <psychon@znc.in>
write() is allowed to write only partial data. Good luck debugging why
some part of the log message is missing. This commit changes the logging
to use write_all() instead, which ensures everything is written.

This might end up doing multiple writes to /dev/kmsg, which would turn
into multiple log records. I think that is still better than silently
discarding some data.

Signed-off-by: Uli Schlachter <psychon@znc.in>
The logging code already does trim_end_matches('\n') so we do not have
to the that in the caller, too.

Signed-off-by: Uli Schlachter <psychon@znc.in>
@arighi arighi merged commit e33e64d into arighi:main Nov 18, 2023
1 check passed
@arighi
Copy link
Owner

arighi commented Nov 18, 2023

@psychon good stuff! I didn't notice any measurable performance boost, but it all makes sense to me and the code looks much more readable now, therefore applied. Thanks!

@psychon psychon deleted the logging branch November 18, 2023 18:38
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.

2 participants